Measuring time results in return values of 0 or 0.001

Question

I am trying to use chrono::steady_clock to measure fractional seconds elapsed between a block of code in my program. I have this block of code working in LiveWorkSpace (http://liveworkspace.org/code/YT1I$9):

#include <chrono>
#include <iostream>
#include <vector>

int main()
{
    auto start = std::chrono::steady_clock::now();
    for (unsigned long long int i = 0; i < 10000; ++i) {
       std::vector<int> v(i, 1);
    }
    auto end = std::chrono::steady_clock::now();

    auto difference = std::chrono::duration_cast<std::chrono::microseconds>(end - start).count();

    std::cout << "seconds since start: " << ((double)difference / 1000000);
}

When I implement the same idea into my program like so:

auto start = std::chrono::steady_clock::now();
// block of code to time
auto end = std::chrono::stead_clock::now();

auto difference = std::chrono::duration_cast<std::chrono::microseconds>(end - start).count()

std::cout << "seconds since start: " << ((double) difference / 1000000);

The program will only print out values of 0 and 0.001. I highly doubt that the execution time for my block of code always equals 0 or 1000 microseconds, so what is accounting for this rounding and how might I eliminate it so that I can get the proper fractional values?

This is a Windows program.

Answer 1

This question already has a good answer. But I'd like to add another suggestion:

Work within the <chrono> framework. Build your own clock. Build your own time_point. Build your own duration. The <chrono> framework is very customizable. By working within that system, you will not only learn std::chrono, but when your vendor starts shipping clocks you're happy with, it will be trivial to transition your code from your hand-rolled chrono::clock to std::high_resolution_clock (or whatever).

First though, a minor criticism about your original code:

std::cout << "seconds since start: " << ((double) difference / 1000000);

Whenever you see yourself introducing conversion constants (like 1000000) to get what you want, you're not using chrono correctly. Your code isn't incorrect, just fragile. Are you sure you got the right number of zeros in that constant?!

Even in this simple example you should say to yourself:

I want to see output in terms of seconds represented by a double.

And then you should use chrono do that for you. It is very easy once you learn how:

typedef std::chrono::duration<double> sec;
sec difference = end - start;
std::cout << "seconds since start: " << difference.count() << '\n';

The first line creates a type with a period of 1 second, represented by a double.

The second line simply subtracts your time_points and assigns it to your custom duration type. The conversion from the units of steady_clock::time_point to your custom duration (a double second) are done by the chrono library automatically. This is much simpler than:

auto difference = std::chrono::duration_cast<std::chrono::microseconds>(end - start).count()

And then finally you just print out your result with the .count() member function. This is again much simpler than:

std::cout << "seconds since start: " << ((double) difference / 1000000);

---

---

But since you're not happy with the precision of std::chrono::steady_clock, and you have access to QueryPerformanceCounter, you can do better. You can build your own clock on top of QueryPerformanceCounter.

<disclaimer>

I don't have a Windows system to test the following code on.

</disclaimer>

struct my_clock
{
    typedef double                             rep;
    typedef std::ratio<1>                      period;
    typedef std::chrono::duration<rep, period> duration;
    typedef std::chrono::time_point<my_clock>  time_point;
    static const bool is_steady =              false;

    static time_point now()
    {
        static const long long frequency = init_frequency();
        long long t;
        QueryPerformanceCounter(&t);
        return time_point(duration(static_cast<rep>(t)/frequency));
    }
private:
    static long long init_frequency()
    {
        long long f;
        QueryPerformanceFrequency(&f);
        return f;
    }
};

Since you wanted your output in terms of a double second, I've made the rep of this clock a double and the period 1 second. You could just as easily make the rep integral and the period some other unit such as microseconds or nanoseconds. You just adjust the typedefs and the conversion from QueryPerformanceCounter to your duration in now().

And now your code can look much like your original code:

int main()
{
    auto start = my_clock::now();
    for (unsigned long long int i = 0; i < 10000; ++i) {
       std::vector<int> v(i, 1);
    }
    auto end = my_clock::now();

    auto difference = end - start;
    std::cout << "seconds since start: " << difference.count() << '\n';
}

But without the hand-coded conversion constants, and with (what I'm hoping is) sufficient precision for your needs. And with a much easier porting path to a future std::chrono::steady_clock implementation.

<chrono> was designed to be an extensible library. Please extend it. :-)

Answer 2

After running some tests on MSVC2012, I could confirm that the C++11 clocks in Microsoft's implementation do not have a high enough resolution. See C++ header's high_resolution_clock does not have high resolution for a bug report concerning this issue.

So, unfortunately for a higher resolution timer, you will need to use boost::chrono or QueryPerformanceCounter directly like so until they fix the bug:

#include <iostream>
#include <Windows.h>

int main()
{
    LARGE_INTEGER frequency;
    QueryPerformanceFrequency(&frequency);

    LARGE_INTEGER start;
    QueryPerformanceCounter(&start);

    // Put code here to time

    LARGE_INTEGER end;
    QueryPerformanceCounter(&end);

    // for microseconds use 1000000.0
    double interval = static_cast<double>(end.QuadPart- start.QuadPart) / 
                      frequency.QuadPart; // in seconds
    std::cout << interval;
}