Using a timer in a Windows service - elapsed event handler keeps firing even when the timer is disabled

Question

I've read a lot of the posts related to Windows services and the use of timers, but I haven't found any reason why my event handler is still being triggered. Could anyone point me in the right direction? I want to know why this is happening so I understand how to avoid this in the future.

Edit: The onError event handler is never invoked (or I would have seen the event in the event log).

Timer: System.Timers.Timer
ServiceBase: System.ServiceProcess.ServiceBase

Here is the abstract class:

public abstract class ABCService : ServiceBase
{
    // Members
    protected Timer             invocationTimer;
    protected Timer             wellnessTimer;
    protected FileSystemWatcher fsw;


    // Constructors
    protected ABCService()
    {
        invocationTimer = new Timer();
        wellnessTimer   = new Timer();
        fsw             = null;

        invocationTimer.AutoReset = false;
        invocationTimer.Interval  = 30000; // 30 seconds
        invocationTimer.Elapsed  += new ElapsedEventHandler(invocationTimer_Elapsed);

        wellnessTimer.AutoReset   = false;
        wellnessTimer.Elapsed    += new ElapsedEventHandler(wellnessTimer_Elapsed);
    }


    // Methods
    protected void invocationTimer_Elapsed(object o, ElapsedEventArgs args)
    {
        try
        {
            // log to event log

            invocationTimer.Stop();

            if ((new FileInfo(fsw.Path + "\\" + fsw.Filter)).Exists)
            {
                onCreated(this, new FileSystemEventArgs(WatcherChangeTypes.Created, fsw.Path, fsw.Filter));
            }
        }
        catch (Exception x)
        {
            onError(this, new ErrorEventArgs(x));
        }
    }

    protected void wellnessTimer_Elapsed(object o, ElapsedEventArgs args)
    {
        try
        {
            // log to event log

            wellnessTimer.Stop();
            wellnessTimer.Interval = 60000; // ms

            if (fsw != null)
            {
                fsw.Dispose();
            }

            fsw = new FileSystemWatcher(ConfigurationManager.AppSettings["pathKey"], ConfigurationManager.AppSettings["filterKey"]);

            invocationTimer.Start();
        }
        catch (Exception x)
        {
            onError(this, new ErrorEventArgs(x));
        }
    }

    protected abstract void onCreated(object o, FileSystemEventArgs args);

    protected virtual void onError(object o, ErrorEventArgs args)
    {
        // log to event log

        wellnessTimer.Start();
    }

    protected override void OnStart(string[] args)
    {
        // log to event log

        wellnessTimer.Interval = 5000; // 5 seconds
        wellnessTimer.Start();
    }

    protected override void OnStop()
    {
        // log to event log

        wellnessTimer.Stop();
    }
}

Here is an instance class:

public partial class Service1 : ABCService
{
    // Members
    private static object locket = new object();
    private static DateTime LAST_RUN_TIME = DateTime.Now.AddSeconds(-10);


    // Constructors
    public Service1()
    {
        InitializeComponent();
    }


    // Methods
    protected override void onCreated(object o, FileSystemEventArgs args)
    {
        lock (locket)
        {
            // log to event log

            if ((DateTime.Now - LAST_RUN_TIME).Seconds >= 10)
            {
                // do stuff
            }
            else
            {
                // log to event log

                invocationTimer.Stop();
                invocationTimer.Start();
            }
        }
    }
}

Here is the autogenerated code for the partial class:

partial class Service1
{
    /// <summary> 
    /// Required designer variable.
    /// </summary>
    private System.ComponentModel.IContainer components = null;

    /// <summary>
    /// Clean up any resources being used.
    /// </summary>
    /// <param name="disposing">true if managed resources should be disposed; otherwise, false.</param>
    protected override void Dispose(bool disposing)
    {
        if (disposing && (components != null))
        {
            components.Dispose();
        }
        base.Dispose(disposing);
    }

    #region Component Designer generated code

    /// <summary> 
    /// Required method for Designer support - do not modify 
    /// the contents of this method with the code editor.
    /// </summary>
    private void InitializeComponent()
    {
        // 
        // Service1
        // 
        this.ServiceName = "Service1";

    }

    #endregion
}

So what exactly is happening? I'm looking at my event log and I see that once every minute the wellnessTimer event handler is invoked.

Here is what I think is happening, but I'm obviously wrong:

1. Service is started via MMC
2. OnStart() method is invoked
3. wellnessTimer interval is set to 5 seconds
4. wellnessTimer start method is invoked
5. wellnessTimer_Elapsed event handler is invoked
6. wellnessTimer stop method is invoked
7. wellnessTimer interval is set to 5 minutes
8. invocationTimer start method is invoked
9. 30 seconds later, the invocationTimer_Elapsed method is invoked
10. invocationTimer stop method is invoked

At this point both timers should still exist for this instance, but should be disabled. I debugged this via attach to process in Visual Studio 2010 and marked an ID for the object (sender) being passed into the event handlers. It is the same object as the instance. Also, both timers in the Locals window had their enabled property set to false.

This makes me thing I'm using inheritance incorrectly, or something is going on with threading. I'm not the best at either of those things, but if it is due to them please let me know so I can learn.

Thanks to everyone in advance.

Edit #2: Here is some trace data...

'o' represents the object passed into the event handler

ABCService() method invoked <--
ABCService() method invoked -->

Service1() method invoked <--
Service1() method invoked -->

OnStart() method invoked <--
OnStart() method invoked -->

wellnessTimer_Elapsed() method invoked <--
((System.Timers.Timer) o).Enabled  = False
((System.Timers.Timer) o).Interval = 5000
this.wellnessTimer.Enabled  = False
this.wellnessTimer.Interval = 5000
wellnessTimer_Elapsed() method invoked -->

invocationTimer_Elapsed() method invoked <--
((System.Timers.Timer) o).Enabled  = False
((System.Timers.Timer) o).Interval = 30000
this.invocationTimer.Enabled  = False
this.invocationTimer.Interval = 30000
invocationTimer_Elapsed() method invoked -->

wellnessTimer_Elapsed() method invoked <--
((System.Timers.Timer) o).Enabled  = False
((System.Timers.Timer) o).Interval = 60000
this.wellnessTimer.Enabled  = False
this.wellnessTimer.Interval = 60000
wellnessTimer_Elapsed() method invoked -->

invocationTimer_Elapsed() method invoked <--
((System.Timers.Timer) o).Enabled  = False
((System.Timers.Timer) o).Interval = 30000
this.invocationTimer.Enabled  = False
this.invocationTimer.Interval = 30000
invocationTimer_Elapsed() method invoked -->

Try to comment the wellnessTimer.Start() on the onError method. Maybe (just maybe) something is going wrong and the error event is fired? — Marcelo De Zen, Jul 24 '12 at 01:06
[The right direction is here](http://stackoverflow.com/a/246839/366904). — Cody Gray, Jul 24 '12 at 01:13
@CodyGray Aye, I read that too. But I will disagree with you. This application is designed to run continuously; the timers should not be firing on any predetermined intervals. — The Cog, Jul 24 '12 at 14:23
@devundef I updated my code to reflect the event logging. The onError event handler is never invoked. — The Cog, Jul 24 '12 at 14:59

Thomas C. G. de Vilhena · Answer 1 · 2012-07-24T01:17:19.150

From MSDN's remarks on the Timer class:

Elapsed events can occur after the Dispose or Stop method has been called or after the Enabled property has been set to false, because the signal to raise the Elapsed event is always queued for execution on a thread pool thread. One way to resolve this race condition is to set a flag that tells the event handler for the Elapsed event to ignore subsequent events.

So you can do something like this inside your event handler to prevent executing it after the timer has been disabled:

private static void OnTimedEvent(object source, ElapsedEventArgs e)
{
    if (timer.Enabled)
    {
        Console.WriteLine("The Elapsed event was raised at {0}", e.SignalTime);
    }
}

I understand how it can be invoked after the Stop() method has been called, but 60 seconds after the Stop() method has been called? For the purposes of this thread and testing, that number is lowered. It used to be 5 minutes, and the event was still being fired. — The Cog, Jul 24 '12 at 15:06

score 0 · Answer 2 · answered Jul 24 '12 at 01:21

0

Are you experiencing the problem with the code exactly as you provided, or would it be dependent on code around:

       // depending on logic, these next two lines will be called together or not at all

Based on what I read from the code, the wellness timer will fire every 60 seconds when it encounters an error on the onCreated call. If this is doing file operations, the one thing that screams out is security permissions for the account the service is running as.

When catching an exception, Output it to the event log or a log file. Behaviour by exception can easily lead to confusing situations, especially where it's not so convenient to hook up a debugger.

answered Jul 24 '12 at 01:21

Steve Py

15,253
1
18
29

Aye, I cleaned up my code before I posted it. I will rewrite my code and update it shortly. Perhaps that will help. – The Cog Jul 24 '12 at 14:28
ok, a couple things: 1) Have you put a log output inside your onCreated handler? Ensuring it's running without throwing an exception. 2) The time check looks like you intend for something to check every 10 seconds? You'll want .TotalSeconds. .Seconds will give you the Seconds component of the time difference. Wouldn't be a problem unless something took between x:00-x:09 long. where x=1 minute or more. This assumption can cause wacky bugs if used in other scenarios, not necessarily this one. :) – Steve Py Jul 26 '12 at 00:53
I was able to figure it out, but I had to rewrite it. It is completely blowing my mind why when all of the timers are disabled that they are still triggering the elasped event. I will post the rewritten code, as well as the legacy code for comparison. Perhaps this will lead to a definitive answer and I will finally know why! :) Thanks for your help! 1) Yes, I actually commented out the entire guts of the onCreated event handler in the implementing classes. 2) The goal is to use an extended FileSystemWatcher and tie the onError event handler into it so I can fix its bad state. – The Cog Jul 27 '12 at 00:12

Using a timer in a Windows service - elapsed event handler keeps firing even when the timer is disabled

2 Answers2