odd behaviour using chrono::high_resolution_clock::now()

Question

I've been looking at various game timing loop methods e.g. Glenn Fiedler and DeWitter. I found critical areas difficult to understand due to my own C++ knowledge limitations. With this I set about trying to implement my own method....I thought a good way to try to understand something about these methods.

[edit1: I'm using CodeBlocks IDE with minGW-w64 (x64-4.8.1-posix-seh-rev5) as the compiler]

[edit2: code and output windows amended to include a 3rd timer, QueryPerformanceCounter]

In trying to accomplish this I came across the following issue:

Minimal code:

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

using namespace std;
using namespace chrono;

LARGE_INTEGER startqpc, stopqpc, li;
double PCFreq = 0.0;


void print()
{
for (int p=0; p<1000000; ) p += 1;  //adjust till ms (steady) returns 1-2ms
}

int main()
{
    for(int x=0; x<200; x += 1)
    {
    steady_clock::time_point start = steady_clock::now();
    auto timePoint1 = chrono::high_resolution_clock::now();

    if(!QueryPerformanceFrequency(&li))
        cout << "QueryPerformanceFrequency failed!\n";
    PCFreq = double(li.QuadPart)/1000.0;
    QueryPerformanceCounter(&startqpc);

    print();

    steady_clock::time_point finish = steady_clock::now();
    auto timePoint2 = chrono::high_resolution_clock::now();
    QueryPerformanceCounter(&stopqpc);
    auto elapsedTime(timePoint2 - timePoint1);
    double diff = (stopqpc.QuadPart - startqpc.QuadPart)/PCFreq;

    cout << "Elapsed time: "
              << duration_cast<milliseconds>(finish - start).count() << "ms (steady)   "
              << chrono::duration_cast<chrono::duration<float, milli >> (elapsedTime).count() << "ms (hires)   "
              << diff << " (qpc) \n";

    }
}

For comparison purposes, the above code makes use of two timers.

On my PC the output from this is as follows:

Elapsed time: 1ms (steady)   0ms (hires)   1.8429 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.8429 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.85152 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   15.6001ms (hires)   1.85557 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.59283 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.25573 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.85072 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.85422 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1ms (steady)   15.6001ms (hires)   1.85099 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.31582 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.84964 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.52466 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 2ms (steady)   15.6ms (hires)   2.25169 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.26974 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84991 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84667 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.89518 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.87874 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.92213 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.87605 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.03126 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.87659 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.88467 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.24899 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.30316 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23579 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93263 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23552 (qpc)
Elapsed time: 2ms (steady)   15.6ms (hires)   2.42118 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.24522 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23471 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23848 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93425 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9329 (qpc)
Elapsed time: 1ms (steady)   15.6001ms (hires)   1.85126 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.35355 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23687 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23633 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.2374 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23498 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.85449 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.0097 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.15441 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93263 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93425 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23579 (qpc)
Elapsed time: 2ms (steady)   15.6ms (hires)   2.04554 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.1121 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.01779 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.07222 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9329 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93425 (qpc)
Elapsed time: 1ms (steady)   15.6001ms (hires)   1.95015 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.95177 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84587 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.85233 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.88278 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84667 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.88629 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.8588 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.06225 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23633 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93317 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.06009 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1ms (steady)   15.6001ms (hires)   1.86284 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93425 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.02803 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.26839 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93398 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.93641 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93371 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93344 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9329 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.02345 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.08731 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9356 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93398 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.09 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93371 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.03072 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.19213 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.85287 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9321 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93344 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93317 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93344 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93263 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.42711 (qpc)
Elapsed time: 1ms (steady)   15.6001ms (hires)   1.9418 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9356 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.08947 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9329 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93614 (qpc)
Elapsed time: 2ms (steady)   15.6ms (hires)   2.27702 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93614 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93317 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.08974 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.92698 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93317 (qpc)
Elapsed time: 2ms (steady)   15.6ms (hires)   2.09054 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.96066 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.96093 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1ms (steady)   15.6001ms (hires)   1.91835 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84587 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.85233 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93317 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93317 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.23552 (qpc)
Elapsed time: 1ms (steady)   15.6ms (hires)   1.93102 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.07033 (qpc)
Elapsed time: 2ms (steady)   0ms (hires)   2.09405 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.9329 (qpc)
Elapsed time: 1ms (steady)   0ms (hires)   1.93263 (qpc)

Process returned 0 (0x0)   execution time : 0.484 s
Press any key to continue.

Using duration_cast<microseconds>(finish - start).count()/1000.0 for the steady_clock we see the following:-

Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1.843ms (steady)   0ms (hires)   1.84317 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.846ms (steady)   0ms (hires)   1.84694 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1.877ms (steady)   0ms (hires)   1.87685 (qpc)
Elapsed time: 1.916ms (steady)   15.6ms (hires)   1.9162 (qpc)
Elapsed time: 1.906ms (steady)   0ms (hires)   1.90623 (qpc)
Elapsed time: 1.905ms (steady)   0ms (hires)   1.90515 (qpc)
Elapsed time: 1.909ms (steady)   0ms (hires)   1.90919 (qpc)
Elapsed time: 1.905ms (steady)   0ms (hires)   1.90542 (qpc)
Elapsed time: 1.905ms (steady)   0ms (hires)   1.90488 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.943ms (steady)   15.6ms (hires)   1.94287 (qpc)
Elapsed time: 1.872ms (steady)   0ms (hires)   1.87281 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.846ms (steady)   15.6001ms (hires)   1.8464 (qpc)
Elapsed time: 1.875ms (steady)   0ms (hires)   1.87497 (qpc)
Elapsed time: 2.033ms (steady)   0ms (hires)   2.03449 (qpc)
Elapsed time: 1.922ms (steady)   0ms (hires)   1.92293 (qpc)
Elapsed time: 1.922ms (steady)   0ms (hires)   1.92293 (qpc)
Elapsed time: 1.926ms (steady)   0ms (hires)   1.92698 (qpc)
Elapsed time: 2.004ms (steady)   15.6ms (hires)   2.00485 (qpc)
Elapsed time: 1.847ms (steady)   0ms (hires)   1.84748 (qpc)
Elapsed time: 1.847ms (steady)   0ms (hires)   1.84748 (qpc)
Elapsed time: 1.848ms (steady)   0ms (hires)   1.84856 (qpc)
Elapsed time: 1.849ms (steady)   0ms (hires)   1.84937 (qpc)
Elapsed time: 2.299ms (steady)   0ms (hires)   2.29938 (qpc)
Elapsed time: 3.497ms (steady)   15.6ms (hires)   3.49664 (qpc)
Elapsed time: 3.528ms (steady)   0ms (hires)   3.52843 (qpc)
Elapsed time: 2.299ms (steady)   0ms (hires)   2.29857 (qpc)
Elapsed time: 1.849ms (steady)   0ms (hires)   1.84937 (qpc)
Elapsed time: 1.848ms (steady)   0ms (hires)   1.84856 (qpc)
Elapsed time: 1.848ms (steady)   0ms (hires)   1.84856 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84263 (qpc)
Elapsed time: 1.854ms (steady)   0ms (hires)   1.85395 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.843ms (steady)   0ms (hires)   1.84371 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.8429 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.843ms (steady)   0ms (hires)   1.8429 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.861ms (steady)   0ms (hires)   1.86123 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 2.058ms (steady)   0ms (hires)   2.05848 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.881ms (steady)   0ms (hires)   1.88144 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.843ms (steady)   0ms (hires)   1.84371 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84209 (qpc)
Elapsed time: 1.896ms (steady)   0ms (hires)   1.89653 (qpc)
Elapsed time: 1.842ms (steady)   0ms (hires)   1.84236 (qpc)
Elapsed time: 1.843ms (steady)   0ms (hires)   1.84398 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.886ms (steady)   0ms (hires)   1.88656 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.85ms (steady)   15.6ms (hires)   1.85099 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.848ms (steady)   15.6001ms (hires)   1.84883 (qpc)
Elapsed time: 2.066ms (steady)   0ms (hires)   2.06683 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.888ms (steady)   0ms (hires)   1.88817 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.853ms (steady)   15.6ms (hires)   1.85341 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 2.056ms (steady)   0ms (hires)   2.05605 (qpc)
Elapsed time: 1.88ms (steady)   0ms (hires)   1.8809 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.882ms (steady)   0ms (hires)   1.88224 (qpc)
Elapsed time: 1.849ms (steady)   15.6ms (hires)   1.85018 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 2.243ms (steady)   0ms (hires)   2.24333 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.849ms (steady)   15.6ms (hires)   1.85018 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 2.109ms (steady)   0ms (hires)   2.10914 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 2.006ms (steady)   0ms (hires)   2.00647 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.852ms (steady)   15.6ms (hires)   1.8526 (qpc)
Elapsed time: 2.534ms (steady)   0ms (hires)   2.53463 (qpc)
Elapsed time: 2.368ms (steady)   0ms (hires)   2.3681 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.853ms (steady)   15.6ms (hires)   1.85368 (qpc)
Elapsed time: 1.843ms (steady)   0ms (hires)   1.84371 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84533 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.852ms (steady)   15.6ms (hires)   1.85233 (qpc)
Elapsed time: 1.849ms (steady)   0ms (hires)   1.8491 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84587 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.891ms (steady)   15.6001ms (hires)   1.89168 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.846ms (steady)   0ms (hires)   1.84587 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.846ms (steady)   15.6ms (hires)   1.8464 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84587 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.848ms (steady)   15.6ms (hires)   1.84829 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.846ms (steady)   15.6ms (hires)   1.84614 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.8456 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84506 (qpc)
Elapsed time: 1.872ms (steady)   15.6001ms (hires)   1.87281 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84452 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84587 (qpc)
Elapsed time: 1.844ms (steady)   0ms (hires)   1.84425 (qpc)
Elapsed time: 1.845ms (steady)   0ms (hires)   1.84479 (qpc)

Process returned 0 (0x0)   execution time : 0.499 s
Press any key to continue

Notice how the high resolution clock fluctuates between 0 and 15.6ms and notice the steady_clock comparison.

The issue I have is that is that if I were to implement a fixed-time game loop where the update() code updates entity positions at exactly 1000/60 (60 update cycles a second) i.e. every 16.666etc ms - then this is very close to the returned hires timer fluctuating value! The real problem is that if I also implement an accumulator in order to accommodate both game loop frame times that are under 1000/60ms and any leftover once update() has completed, the update loop is entered sooner - and at irregular time points - than it should.

Is there an issue with the minimal code above, and if not, should I be concerned with this for any proper fixed-time implementation? Additionally, and if relevant, is there any way to isolate a program/thread so that it is not interrupted by system IRQ or other polling events? I'm guessing the hires timer may be subject to such interruptions.

I've artificially constructed the minimal code to show the odd behaviour I'm experiencing with the high res timer. My actual game code (doesn't use a 'busy-wait') also exhibits this issue where the game cycles fluctuate between 0 and 15.6ms.......or more accurately (where the game loop is busier), there appears an issue with 15.6ms being irregularly added to the game loop. — Jim, Jan 31 '14 at 01:20
I agree with Ben Voigt that your standard library's implementation of std::chrono is buggy. Even with a low quality implementation, I don't see how your output is reasonable. I see nothing wrong with your code. Perhaps on this platform you need to define your own `chrono::clock`. Here is an example of how to turn the rdtsc assembly instruction into a `chrono::clock`: http://stackoverflow.com/a/5524138/576911 — Howard Hinnant, Jan 31 '14 at 02:57

score 10 · Accepted Answer · answered Jan 31 '14 at 00:22

10

There's a bug in your standard library's implementation of std::chrono.

I'm aware of one such bug in Visual C++, not sure what compiler you are using but if support for std::chrono is a recent addition they might still have some flaws.

If you are using Visual C++, you should be aware of:

answered Jan 31 '14 at 00:22

Ben Voigt

277,958
43
419
720

Thanks for your reply. I'm aware of the VS bug (used VS Express 2013 previously) and am now using CodeBlocks IDE with minGW-w64 (x64-4.8.1-posix-seh-rev5) as the compiler. I understood (probably wrongly) that this compiler didn't have this problem. – Jim Jan 31 '14 at 00:29
1

@Jim: Does that use msvcrt.dll or newlib as the runtime library? I thought mingw uses msvcrt .... which means it will inherit many Microsoft bugs. – Ben Voigt Jan 31 '14 at 00:32
I do see libmsvcrt.a at C:\Program Files\mingw-builds\x64-4.8.1-posix-seh-rev5\mingw64\x86_64-w64-mingw32\lib. If this is the issue do you know of any other compiler that doesn't have this issue? It took a very long time in trying out various mingw versions before settle on this version (though I did learn a lot in the process). – Jim Jan 31 '14 at 00:39
1

So it is using the msvc runtime library. I *think* that only affects the C Standard Library, and not C++ library (depending on how the C++ library is built on top of the C library and Win32 API -- they certainly had the option of building on QueryPerformanceCounter). Still, I imagine that the mingw port of g++ and library gets much less testing than on Linux. – Ben Voigt Jan 31 '14 at 00:41
1

IIRC correctly, C++11 doesn't attempt to make any corrections to account for CPU frequency changes (or other events like a sleep/hibernate) with the `high_resolution_clock`, does it? Isn't it effectively intended to sit on an instruction like `rtdsc` (x86/x64) that gets the tick count of the CPU? – Nathan Ernst Jan 31 '14 at 00:59
RDTSC no longer varies with dynamic clock changes – Ben Voigt Jan 31 '14 at 01:00
1

If it makes any difference (and trying to remember my BIOS settings) CPU-Z shows my i7920 to be fairly well fixed at an overclocked 3800MHz, varying by around 0.20 MHz. I chose this rather than allow automatic frequency changes. – Jim Jan 31 '14 at 01:14
Thanks all for this. I'll try out Howard's suggestion. I realise others are available e.g. Boost, however, I'm keen to keep overheads down if possible. – Jim Jan 31 '14 at 08:13
@Jim: Howard's implementation is good for exposition for terrible for actual usage. You don't want your CPU frequency fixed in your source code. Try `QueryPerformanceCounter` and `QueryPerformanceFrequency` instead, which should be precise within less than 1 microsecond. – Ben Voigt Jan 31 '14 at 17:18
@Ben: Upon checking Howard's link out I thought the same thing (frequency tied) though as he rightly says 'useful for investigation purposes'. For myself, back to Googling QueryPerformanceCounter and/or QueryPerformanceFrequency custom implementations; I might also check out Boost::chrono after all (hoping there's no issues of accuracy between 32bit / 64bit Windows). – Jim Jan 31 '14 at 21:40
I've edited the minimal code and output windows to include a possible implementation of the QueryPerformanceCounter to the mix. It seems to be in line with the steady clock, though at a higher resolution (as hoped). It's based on http://stackoverflow.com/questions/1739259/how-to-use-queryperformancecounter. I'd be grateful if someone could answer if this (QPC) implementation would be robust/safe enough to use downstream (e.g. game loop timing). – Jim Feb 01 '14 at 00:27
@Jim: QPC is rock solid, it's good for almost any purpose. That said, your new results are interesting... and I think you are not showing the full resolution of the `steady_clock`. Could you try `duration_cast(...).count()/1000.0` instead? – Ben Voigt Feb 01 '14 at 02:10
In line with the above qpc link, to return the qpc as microseconds I've temporarily amended the code to "PCFreq = double(li.QuadPart)/1000000.0;" and displayed the output as a separate window. – Jim Feb 01 '14 at 02:38
It was steady_clock I wanted to see in microseconds. I think you're rounding it unfairly right now. – Ben Voigt Feb 01 '14 at 03:29
Apologies, Ben, for the misread (a bit late last night). I've presented the new run data and altered window description to reflect the steady_clock conversion back to milli, this time from microseconds. – Jim Feb 01 '14 at 10:45
@Jim: Looks like you might be best off just using `steady_clock`, since it seems to have good precision as well. – Ben Voigt Feb 01 '14 at 18:24

odd behaviour using chrono::high_resolution_clock::now()

1 Answers1

Linked