Timer randomly doesn't fire

Question

I have code that looks like this

mTestModeMetadataTimer = new System.Threading.Timer(SomeTimerCallback, null, 1000, Timeout.Infinite);

Stopwatch tmStopwatch = new Stopwatch();

private void SomeTimerCallback(object state)
{
    // doing minimal work here

    Console.WriteLine("{0}: SomeTimerCallback time: {1}", System.Threading.Thread.CurrentThread.ManagedThreadId, tmStopwatch.ElapsedMilliseconds);
    tmStopwatch.Restart();

    // Better to be on the safe side and do this slightly more than once per second, than slightly less.
    mTestModeMetadataTimer.Change(990, Timeout.Infinite);
}

Everything works fine except that occasionally there's a huge delay between timer events as seen in this console output.

 31: SomeTimerCallback time: 998
 21: SomeTimerCallback time: 997
 20: SomeTimerCallback time: 999
 3: SomeTimerCallback time: 989
 3: SomeTimerCallback time: 1000
 3: SomeTimerCallback time: 994
 37: SomeTimerCallback time: 999
 3: SomeTimerCallback time: 991
 29: SomeTimerCallback time: 1002
 37: SomeTimerCallback time: 1000
 3: SomeTimerCallback time: 17568
 3: SomeTimerCallback time: 999
 29: SomeTimerCallback time: 993

This is a small portion of a pretty sizable application. The same behavior existed with a System.Timers.Timer and, in fact, occurs for various other times throughout the application. I added the thread ID to the console output of this particular timer to hopefully gain a little more insight as to why there's a random 17.5 second elapsed time among the correct one second events.

Is there something I'm obviously doing wrong? Perhaps there's some more data I can gather to figure out why my timers are acting funny?

Any suggestions here would be greatly appreciated.

Are you doing other things in your program that would cause a large number of threads in the thread pool to be in use? — Scott Chamberlain, May 28 '14 at 14:00
There are quite a lot of threads being thrown around (unfortunately, we're stuck using a third party library that uses a ridiculous amount of threads). For this particular instance, the application had approximately 250 threads, with a total cpu usage of about 11% (i7 4770). — Afcrowe, May 28 '14 at 14:09

score 2 · Answer 1 · edited May 23 '17 at 11:57

2

From your comment the reason this happens is you are exhausting the threads in the thread pool. Because every thread was in use the timer had to wait 17.5 seconds for a thread to become available before it could run.

Your options as I see it are either increase the max number of threads in the thread pool or use a different timer that does not use the thread pool (~~System.Timers.Timer with a synchronization object that does not use the thread pool~~(Still uses the thread pool to kick it off) or a System.Windows.Forms.Timer with a message pump running)

edited May 23 '17 at 11:57

Community

1
1

answered May 28 '14 at 14:20

Scott Chamberlain

124,994
33
282
431

1

`System.Timers.Timer` uses the threadpool, even when the `SynchronizingObject` is set. The callback is initially executed on a threadpool thread, which then does a `BeginInvoke` on the synchronizing object's thread. See http://referencesource.microsoft.com/#System/services/timers/system/timers/Timer.cs#897683f27faba082 for details. – Jim Mischel May 28 '14 at 14:32
Just checked what the threadpool size was with System.Threading.ThreadPool.GetMaxThreads(), and it came back with 2047 worker threads, and 1000 completion port threads. I think I'm well under the point of exhausting the threadpool. – Afcrowe May 28 '14 at 14:37
@Afcrowe It is the only thing I can think of that would describe that behavior. – Scott Chamberlain May 28 '14 at 14:41
Check available threads instead of maximum threads: `ThreadPool.GetAvailableThreads`. That will give you more accurate information, instead of assuming that you don't reach maximum number of threads. – Edin May 28 '14 at 15:05

Edin · Answer 2 · 2014-05-29T13:40:39.313

System.Threading.Timer invokes an event handler on a worker thread obtained from the CLR thread pool. If the thread pool is in starvation, it may happen that the callback is queued until the thread is freed.

To check if you are exhausting the thread pool, you can log the number of available threads periodically while debugging:

int workerThreads;
int completitionPortThreads;
System.Threading.ThreadPool.GetAvailableThreads(out workerThreads, out completitionPortThreads);

score 0 · Answer 3 · answered May 28 '14 at 14:04

0

Try with the periodic in the Timer constructor :

mTestModeMetadataTimer = new System.Threading.Timer(SomeTimerCallback, null, 1000, TimeSpan.FromMilliseconds(990));

Are you sure you weren't in debug mode and you let the time go before continue ?

answered May 28 '14 at 14:04

Poppyto

554
8
17

Definitely not caused by a breakpoint or user interference. I can start my release build and walk away for ten minutes, and when I come back I see these long wait times littered throughout the log. – Afcrowe May 28 '14 at 14:14

Timer randomly doesn't fire

3 Answers3