Can the .NET Stopwatch class be THIS terrible?

BabaBooey picture BabaBooey · Aug 3, 2010 · Viewed 8k times · Source

I'm making an application that needs some pretty tight timing, and the Stopwatch class is the perfect solution. However, I noticed sometimes, when running on a small panel PC, the Stopwatch values were way off. I added some debug printouts that monitor the value of the stopwatch every 200 ms or so:

0:00:197
0:00:502
0:00:702
...
0:03:356
0:12:93

0:13:21
0:13:421
...

How could it possibly jump from ~3 seconds to ~13 seconds? I now see that the underlying function QueryPerformanceCounter() is buggy (Beware of QueryPerformanceCounter()), but I get the sense that something else is going on here.

Any insight is appreciated.

Update:

Here's a little more detail on my code: it's pretty straightforward. It's a WPF application that creates a new Stopwatch object on startup, and then kicks it off via Start(). I then create a DispatcherTimer, like so:

displayTimer = new DispatcherTimer(); 
displayTimer.Tick += display_Tick; 
displayTimer.Interval = DISPLAY_INTERVAL_TIMESPAN; 

where the timespan is 200 ms. My debug code simply prints out the value of the Stopwatch object every time the dispatchTimer ticks.

Update2:

A fun Microsoft support article is Performance counter value may unexpectedly leap forward.

Answer

Dirk Vollmar picture Dirk Vollmar · Aug 3, 2010

Update (after seeing your log)

As you already mentioned, the Stopwatch class uses the QueryPerformanceCounter function underneath. In the Remarks section MSDN says:

On a multiprocessor computer, it should not matter which processor is called. However, you can get different results on different processors due to bugs in the basic input/output system (BIOS) or the hardware abstraction layer (HAL). To specify processor affinity for a thread, use the SetThreadAffinityMask function.

As you are using the Dispatcher, QueryPerformanceCounter might not be executed on the same CPU every time that you query the elapsed time.

You can possibly check if the issue mentioned in MSDN is the reason for your problem by specifying a processor affinity for your process, e.g. by calling your executable using the start command. 10 seconds seems like a big lag between CPUs to me, but the documentation is very vague on how big the difference may be. The following command will bind your application to the first CPU:

> start.exe /AFFINITY 1 program.exe

If this should solve the issue you might want to have a look at the suggested workaround, i.e. calling the SetThreadAffinityMask function before querying the Stopwatch object.

Your comment said that you are using a WPF DispatcherTimer. The documentation of that class states:

Timers are not guaranteed to execute exactly when the time interval occurs, but they are guaranteed to not execute before the time interval occurs. This is because DispatcherTimer operations are placed on the Dispatcher queue like other operations. When the DispatcherTimer operation executes is dependent on the other jobs in the queue and their priorities.

This means that the timer event may arrive delayed, especially if the dispatcher is busy with other tasks. Did you place other things in the dispatcher queue that will prevent the event from triggering earlier?