Search code examples
.netazureazure-webjobsazure-webjobssdk

Continuous WebJob stopping_wait_time ignored?


After my yesterday's question (Continuous WebJobs and CancellationToken) I thought now I've understand the handling of continuous WebJobs and graceful shutdown and did some testing.

Additional Info

With https://myWebJob.scm.azurewebsites.net/api/continuouswebjobs I get:

{
    [some info ommited...]
    "type": "continuous",
    "error": null,
    "using_sdk": true,
    "settings": {
        "stopping_wait_time": 120
    }
}

At Thu, 31 Dec 2015 07:00:23 GMT I put a Stop to the Server, the following entries in the Dash Board are:


    [12/31/2015 07:00:23 > d71f29: SYS INFO] Status changed to Disabling
    [12/31/2015 07:00:28 > d71f29: SYS INFO] Detected WebJob file/s were updated, refreshing WebJob
    [12/31/2015 07:00:28 > d71f29: SYS INFO] Status changed to Stopping
    [12/31/2015 07:00:30 > d71f29: INFO] Job host stopped
    [12/31/2015 07:00:32 > d71f29: SYS INFO] Status changed to Success
    [12/31/2015 07:00:32 > d71f29: SYS INFO] Status changed to Stopped

And my running job ends at once without any further information. The last two lines of code of my function are the logging to the dashboard and writing an entry into a storage table. None of these entries are written... I've retried several times and everytime within 5 seconds the Job host stops. So:

Question

Is the "stopping_wait_time" value gracefully ignored for continuous WebJobs?


Solution

  • The stopping_wait_time setting is used by both Continuous and Triggered jobs. You can see how the Continuous job runner employs this setting here in the source code.

    I've uploaded a working sample demonstrating graceful shutdown here. In that sample I override the shutdown timeout to 60 seconds, and verify that my job function is able to perform 30 seconds of shutdown activity w/o being killed.

    Please download that sample and try it. You can also run the sample locally as detailed in the sample readme linked above. I also inline the sample function here showing how to use the CancellationToken:

    public static class Functions
    {
        [NoAutomaticTrigger]
        public static async Task GracefulShutdown(CancellationToken cancellationToken)
        {
            // Simulate a long running function, passing in the CancellationToken to
            // all async operations we initiate. 
            // We can also monitor CancellationToken.IsCancellationRequested in our code
            // if our code is iterative.
            try
            {
                await Task.Delay(TimeSpan.FromMinutes(10), cancellationToken);
            }
            catch (TaskCanceledException)
            {
                Shutdown().Wait();
            }
    
            Console.WriteLine("Function completed succesfully.");        
        }
    
        private static async Task Shutdown()
        {
            // simulate some cleanup work to show that the Continuous job host
            // will wait for the time configured via stopping_wait_time before
            // killing the process. The default value for stopping_wait_time is 5 seconds,
            // so this code will demonstrate that our override in settings.job
            // is functional.
            Console.WriteLine("Function has been cancelled. Performing cleanup ...");
            await Task.Delay(TimeSpan.FromSeconds(30));
    
            Console.WriteLine("Function was cancelled and has terminated gracefully.");
        }
    

    This function's 30 seconds of graceful shutdown logic runs successfully, as shown by the console output:

    • [12/31/2015 17:15:08 > 951460: SYS INFO] Status changed to Stopping
    • [12/31/2015 17:15:09 > 951460: INFO] Function has been cancelled. Performing cleanup ...
    • [12/31/2015 17:15:39 > 951460: INFO] Function was cancelled and has terminated gracefully.
    • [12/31/2015 17:15:39 > 951460: INFO] Function completed succesfully.
    • [12/31/2015 17:15:39 > 951460: INFO] Job host stopped
    • [12/31/2015 17:15:39 > 951460: SYS INFO] Status changed to Success
    • [12/31/2015 17:15:39 > 951460: SYS INFO] Status changed to Stopped