title: Profiling SIMD Code
body: <p><strong>UPDATED - Check Below</strong></p>
  
  <p>Will keep this as short as possible. Happy to add any more details if required.</p>
  
  <p>I have some sse code for normalising a vector. I'm using QueryPerformanceCounter() (wrapped in a helper struct) to measure performance.</p>
  
  <p>If I measure like this</p>
  
  <pre><code>for( int j = 0; j &lt; NUM_VECTORS; ++j )
  {
    Timer t(norm_sse);
    NormaliseSSE( vectors_sse+j);
  }
  </code></pre>
  
  <p>The results I get are often slower than just doing a standard normalise with 4 doubles representing a vector (testing in the same configuration).</p>
  
  <pre><code>for( int j = 0; j &lt; NUM_VECTORS; ++j )
  {
    Timer t(norm_dbl);
    NormaliseDBL( vectors_dbl+j);
  }
  </code></pre>
  
  <p>However, timing just the entirety of the loop like this</p>
  
  <pre><code>{
    Timer t(norm_sse);
    for( int j = 0; j &lt; NUM_VECTORS; ++j ){
      NormaliseSSE( vectors_sse+j );
    }    
  }
  </code></pre>
  
  <p>shows the SSE code to be an order of magnitude faster, but doesn't really affect the measurements for the double version.
  I've done a fair bit of experimentation and searching, and can't seem to find a reasonable answer as to why.</p>
  
  <p>For example, I know there can be penalities when casting the results to float, but none of that is going on here. </p>
  
  <p>Can anyone offer any insight? What is it about calling QueryPerformanceCounter between each normalise that slows the SIMD code down so much?</p>
  
  <p>Thanks for reading :)</p>
  
  <p>More details below:</p>
  
  <ul>
  <li>Both normalise methods are inlined (verified in disassembly)</li>
  <li>Running in release</li>
  <li>32 bit compilation</li>
  </ul>
  
  <p><strong>Simple Vector struct</strong></p>
  
  <pre><code>_declspec(align(16)) struct FVECTOR{
      typedef float REAL;
    union{
      struct { REAL x, y, z, w; };
      __m128 Vec;
    };
  };
  </code></pre>
  
  <p><strong>Code to Normalise SSE:</strong></p>
  
  <pre><code>  __m128 Vec = _v-&gt;Vec;
    __m128 sqr = _mm_mul_ps( Vec, Vec ); // Vec * Vec
    __m128 yxwz = _mm_shuffle_ps( sqr, sqr , 0x4e ); 
    __m128 addOne = _mm_add_ps( sqr, yxwz ); 
    __m128 swapPairs = _mm_shuffle_ps( addOne, addOne , 0x11 );
    __m128 addTwo = _mm_add_ps( addOne, swapPairs ); 
    __m128 invSqrOne = _mm_rsqrt_ps( addTwo ); 
    _v-&gt;Vec = _mm_mul_ps( invSqrOne, Vec );   
  </code></pre>
  
  <p><strong>Code to normalise doubles</strong></p>
  
  <pre><code>double len_recip = 1./sqrt(v-&gt;x*v-&gt;x + v-&gt;y*v-&gt;y + v-&gt;z*v-&gt;z);
  v-&gt;x *= len_recip;
  v-&gt;y *= len_recip;
  v-&gt;z *= len_recip;
  </code></pre>
  
  <p><strong>Helper struct</strong></p>
  
  <pre><code>struct Timer{
    Timer( LARGE_INTEGER &amp; a_Storage ): Storage( a_Storage ){
        QueryPerformanceCounter( &amp;PStart );
    }
  
    ~Timer(){
      LARGE_INTEGER PEnd;
      QueryPerformanceCounter( &amp;PEnd );
      Storage.QuadPart += ( PEnd.QuadPart - PStart.QuadPart );
    }
  
    LARGE_INTEGER&amp; Storage;
    LARGE_INTEGER PStart;
  };
  </code></pre>
  
  <p><strong>Update</strong>
  So thanks to Johns comments, I think I've managed to confirm that it is QueryPerformanceCounter thats doing bad things to my simd code.</p>
  
  <p>I added a new timer struct that uses RDTSC directly, and it seems to give results consistent to what I would expect. The result is still far slower than timing the entire loop, rather than each iteration separately, but I expect that that's because Getting the RDTSC involves flushing the instruction pipeline (Check <a href="http://www.strchr.com/performance_measurements_with_rdtsc" rel="nofollow" title="here">http://www.strchr.com/performance_measurements_with_rdtsc</a> for more info).</p>
  
  <pre><code>struct PreciseTimer{
  
      PreciseTimer( LARGE_INTEGER&amp; a_Storage ) : Storage(a_Storage){
          StartVal.QuadPart = GetRDTSC();
      }
  
      ~PreciseTimer(){
          Storage.QuadPart += ( GetRDTSC() - StartVal.QuadPart );
      }
  
      unsigned __int64 inline GetRDTSC() {
          unsigned int lo, hi;
          __asm {
               ; Flush the pipeline
               xor eax, eax
               CPUID
               ; Get RDTSC counter in edx:eax
               RDTSC
               mov DWORD PTR [hi], edx
               mov DWORD PTR [lo], eax
          }
  
          return (unsigned __int64)(hi &lt;&lt; 32 | lo);
  
      }
  
      LARGE_INTEGER StartVal;
      LARGE_INTEGER&amp; Storage;
  };
  </code></pre>