17

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.

9
  • 10
    You haven't told us anything about what's happening between these measurements. Perhaps your app stalled? What happens if you print out DateTime.UtcNow at the same time?
    – Jon Skeet
    Aug 3, 2010 at 19:52
  • 4
    How are you guaranteeing that the code is called exactly every 200ms? Aug 3, 2010 at 19:53
  • 4
    buggy it may be, but not that buggy :)
    – µBio
    Aug 3, 2010 at 19:54
  • agreed. 10 seconds is unacceptable. Aug 3, 2010 at 20:01
  • 2
    Maybe you're assuming timers stop advancing when you hit a breakpoint? That's not the case, although it would be nice. I often see time-dependent code behave incorrectly because I spent a minute at a breakpoint and it assumes smaller intervals. Aug 3, 2010 at 20:08

3 Answers 3

17

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?

5
  • Understood, but the dispatcherTimer is simply monitoring the Stopwatch. The dispatcherTimer tick doesn't really need to be accurate for me... I just can't absorb a 10 second jump in my stopwatch :)
    – BabaBooey
    Aug 3, 2010 at 20:26
  • 1
    @Tim: Ok, hadn't seen your log file yet when I answered. Are you able to produce a small sample application to reproduce the artifact? By the way, you are able to edit your question and include additional information. Aug 3, 2010 at 20:33
  • 1
    Interesting. Unfortunately, I'm running on a small panel PC (with Windows Embedded Standard) that only has one CPU. I'm not very familiar with start.exe, but there is no AFFINITY switch available for me.
    – BabaBooey
    Aug 3, 2010 at 21:51
  • 3
    @Tim: Alright, this is actually an important fact that you are observing this on an embedded system and not a regular desktop PC. As the clock is based on hardware after all, this makes a hardware bug the most likely. Aug 3, 2010 at 22:00
  • That's what I was afraid of. I suppose I can roll my own stopwatch that doesn't use 'QueryPerformanceCounter'. It is especially frustrating when a library call doesn't work as advertised. I mean, I can deal with my stuff not working, but not somebody else's :)
    – BabaBooey
    Aug 3, 2010 at 22:08
15

Exact timing on PC hardware isn't straightforward, period. Here are some resources, showing some experiences with timing in Windows, which will be the underlying implementation of any counter in a Windows environment, including .NET:

It explains why sometimes you will get 10 ms resolution, depending on which system call you use, and sheds a little more light on why QueryPerformanceCounter is "buggy". One of the points made is that power saving modes/variable CPU speeds can interfere with these timings.

A related concept to this is "locking the timestep" in real-time physical simulations. If you google for that, you may get some ideas on how to work around problems you are having. The basic concept is that you have fixed time steps, and do a sort of producer/consumer implementation for your timing/update functions. I don't know if this applies to your specific domain, but it is considered a best-practices in video games.

5
  • 2
    10 ms resolution is fine for me... I'm seeing a 10 SECOND jump forward by the Stopwatch class.
    – BabaBooey
    Aug 3, 2010 at 20:00
  • I agree... 10 seconds is pretty nuts. Aug 3, 2010 at 20:01
  • 2
    Maybe, just maybe, 10 seconds actually passed? What was your program actually doing?
    – dlras2
    Aug 3, 2010 at 20:02
  • 5
    @Tim: This is the closest most people are going to get at guessing your problem. You'll have to show some minimal code that repros the problem, and give specifics about your environment for us to stop guessing :) Aug 3, 2010 at 20:02
  • 4
    Ten seconds may be "pretty nuts" but it's very possible if the GC kicks in. Aug 3, 2010 at 20:12
2

Perhaps I am misunderstanding your question, but do you need to just measure time intervals or do you need to execute code at those intervals? If you need to execute code, then check out System.Timers.Timer class as it is thread safe and should work fine for multi-processors.

1
  • Both :) I need to fire up a method every so often and I need to measure time intervals.
    – BabaBooey
    Aug 3, 2010 at 21:56

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.