Scaling up/down of Azure App Service not working as expected

Question

Scaling up/down of Azure App Service not working as expected

Mo Becker 11

Requirements

I need to run an App Service that fulfils two requirements:

Only at most one instance should be running at any time.
The App Service should never terminate without graceful shutdown.

Problem

Even when the App Service is configured as Single Instance and the environment variable WEBSITE_DISABLE_OVERLAPPED_RECYCLING is set to 1 both requirements are violated:

After a scale up/down of the App Service Plan, there are two instances running continuously.
Instances are sometimes terminated without graceful shutdown after scale up/down, but also after auto recycle due to Azure update/maintenance.

Code to reproduce problem

To reproduce the problem, publish the following code to an App Service (S1, Single Instance, Windows, .NET 6.0, 64 bit, Always On) and set WEBSITE_DISABLE_OVERLAPPED_RECYCLING to 1. Then start the App Service and scale up the App Service Plan. The produced log file log.txt shows the problem.

public class Program
{
    /// <summary>
    /// A fresh ID for each instance.
    /// </summary>
    public static Guid InstanceId = Guid.NewGuid();

    public static void Main(string[] args)
    {
        WebApplicationBuilder builder = WebApplication.CreateBuilder(args);
        builder.Services.AddHostedService<Worker>();

        builder.Logging.AddEventLog();
        WebApplication app = builder.Build();

        app.MapGet("/", () =>
        {
            Helper.Log($"Hello world!");
            return "Hello World!";
        });
        app.Lifetime.ApplicationStarted.Register(() =>
        {
            Helper.Log($"Application started");
        });

        app.Lifetime.ApplicationStopping.Register(() =>
        {
            Helper.Log($"Application stopping");
        });

        app.Lifetime.ApplicationStopped.Register(() =>
        {
            Helper.Log($"Application stopped");
        });
        app.Run();
    }
}

/// <summary>
/// This just writes a message every 10 s to show that the instance is still alive.
/// </summary>
public class Worker : BackgroundService
{
    protected override async Task ExecuteAsync(CancellationToken stoppingToken)
    {
        int n = 0;
        while (!stoppingToken.IsCancellationRequested)
        {
            n++;
            Helper.Log($"Tick {n}");
            await Task.Delay(10000, stoppingToken);
        }
    }

    public override void Dispose()
    {
        base.Dispose();
        Helper.Log($"Ticker disposed");
    }
}

public static class Helper
{
    /// <summary>
    /// Write a log message with timestamp and the instance ID.
    /// </summary>
    /// <param name="msg"></param>
    public static void Log(string msg)
    {
        File.AppendAllLines(@$"c:\home\logfiles\log.txt", new[] { $"{DateTime.Now:O} - {Program.InstanceId} - {msg}" });
    }
}

Produced log file

The following log file exhibits both problems. I manually added the comments preceded by // for clarity.

2023-02-23T15:00:20.7857343+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Tick 1
2023-02-23T15:00:20.8299496+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Application started
2023-02-23T15:00:20.8545424+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Hello world!
2023-02-23T15:00:29.3072338+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Hello world!
2023-02-23T15:00:30.8106730+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Tick 2
2023-02-23T15:00:39.2719595+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Hello world!
2023-02-23T15:00:40.8339116+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Tick 3
2023-02-23T15:00:50.8595909+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Tick 4
2023-02-23T15:01:00.8838360+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Tick 5
2023-02-23T15:01:07.7440347+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Application stopping // Scale down initiated from P1V3 to S1
2023-02-23T15:01:07.7558963+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Application stopped // The old instance had a graceful shutdown :-)
2023-02-23T15:01:07.7869120+00:00 - e1f642cd-7226-4082-b5b4-c0f5060f02cc - Ticker disposed
2023-02-23T15:01:24.6284686+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 1
2023-02-23T15:01:24.6737150+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Application started // A new instance started :-)
2023-02-23T15:01:24.7218975+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Hello world!
2023-02-23T15:01:34.6468119+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 2
2023-02-23T15:01:44.6597262+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 3
2023-02-23T15:01:47.2223367+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 1
2023-02-23T15:01:48.2358619+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Application started // A second instance suddenly started, why??? :-(
2023-02-23T15:01:48.6327758+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:01:49.0533174+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:01:49.2142027+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:01:49.8240615+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:01:54.6715264+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 4
2023-02-23T15:01:58.0032448+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 2
2023-02-23T15:01:59.5559042+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:02:04.6945103+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 5
2023-02-23T15:02:09.3405433+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 3
2023-02-23T15:02:09.9822647+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:02:14.7071506+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 6
2023-02-23T15:02:20.6952788+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 4
2023-02-23T15:02:24.7302992+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 7
2023-02-23T15:02:33.2630139+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 5
2023-02-23T15:02:34.7402361+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 8
2023-02-23T15:02:43.8932127+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 6
2023-02-23T15:02:44.7528576+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 9
2023-02-23T15:02:53.9810994+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 7
2023-02-23T15:02:54.7738825+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 10
2023-02-23T15:03:04.0594280+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 8
2023-02-23T15:03:04.7899118+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 11
2023-02-23T15:03:14.0815877+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 9
2023-02-23T15:03:14.8048416+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 12
2023-02-23T15:03:24.2213344+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 10
2023-02-23T15:03:24.8230745+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 13
2023-02-23T15:03:30.1624638+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:03:32.6929313+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:03:34.4860609+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 11
2023-02-23T15:03:34.8437309+00:00 - 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 - Tick 14 // This instance suddenly dies without graceful shutdown :-(
2023-02-23T15:03:39.3089911+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:03:44.6882410+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 12
2023-02-23T15:03:46.4742756+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 1
2023-02-23T15:03:46.5255954+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Application started // Yet another instance started :-(
2023-02-23T15:03:46.5668066+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Hello world!
2023-02-23T15:03:55.2507575+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 13
2023-02-23T15:03:56.4995971+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 2
2023-02-23T15:04:05.9076464+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 14
2023-02-23T15:04:06.5180670+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 3
2023-02-23T15:04:15.9488660+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 15
2023-02-23T15:04:16.5316429+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 4
2023-02-23T15:04:26.0047521+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 16
2023-02-23T15:04:26.5418576+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 5
2023-02-23T15:04:36.0339082+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 17
2023-02-23T15:04:36.5578078+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 6
2023-02-23T15:04:46.0579240+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 18
2023-02-23T15:04:46.5741412+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 7
2023-02-23T15:04:48.9724404+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:04:49.2280636+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:04:49.4796442+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:04:49.8836912+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:04:50.1474741+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:04:50.4147617+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:04:56.0805844+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 19
2023-02-23T15:04:56.5961556+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 8
2023-02-23T15:05:06.0977331+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 20
2023-02-23T15:05:06.6180789+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 9
2023-02-23T15:05:11.1257974+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:05:11.4018641+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:05:11.6721724+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:05:11.9601453+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:05:12.2497483+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:05:12.5267465+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Hello world!
2023-02-23T15:05:16.1479352+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 21
2023-02-23T15:05:16.6370800+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 10
2023-02-23T15:05:26.1592402+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 22
2023-02-23T15:05:26.6645655+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 11
2023-02-23T15:05:36.2102495+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 23
2023-02-23T15:05:36.6878044+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 12
2023-02-23T15:05:46.2341964+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 24
2023-02-23T15:05:46.7041762+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 13
2023-02-23T15:05:56.2505812+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 25
2023-02-23T15:05:56.7149913+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 14
2023-02-23T15:06:06.2745368+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 26
2023-02-23T15:06:06.7306221+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 15
2023-02-23T15:06:16.2886601+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 27
2023-02-23T15:06:16.7473395+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 16
2023-02-23T15:06:26.3002791+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 28
2023-02-23T15:06:26.7643961+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 17
2023-02-23T15:06:36.3133650+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 29
2023-02-23T15:06:36.7801386+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 18
2023-02-23T15:06:46.3383480+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 30
2023-02-23T15:06:46.7940874+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 19
2023-02-23T15:06:56.3773579+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Tick 31
2023-02-23T15:06:56.8101851+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Tick 20
2023-02-23T15:06:57.2054456+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Application stopping // Stop button was pressed in Azure Portal
2023-02-23T15:06:57.3000267+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Application stopped
2023-02-23T15:06:57.3275943+00:00 - 30c23de4-e5d5-436f-84f7-9036934fd054 - Ticker disposed
2023-02-23T15:06:58.6198039+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Application stopping
2023-02-23T15:06:58.6310443+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Application stopped
2023-02-23T15:06:58.6401636+00:00 - a9e39e6f-b328-4668-b77f-b84adc5fc247 - Ticker disposed // Two instances shut down gracefully, but 5aa1dcca-ed6a-4256-b34f-cde5ed3281d5 just vanished :-(

1 answer

Your answer

Answer 1

Ryan Hill 29,936 Microsoft Employee

@Mo Becker apologies for the delayed response. So, by setting WEBSITE_DISABLE_OVERLAPPED_RECYCLING to 1, you effectively disabled the setting which results in the behavior what you're seeing. Use 0 to ensure that at least one instance is running when recycled; however, as stated, using 1 to disable this feature could lead to increased downtime due to file locks. So, use this setting as you see what's best fitting for your application.

Feel free to comment down below if you have any follow up questions.

Mo Becker 11 Reputation points

2023-03-01T10:28:58.9066667+00:00

@Ryan Hill Shouldn't setting WEBSITE_DISABLE_OVERLAPPED_RECYCLING to 1 disable overlapping executions? That's exactly what we want, as I have described at the beginning of my question. But as you can see from the logs we are still getting two executions that are running simultaneously. That's clearly a bug in Azure.

And there is also the second bug, which is that instances are sometimes terminated without graceful shutdown.
Ryan Hill 29,936 Reputation points Microsoft Employee

2023-03-01T13:58:09.7333333+00:00

Sorry for the misunderstanding. Just to make sure I'm understanding, is your intent to ensure a single instance is left running during a scale in/recycle operation, correct?
Mo Becker 11 Reputation points

2023-03-14T08:54:45.1966667+00:00

Yes, I want to ensure that only a single (i.e. at most one) instance is running at any given time. And even more importantly, I want to ensure that every instance receives an ApplicationStopping signal before terminating, especially when Azure schedules a maintenance upgrade.
Martin Meixger - Internet Consulting 1 Reputation point

2024-08-19T06:39:52.07+00:00

I see a similar behavior on App Service when platform events occur on single (scale=1) instances:
Seems that App Service doesn't wait long enough for the old process to exit.
A new process is started when the old one is still running and logging.

I suspect, that on WEBSITE_DISABLE_OVERLAPPED_RECYCLING is useless when the 2nd instance is started on a new VM (App Service Plan).

It would be nice to have a more technical explanation how this works (App Service team, Kudu team) under the hood.

Share via

Scaling up/down of Azure App Service not working as expected

Requirements

Problem

Code to reproduce problem

Produced log file

1 answer

Your answer