Search code examples
c++releaseexecution-time

Incorrect timing in release mode


I'm trying to measure time of execution of the following code:

#include <iostream>
#include <cmath>
#include <stdio.h>
#include <chrono>

uint64_t LCG(uint64_t LCG_state)
{
    LCG_state = (LCG_state * 2862933555777941757 + 1422359891750319841);
    return LCG_state;
}

int main()
{
auto begin = std::chrono::high_resolution_clock::now();
    uint64_t LCG_state = 333;
    uint32_t w;

    for(int i=0; i<640000000; i++)
    {
        LCG_state = LCG(LCG_state);
        w = LCG_state >> 32;
        //std::cout << w << "\n";
    }

auto end = std::chrono::high_resolution_clock::now();
auto elapsed = std::chrono::duration_cast<std::chrono::nanoseconds>(end - begin);
printf("Time measured: %.3f seconds.\n", elapsed.count() * 1e-9);
}

I'm using option release in Code Blocks (because I think I should if I want to measure it right). Problem is that time measured is 0 s every time. What's more if I would do loop:

#include <iostream>
#include <cmath>
#include <stdio.h>
#include <chrono>

uint64_t LCG(uint64_t LCG_state)
{
    LCG_state = (LCG_state * 2862933555777941757 + 1422359891750319841);
    return LCG_state;
}

int main()
{
auto begin = std::chrono::high_resolution_clock::now();
    uint64_t LCG_state = 333;
    uint32_t w;

    for(int i=0; i<10000; i++)
    {
    for(int i=0; i<640000000; i++)
    {
        LCG_state = LCG(LCG_state);
        w = LCG_state >> 32;
        //std::cout << w << "\n";
    }
    }

auto end = std::chrono::high_resolution_clock::now();
auto elapsed = std::chrono::duration_cast<std::chrono::nanoseconds>(end - begin);
printf("Time measured: %.3f seconds.\n", elapsed.count() * 1e-9);
}

Then still measurerd time is 0 s. In debug trybe everything works right, but measuring time of code with debug make no sense right? Especially I would like to compare it to for example this:

#include <stdint.h>
#include <iostream>

uint64_t s[2] = {5,11};

uint64_t result;

uint64_t next(void) {
  uint64_t s1 = s[0];
  uint64_t s0 = s[1];
  uint64_t result = s0 + s1;
  s[0] = s0;
  s1 ^= s1 << 23; // a
  s[1] = s1 ^ s0 ^ (s1 >> 18) ^ (s0 >> 5); // b, c
  return result;
}

int main()
{
    for(int i=0; i<160000000; i++)
    //while (true)
    {
    //std::cout << next() << "\n";
    result = next();
    //char *c = reinterpret_cast<char*>(&result);
    //std::cout.write(reinterpret_cast<char*>(&result), sizeof result);
    }
}

I want to know what is faster. How to measure it right? Why is the execution time 0 seconds, does the code not execute at all?


Solution

  • You can add an empty asm statement dependent on the variable w

    #include <iostream>
    #include <cmath>
    #include <stdio.h>
    #include <chrono>
    
    uint64_t LCG(uint64_t LCG_state)
    {
        LCG_state = (LCG_state * 2862933555777941757 + 1422359891750319841);
        return LCG_state;
    }
    
    int main()
    {
    auto begin = std::chrono::high_resolution_clock::now();
        uint64_t LCG_state = 333;
        uint32_t w;
    
        for(int i=0; i<640000000; i++)
        {
            LCG_state = LCG(LCG_state);
            w = LCG_state >> 32;
            __asm__ volatile("" : "+g" (w) : :);
        }
    
    auto end = std::chrono::high_resolution_clock::now();
    auto elapsed = std::chrono::duration_cast<std::chrono::nanoseconds>(end - begin);
    printf("Time measured: %.3f seconds.\n", elapsed.count() * 1e-9);
    }
    

    This is opaque to the compiler and will prevent the loop from being optimized out