Why do unexpected Timer Elapsed Events fire in my application? [Josh Free]

  • Article

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: https://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:

  1. The first two lines both have zero (0) for their printed “count”
  2. 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