2

I created simple program to determinate how long QueryPerformanceCounter call takes. It takes around 8 nanoseconds on my computer but from time to time I can see some spikes up to 500 usecs per call.

Some details:
Visual Studio 2013, C++

LARGE_INTEGER ll;
QueryPerformanceFrequency(&ll);
int steps = 10000000;
LARGE_INTEGER t1, t2;
long long dt=0, dtAvg=0, dtMax=0;
double NanoSecMult = 1000000000.0 / ll.QuadPart;
double UsecSecMult = 1000000.0 / ll.QuadPart;

for (int i = 0; i < steps; i++)
{
    QueryPerformanceCounter(&t1);
    QueryPerformanceCounter(&t2);
    dt = t2.QuadPart - t1.QuadPart;
    dtAvg += dt;
    if (dt>dtMax)
        dtMax = dt;
}
double dtd = dtAvg*UsecSecMult / steps;
double dtdMax = dtMax * UsecSecMult;
printf_s("steps: %d, dtAvg: %.12f usec, dtMax: %.6f usec\n", steps, dtd, dtdMax);

Output example:

... 
steps: 10000000, dtAvg: 0.008456895938 usec, dtMax: 3.893501 usec
steps: 10000000, dtAvg: 0.008427907056 usec, dtMax: 222.991405 usec
steps: 10000000, dtAvg: 0.008488256317 usec, dtMax: 452.353993 usec
steps: 10000000, dtAvg: 0.008457002125 usec, dtMax: 433.594398 usec
steps: 10000000, dtAvg: 0.008493247077 usec, dtMax: 9.910729 usec
steps: 10000000, dtAvg: 0.008432154511 usec, dtMax: 10.618638 usec
steps: 10000000, dtAvg: 0.008588921008 usec, dtMax: 480.670362 usec
...

So dtAvg is almost the same all the time with difference in last digits but dtMax jumps a lot from 2 usecs up to 550 usecs

Questions:

  1. Does anyone have any ideas why this can happen and if I can eliminate these spikes?
  2. Does it really take these 500 usecs for call (with blocking thread for this time) or it just returns "incorrect" values but doesn't effect thread execution?

Thank you.

1
  • I was concerned about your high dtMax values, so I've added another counter dt0 and incremented it if (dt == 0). Here are the numbers from four tests: 9,695,784, 9,659,654, 9,645,470, 9,708,995, or about 97% of all readings. Aug 27, 2015 at 16:17

1 Answer 1

6

At a guess, what's happening is that once in a while you're timing a process switch--that is, your process is running and returning successive values from the clock--but at some point, the process scheduler decides some other process should get a little CPU time (or at least the scheduler itself runs to figure out whether some other process should get some CPU time, anyway).

When that happens, one of the calls to QPC is going to show a much larger delta than most of the rest.

2
  • As well as process scheduling, another possible cause is hardware interrupts. Aug 19, 2015 at 14:05
  • 2
    The process switching may be confirmed by adding SetThreadPriority(GetCurrentThread(), THREAD_PRIORITY_TIME_CRITICAL); to the test, there will not be any 500us pauses. Aug 27, 2015 at 15:16

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.