Why Stop method is invoked many times in Topshelf

Question

Topshelf is working as the windows service broker in our application. This morning, we find that the Stop mehtod is invoked many times. Here is the related code.

class Program
{
    static void Main(string[] args)
    {
        ILog Log = new FileLog();
        try
        {
            HostFactory.Run(serviceConfig =>
            {
                serviceConfig.Service<ServiceManager>(serviceInstance =>
                {
                    serviceInstance.ConstructUsing(() => new ServiceManager());
                    serviceInstance.WhenStarted(execute => execute.Start());
                    serviceInstance.WhenStopped(execute => execute.Stop());
                });

            });
        }
        catch (Exception ex)
        {
            Console.WriteLine(ex);
            Log.Error("Program.Main", ex, LogType.Error);
            Console.ReadLine();
        };
    }
}

In the ServiceManager, we have the Stop mehtod, which will be invoked then TopShelf receives the stop signal from operation system.

class ServiceManager
{

    xxx.....

    public bool Stop()
    {
        try
        {
            _log.Info("The service is stopping", LogType.Info);
            _service.StopExecuteProduceMessage();
            Task.WaitAll(_tasks.ToArray());
            _log.Info("The service is stopped", LogType.Info);
        }
        catch (Exception ex)
        {
            _log.Error("Stop", ex, LogType.Error);
        }
        return true;
    }
}

This morning, we find the service is stopped with unclear reason. And there are many lines logging about this stop action.

I guess Topshelf invoke ServiceManager.Stop method many times. Anyone have encountered this problem before? I want to know I can trace why this happens.

Anyone can help? Many thanks.

Answer 1

You are experiencing this behavior because your Stop() method takes a while but is not being responsive to the request to stop.

Your method essentially looks like this:

Stop() {
   log-stopping;
   wait-a-while;
   log-stopped;
}

While you are waiting, the status of the service remains "Running". This causes the requester (could be Windows itself or another program) to keep re-sending the stop request, resulting in multiple parallel/overlapping calls to Stop(). That accounts for the first 10 lines in the log you included.

You can see that it takes almost 20 seconds for the "wait" to complete (from 05:39:45 to 05:40:04).

After that, it looks like Topshelf may be stuck. That causes more messages to be sent. (Notice that in the next lines in your log, the stopping and starting pairs are logged simultaneously because your tasks are stopped and there is no waiting).

To fix the problem, you should:

1. Modify your WhenStopped() call to pass the HostControl parameter to Stop():

   serviceInstance.WhenStopped((execute, hostControl) => execute.Stop(hostControl));

2. Update the Stop() method to take the HostControl parameter and make this call before the call to Task.WaitAll():

   hostControl.RequestAdditionalTime(TimeSpan.FromSeconds(30));

This will inform Windows that your service has received the request and may be working on it for up to 30 seconds. That should avoid the repeated calls.

Reference: Topshelf documentation