Why do unexpected Timer Elapsed Events fire in my application? [Josh Free]
General Timer Background Information
The System.Timers.Timer class provides a convenient way for .NET programmers to create a timer thread that fires events after elapsed time intervals. For more details on using System.Timers.Timer please refer to the MSDN Timer Class documentation: http://msdn.microsoft.com/library/default.asp?url=/library/en-us/cpref/html/frlrfsystemtimerstimerclasstopic.asp.
Scenario
Earlier this year, we were contacted by a programmer who was experiencing weird Timer behavior in their application. This person wanted to use timers to have their application continuously execute a time-intensive task with a four (4) second pause between tasks. However, their application behaved very strangely – firing elapsed events at seemingly random intervals. It turned out that the odd behavior was caused by two factors:
1. The Interval was reset near the start of the ElapsedEventHandler method – which started the next four (4) second countdown
2. The time-intensive task was started after the Interval was set and it sometimes ran longer than four seconds.
(Buggy) Code Example
Here’s a sample C# application that creates a Timer to fire after four (4) seconds. After the initial four seconds, the BuggyHandler ElapsedEventHandler is called to handle the ElapsedEvent:
|
using System;
using System.Timers; // Timer
using System.Threading; // Thread.Sleep & Interlocked.Increment
public class Timer1
{
static int count = 0;
static System.Timers.Timer aTimer;
public static void Main()
{
aTimer = new System.Timers.Timer();
aTimer.Elapsed +=
new ElapsedEventHandler(BuggyHandler);
aTimer.AutoReset = false;
// set the initial timer interval to 4 seconds
aTimer.Interval = 4000;
DateTime now = DateTime.Now;
Console.WriteLine("Main: " + now + " " + now.Millisecond);
aTimer.Enabled = true;
Console.WriteLine("Hit [Return] to quit.");
Console.Read();
}
// This Elapsed Time Event Handler has a bug – the Timer Interval
// is set near the beginning of the method right before a
// long-running task occurs. The reset timer fires again
// before this event handler has a chance to finish!
private static void BuggyHandler(object source,
ElapsedEventArgs e)
{
DateTime now = DateTime.Now;
Console.WriteLine("BuggyHandler["
+ count + "]: " + now
+ " " + now.Millisecond);
// the timer countdown begins as soon as Interval is set
aTimer.Interval = 4000;
// sleep for 7 seconds to simulate an event handler that
// performs a long-running task. While the handler works
// on its “task” the 4 second interval expires...
Thread.Sleep(7000);
// calling Start() resets the timer to 4 seconds
aTimer.Start();
Interlocked.Increment(ref count);
}
} |
Buggy Program Output
Here is the output from the program above. There are two things you should notice about this output:
- The first two lines both have zero (0) for their printed “count”
- The time between events is oscillating between four (4) and seven (7) seconds
|
Main: 3/31/2006 2:41:30 PM 262
Hit [Return] to quit.
BuggyHandler[0]: 3/31/2006 2:41:34 PM 284
BuggyHandler[0]: 3/31/2006 2:41:38 PM 291
BuggyHandler[1]: 3/31/2006 2:41:45 PM 302
BuggyHandler[2]: 3/31/2006 2:41:49 PM 309
BuggyHandler[3]: 3/31/2006 2:41:56 PM 321
BuggyHandler[4]: 3/31/2006 2:42:00 PM 328
BuggyHandler[5]: 3/31/2006 2:42:07 PM 339
BuggyHandler[6]: 3/31/2006 2:42:11 PM 346
BuggyHandler[7]: 3/31/2006 2:42:18 PM 358
BuggyHandler[8]: 3/31/2006 2:42:22 PM 364
BuggyHandler[9]: 3/31/2006 2:42:29 PM 376
BuggyHandler[10]: 3/31/2006 2:42:33 PM 383 |
Corrected Code Example
Here is the fixed ElapsedEventHandler. Instead of setting the Interval near the beginning of the method, the Interval is set at the very end.
|
// This Elapsed Time Event Handler does not have
// Re-entrancy problems because the AutoReset=false and
// the Interval is not set until the very end of the method
private static void FixedHandler(object source,
ElapsedEventArgs e)
{
DateTime now = DateTime.Now;
Console.WriteLine("FixedHandler["
+ count + "]: " + now
+ " " + now.Millisecond);
// sleep for 7 seconds to simulate an event handler that
// performs a long-running task.
Thread.Sleep(7000);
// the timer countdown begins as soon as Interval is set
aTimer.Interval = 4000;
Interlocked.Increment(ref count);
} |
Corrected Program Output
Here is the output using the fixed ElapsedEvent handler from the code sample above. In this example, the first two lines now correctly print zero and one in brackets ([0] [1]) instead of zero and zero ([0] [0]). Also the time between events is now always eleven (11) seconds (because of the 7 second sleep followed by the 4 second Interval).
|
Main: 3/31/2006 2:44:20 PM 30
Hit [Return] to quit.
FixedHandler[0]: 3/31/2006 2:44:24 PM 53
FixedHandler[1]: 3/31/2006 2:44:35 PM 71
FixedHandler[2]: 3/31/2006 2:44:46 PM 89
FixedHandler[3]: 3/31/2006 2:44:57 PM 108
FixedHandler[4]: 3/31/2006 2:45:08 PM 126
FixedHandler[5]: 3/31/2006 2:45:19 PM 145
FixedHandler[6]: 3/31/2006 2:45:30 PM 163
FixedHandler[7]: 3/31/2006 2:45:41 PM 182
FixedHandler[8]: 3/31/2006 2:45:52 PM 200
FixedHandler[9]: 3/31/2006 2:46:03 PM 219
FixedHandler[10]: 3/31/2006 2:46:14 PM 237
FixedHandler[11]: 3/31/2006 2:46:25 PM 255 |
