C++ Como testar o tempo de execução de um código no Visual Studio 2017?

[cyer]

Estou tentando testar o tempo de execução de um código, porém estou sempre obtendo valores incorretos, o primeiro teste vai ser sempre o que tem o pior tempo. E na maioria das vezes o segundo teste é sempre 0.

   

#include <iostream>
#include <math.h>
#include <intrin.h>
#include <chrono>

using namespace std;

#define MAX_LOOP                100000
#define NUM                     10000.f

auto sse_sqrt( float n )
{
    __m128 reg = _mm_load_ss( &n );
    return _mm_mul_ss( reg, _mm_rsqrt_ss( reg ) ).m128_f32[ 0 ];
}

auto stl_sqrt_timer()
{
    auto start = std::chrono::high_resolution_clock::now();

    for ( auto i = 0; i < MAX_LOOP; i++ )
    {
        auto v = std::sqrt( NUM );
    }

    auto end = std::chrono::high_resolution_clock::now();

    return ( end - start ).count();
}

auto sse_sqrt_timer()
{
    auto start = std::chrono::high_resolution_clock::now();

    for ( auto i = 0; i < MAX_LOOP; i++ )
    {
        auto v = sse_sqrt( NUM );
    }

    auto end = std::chrono::high_resolution_clock::now();

    return ( end - start ).count();
}

int main()
{
    cout << "stl_sqrt: " << stl_sqrt_timer() << "\n";
    cout << "sse_sqrt: " << sse_sqrt_timer() << "\n";

    cin.ignore();

    return 0;
}

Primeira execução:
sse_sqrt: 12461
stl_sqrt: 0

 

Segunda execução:
sse_sqrt: 2643
stl_sqrt: 378

 

Invertendo a ordem de testes:

 

Primeira execução:

stl_sqrt: 23032
sse_sqrt: 378

 

Segunda execução:

stl_sqrt: 2265
sse_sqrt: 0

 

 

Estou compilando em Release x86, com otimização /Ox
 

[Ansi C]

Não seria porque da segundo vez a CPU detecta a rotina em cache e faz os cálculos lá mesmo!?

[cyer]

 

1 hora atrás, AnsiC disse:

Não seria porque da segundo vez a CPU detecta a rotina em cache e faz os cálculos lá mesmo!?

 

Acredito que não, porque se fosse realmente isso iria acontecer sempre pois é passado o mesmo valor para ambas as funções, isso acontece apenas em 30 ~ 50% dos testes

[Ansi C]

Eu pouco sei sobre as rotinas de um processador. Só vi que está chamando funções que lidam quase que diretamente com a rotina da cpu, então supos que fosse o cache de logo de cara. Boa sorte com seu enigma!

[cyer]

@AnsiC Obrigado, consegui resolver, eu estava fazendo errado, tinha que executar o teste por pelo menos 10000 vezes depois armazenar o tempo de cada teste em uma variável e depois dividir esse tempo pelo número de testes(10000)

 

#include <iostream>
#include <math.h>
#include <intrin.h>
#include <chrono>
#include <functional>

using namespace std;

#define MAX_LOOP                10000u

auto sse_sqrt( float n )
{
    __m128 reg = _mm_load_ss( &n );
    return _mm_mul_ss( reg, _mm_rsqrt_ss( reg ) ).m128_f32[ 0 ];
}

auto executar_teste( std::function< void() > t )
{
    auto timer = 0ull;
    
    for ( auto i = 0u; i < MAX_LOOP; ++i )
    {
        auto start = std::chrono::high_resolution_clock::now();

        t();

        timer += ( std::chrono::high_resolution_clock::now() - start ).count();
    }

    return timer / static_cast< unsigned long long >( MAX_LOOP );
}

auto stl_sqrt_t()
{
    return std::sqrt( 1000 );     
}

auto sse_sqrt_t()
{
    return sse_sqrt( 1000 );
}

int main()
{
    cout << "stl_sqrt: " << executar_teste( stl_sqrt_t ) << "\n";
    cout << "sse_sqrt: " << executar_teste( sse_sqrt_t ) << "\n";

    cin.ignore();

    return 0;
}

 

Primeira execução:

stl_sqrt: 69
sse_sqrt: 80

 

Segunda execução:

stl_sqrt: 72
sse_sqrt: 78

 

Terceira execução:

stl_sqrt: 71
sse_sqrt: 73