Kudu: App services swap behavior discussion

[xt0rted]

A few of us in the azure channel on the asp.net core slack (sign up page) were talking about the swap functionality and trying to figure out exactly how the auto swap setup works vs. what our expectations are of it. Is this under the kudu umbrella and can be talked about here, or is there somewhere else this should be talked about?

[davidebbo]

It's part of App Service and not really part of Kudu, but it's probably ok discussing here. You should start with http://ruslany.net/2015/09/how-to-warm-up-azure-web-app-during-deployment-slots-swap/. @ruslany is the expert on swap, and if there is missing info on that post, he may be able to clarify it.

[ctolkien]

From the linked blog post:

Then the site in the staging slot gets warmed up. To warm up the site an HTTP request is made to the root directory of the site to every VM instance where site is supposed to run. The warm up request has a User-Agent header set to “SiteWarmup”;
After warm up has completed the host names for the sites in production and staging slots get swapped.

It would be good to get some clarity around what "after warm up has completed" actually means. I can only assume that it _doesn't_ mean a 2XX status code is returned? In practice, if we perform a swap there can be ~60 seconds whilst the _live_ site is unresponsive (and in some cases, time outs, depending on the site).

This makes deployments _reaaally_ painful. The "two-step" "Swap with Preview" gets around this issue, but it's clumsy to use and isn't really integrated into "auto-swap" or the CI functionality in things like VSTS

[xt0rted]

I have some code that runs on site startup and can be turned on or off with an app setting. This is enabled in my warm up slot, and disabled in my production slot. I had a deploy yesterday where the swap happened without that piece of code running in the warm up slot. This is where some of my confusion starts. The docs seem to indicate that the site will be started up before the swap happens, yet in this instance it wasn't. I've added three endpoints under applicationInitialization but that doesn't seem to have made a difference.

I'm also experiencing what @ctolkien mentioned where the auto swap occurs, and then my site's down for a minute while it starts back up. The whole reason for wanting to use a deployment slot with swap was to prevent that.

Now that I'm using the deployment slot I've also seen my builds go from about 6-8 minutes to 20+ minutes. I'm not sure if that's including the swap time or not, but it seems once the post deploy webhook is fired the swap can take another 5 minutes or so to happen. I have two additional instances of this site running for internal use without deployment slots and those still take 10 minutes or less.

The final thing I've noticed is post swap my initial page load times go up as if the views are being compiled. I'm precompiling my views so I'm not really sure why initial page loads are in the 5 second range. I don't recall this being a problem before the slot & swap was setup.

[ruslany]

@ctolkien - having live site unresponsive during the swap is an unexpected behavior that we should investigate. The idea of the deployment slot swap is that the site that is in production slot is never restarted during the swap. Can you please let me know the name of the site where you have this repro and I'll look into this?

As to your question about what "warmup has completed" means, the current logic is as follows:

1. We first wait until site's worker process has been restarted and picked up the configuration changes (such as slot app settings and connection strings)
2. If local cache is enabled then we make a request to a root directory of the site and wait until it returns any status code and then keep polling it until the local cache initialization is complete
3. If AppInit warmup is enabled then we make a request to a root directory of the site and wait until it returns any status code and then keep polling it until the appinit module initialization is complete.

[ruslany]

@xt0rted - can you please let me know the name of your site and timeframe when you had a repro? I'll check in our logs to understand your site in production slot is being restarted.

[xt0rted]

@ruslany dummy1326 and it's the site with portal in its name. My deploys on 10/4 around 5:04 PM EST and the second around 8:27 PM EST (this is the one where the startup code didn't run in the warm up slot).

[ruslany]

@xt0rted I see that the site in the swap has completed in 2 minutes, but then the production slot was restarted at 2017-10-03 21:21:27.6907435 UTC, which is more than 10 minutes after the swap. The restart is unexpected and is caused by the bug that we have fixed, but have not yet enabled the fix worldwide. I'll enable it everywhere sometime this or next month, but meanwhile you can enable it just for your web app by adding this app setting to EVERY deployment slot:

WEBSITE_ADD_SITENAME_BINDINGS_IN_APPHOST_CONFIG = 1

@ctolkien - can you try the same and see if it makes any different for your case?

[xt0rted]

@ruslany I added that setting to my site and upon site restart received the following error on first page load, then all subsequent page loads were fine.

System.InvalidOperationException:
   at System.Web.Mvc.DefaultControllerFactory+DefaultControllerActivator.Create (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)
   at System.Web.Mvc.DefaultControllerFactory.GetControllerInstance (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)
   at System.Web.Mvc.DefaultControllerFactory.CreateController (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)
   at System.Web.Mvc.MvcHandler.ProcessRequestInit (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)
   at System.Web.Mvc.MvcHandler.BeginProcessRequest (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)
   at System.Web.Mvc.MvcHandler.BeginProcessRequest (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)
   at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.BeginProcessRequest (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)
   at System.Web.HttpApplication+CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute (System.Web, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a)
   at System.Web.HttpApplication.ExecuteStep (System.Web, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a)
Inner exception System.MissingMethodException handled at System.Web.Mvc.DefaultControllerFactory+DefaultControllerActivator.Create:
   at System.RuntimeTypeHandle.CreateInstance (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.RuntimeType.CreateInstanceSlow (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.RuntimeType.CreateInstanceDefaultCtor (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Activator.CreateInstance (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Activator.CreateInstance (mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089)
   at System.Web.Mvc.DefaultControllerFactory+DefaultControllerActivator.Create (System.Web.Mvc, Version=5.2.3.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35)

After the setting was in place I did a new deploy (around 4:07 PM EST). The build time was ~12 minutes and then ~5 minutes after the post deploy hook fired the site swapped. After the swap my first page load took at least 30 seconds. After that my second page load took about 30 seconds as well. Then all page loads seemed to load right away.

Something else I've noticed since setting up the deployment slot is my debug snapshots from app insights are no longer being captured. After setting up auto swap I did go back through and make sure app insights was setup on each slot, but the snapshots still aren't being captured. I'm not sure if this is due to a configuration change or possibly an issue with how that works. I can file a bug report on that repo if this is out of scope of the swapping.

[ruslany]

@xt0rted - Do you get this exception every time after restart of the site? One of the reason the fix hasn't been enabled everywhere is because there maybe side effects from it. If you get it every time then it is definitely caused by this setting.

In our logs I can see that when we started warming up the site by sending HTTP requests to the root directory of the site the latencies were anywhere from 20 to 50 seconds. Then the last ping latency was 2 seconds and after that we've performed the swap.

Then later I see that there were requests made from a browser to /prospective-buyers/signup and to /api/prospective-buyers/create-profile and those took 23 and 4 seconds respectively. After that all subsequent requests took no longer than 2 seconds.

Do you use AppInit module for your site and do you have those two URL paths included in its configuration?

[xt0rted]

@ruslany those requests were from me browsing the site after the deploy. The appinit module is setup with the following settings:

<applicationInitialization>
    <add initializationPage="/" hostName="***-staging.azurewebsites.net" />
    <add initializationPage="/heartbeat" hostName="***-staging.azurewebsites.net" />
    <add initializationPage="/account/login" hostName="***-staging.azurewebsites.net" />
</applicationInitialization>

Nothing special happens on those pages, I just added them in to see if anything changed during deploy.

[xt0rted]

@ruslany as far as I can tell that exception only happened once after first adding the setting, since then I haven't seen it.

[ruslany]

Ok, then it is not conclusive if this exception is the result of adding this new app setting.

Even if the root directory and other pages listed in AppInit module have been warmed up it still may be possible that other pages would take longer on the first hit. If you want them to be warmed up too then I would recommend adding them to the AppInit configuration.

The issue with debug snapshots and deployments slots is something I have not heard about before. We'll need to look into this.

[ctolkien]

The name of the site is dummy90210

OK, doing some testing right now. Doing a bunch of swaps (trying both the swap with preview, and direct swap).

Have had the production site return HTTP502 timeout - and be unresponsive.

We also had an error logged with resetting the slots be logged.

Visualised:

This does not have the WEBSITE_ADD_SITENAME_BINDINGS_IN_APPHOST_CONFIG = 1 in place - just testing vanilla at the moment.

[ruslany]

@ctolkien - yes, I see in our logs that the site is restarted for the same reason as in @xt0rted's case. The app setting should prevent that.

[ctolkien]

@ruslany - I put that app setting in place. It seems "improved", but still not seamless. We still logged 500 errors for timeouts (last part of graph):

And the response time shot up to 30 seconds:

[ctolkien]

No idea if related, but there is a stack of data usage in line with when swaps are taking place:

Also CPU usage spikes right up whilst this is taking place, which I guess makes sense... in that it is having to reboot the staged site - not sure if that is what is impacting the performance of the live site.

[xt0rted]

I triggered a swap with preview and as soon as I did my live site hung for about 20 seconds. When the swap was completed the site then hung again for another 20 seconds or so, second page load hung about that long as well, then the rest of the page loads seemed fine. This was completed around 7:11 PM EST.

I then triggered the swap again to get back to where I started. As soon as I did my live site hung for around 50 seconds on first page load, and 25 seconds on second page load then the rest were fine. Once the swap was completed the site then hung for around 20-30 seconds for first page load and a little less for the second. This was started at 7:14 PM EST and completed at 7:21 PM EST.

During the swaps I'm not seeing any 500 errors, the data in/out seems fine, requests are up some, and the average response time goes up.

[ruslany]

@xt0rted - I am wondering if these latency increases are caused by the fact that both production and staging slots run on the same VM instance so when the site in the staging slot is restarted during the first step of swap with preview it causes more CPU usage on the VM which affects the site in the production slot. Also after the swap is completed we restart the "used to be in production" site which again may increase the CPU usage. I see in the VM logs that CPU spiked around the time you performed the swap with preview.

We are in a process of enabling swap between slots that are located in different app service plans. With that you would be able to place production and staging slots in different VMs so that during the swap they do not affect each other's performance.

[xt0rted]

@ruslany right now kudu is doing my build & deploy, would moving this out to say AppVeyor with webdeploy help at all? That's been my plan all along (already using them for PR builds), I've just wanted to get a two stage deployment in place first.

I have two other sites and some functions running in this VM. None of them are doing much, but I could see about moving the functions out.

I also forgot about Local Cache. None of my sites store anything on disk that needs to be persisted between reboots, so if enabling that could help I can try doing that as well.

[ctolkien]

We are using AppVeyor, it's not making any difference.

We are in a process of enabling swap between slots that are located in different app service plans. With that you would be able to place production and staging slots in different VMs so that during the swap they do not affect each other's performance.

That's going to double my clients costs - they aren't going to wear that :/

[xt0rted]

@ruslany I did another deploy earlier and the same things happened, existing slot restarted, the staging slot started to warm up, then after the swap the new production slot restarted again. The deploy finished around 10:27 AM EST and the swap happened about 5 minutes later. Here's the cpu/memory graph from that time span.

We're running on a single S2 plan right now with zero traffic to the site when this deploy happened, and no webjobs of functions running (aside from the queue triggers polling). The only resources in use was kudu doing the build & deploy and I was the only user on the site.

Over the weekend I was looking around the web and I kept finding people asking about this same thing, why is the production slot restarting after swap. There's a number of these questions on Stack Overflow and Server Fault dating from this past July to over 2 years ago. Everyone asking about this seems to think that there should be no downtime and no cold start but runs into the similar issue of the slot restarting after swap, and the responses are just people reiterating what the docs & your blog post says. I've yet to find someone who says they're actually running with this setup working as intended.

[PureKrome]

@ruslany Hi Ruslan! I've also been a heavy user of deployment swaps for a while now - since they came out. We all totally understand the requirement for a restart when you have PINNED application settings. So that's ok.. .. but it feels like someting in the deployment workflow is not working _as expected_. It's like, something is out of step.

What we _expected_ was a deployment workflow like the following:

• Human swaps slot_a to slot_b
• LB takes slot_b _offline_
• normal stuff happens, like app settings are copied over, etc
• hit the 'offline' website to warm it up.
• wait for 200 OK (or whatever the requirements for 'website is warm/ok/online' is .. as mentioned above).
• * _At this point, the site is now considered READY if HTTP200OK was receieved_ *
• Tell LB to now stop pointing to the old slot and point to the new slot.

If _feels like_ the LB flips over to the new slot SOONER than it should and as such, starts sending requests to that way soon than it should, before the site is _really_ fully deployed, warmed and ready to rock'n'roll.

[xt0rted]

I just stumbled upon the xdt transform wiki page and the http to https redirect rule looks a little different from mine (I don't have the <add input="{WARMUP_REQUEST}" pattern="1" negate="true" /> condition). This has me wondering, could some of the issues we're seeing in regards to warm up be due to not having that condition in the rewrite rule? This Stack Overflow question from a few months ago seems to hint towards this as well.

[davidebbo]

@xt0rted it could be, is it could prevent the warmup requests from actually reaching your app.

[ctolkien]

We run CloudFlare (as does @PureKrome from what I understand) in front of all our sites - and it will redirect all HTTP requests to HTTPS before being sent on to our origin server. HTTP requests never reach us so if the WarmUp Service doesn't follow redirects this would be an explanation for what we're seeing.

[PureKrome]

As what @ctolkien said.

Also, we have other sites that use the URL redirection in the web.config and they do all http => https 301 PERM's.

[ruslany]

@ctolkien , @PureKrome - yes, warmup logic does not follow the HTTP redirects.

[xt0rted]

I've updated my url rewrite rule to include <add input="{WARMUP_REQUEST}" pattern="1" negate="true" />. I think this helps some since I'm not noticing any restarts or unresponsiveness during deploy, but that's as far as it goes towards the original issues. The exact changes I made was adding the rewrite condition, and changing the app init section to a single endpoint of / without any host.

What I've observed over my last few deploys is as follows:

1. deploy to the staging slot is triggered
2. staging slot builds & deploys
3. site warm up is triggered
4. auto swap is triggered the moment site warm up is finished
5. the now production slot restarts
6. 30 seconds later the production slot comes back up
7. about a minute or two later the now staging slot restarts
8. the production slot also restarts
9. 30 seconds later the production slot comes back up

Using the app insights live metrics view I can see the cpu peg at ~45% for a good 30 seconds or so each time the site starts up, so I can confirm with certainty that the staging slot is warming up before the swap happens.

I do have two slot settings, one of which is to keep my webjobs disabled in the staging slot since I don't want them running outside of the production slot. Given this setup, is it possible to achieve a zero downtime deployment as we're expecting?

[PureKrome]

@ruslany Thanks for the reply. So .. if we have a really simple .NET Website with a simple URL redirect rule => _any/all_ HTTP traffic gets redirected to HTTPS (which to me is a pretty damn common scenario) then ..

warmup logic does not follow the HTTP redirects.

which means the warmup logic doesn't apply.

If yes - then this is pretty damn serious.

Would be really nice if there's _an option in the Azure portal_ for us (the developers) to set the warmup URL because then we could :-

• define http or https
• define any route, like / or /health or /ping or whatever..

[ctolkien]

Yeah, that the warmup modules doesn't follow the standard HTTP status codes is a.) very surprising b.) seemingly undocumented. I would _strongly_ suggest it is a bug - just about everysite these days _should_ be automatically redirecting to HTTPS.

I've just attempted the following:

<rule name="Azure Exception" xdt:Transform="Insert" stopProcessing="true">
          <match url=".*" />
          <conditions logicalGrouping="MatchAll" trackAllCaptures="false">
            <add input="{HTTP_HOST}" pattern="myclient(-\w+)?\.azurewebsites\.net" />
          </conditions>
          <action type="None" />
    </rule>

This stops any further redirection that we have configured when hitting the site from the foo.azurewebsites.net host name.

Have also configured:

<applicationInitialization xdt:Transform="Insert">
      <add initializationPage="/" hostName="myclient.azurewebsites.net" />
    </applicationInitialization>

To hit the azurewebsites.net hostname, so as to _not_ run through CloudFlare.

Response time shows at 5 mins...

However, I don't know if I trust that figure, it could be from the "staging" side before promoted to production.

Am going to script out some tests to measure TTFB from a remote location whilst a swap takes place.

[ctolkien]

OK, it works!

I wrote a quick and dirty PowerShell script:

do {
    $elapsed = [System.Diagnostics.Stopwatch]::StartNew()
    Invoke-RestMethod $clientUrl -MaximumRedirection 0 | Out-Null
    Write-Host "Elapsed Time: $($elapsed.Elapsed.ToString())"
    Start-Sleep -Seconds 1
} while($true)

And the results are here:
https://gist.github.com/ctolkien/33e646c675f6da2455b1a49d852983fb

TL;DR - a few requests broke 1 second but nothing catastrophic. No timeouts, HTTP500's either.

[ctolkien]

OK wait, my solution shouldn't work:

<applicationInitialization xdt:Transform="Insert">
  <add initializationPage="/" hostName="myclient.azurewebsites.net" />
</applicationInitialization>

That is going to hit the production site, not the staging site (myclient-staging). I would think it's the staging site which needs to be warmed up prior to swapping.

[xt0rted]

@davidebbo where does WARMUP_REQUEST come from? I don't see this documented anywhere aside from being mentioned once in the wiki and in various stack overflow answers. I have that set and my warm up requests are making it through, but the AlwaysOn requests are still showing as getting 301 redirects. According to your SO answers this value should also work for always on, but I'm not seeing that.

[davidebbo]

@ruslany knows best, but I think it's something that comes from IIS and is not new to App Service. @ahmelsayed mentioned it in this old IIS AppInit post. It doesn't seem to be well documented though...

[xt0rted]

I turned auto swap off and I'm working with the manual swap for right now seeing if I can get that working. So far I'm not having any luck with that either.

That's a shot of my CPU after I triggered the swap. The 60-40 second range is when the staging slot was warming up, the 40-25 second range is after the warm up but before the actual swap, then the swap happened, and from 25-0 is when the production slot started back up.

This is 5-6 minutes later when I refreshed the 3 pages I had open from after the swap. All hung until the ~10 second mark when the cpu died back down, and it's been flat with instant page responses since then.

Upon further investigation I noticed in my log files that the site only ever started up once, but at the exact time of the cpu spike 5 minutes later there were these two groups of entries (not sure if they're both for the production slot, there's 8 log files for this timespan for some reason).

2017-10-17T04:37:10,Verbose,******,-1,SnapshotHelper::TakeSnapshotTimerCallback,
2017-10-17T04:37:10,Verbose,******,-1,SnapshotHelper::TakeSnapshotInternal - no new files in CodeGen,
2017-10-17T04:37:13,Verbose,******,-1,SnapshotHelper::TakeSnapshotTimerCallback,
2017-10-17T04:37:13,Verbose,******,-1,SnapshotHelper::TakeSnapshotInternal - no new files in CodeGen,

2017-10-17T04:40:36,Verbose,******,-1,SnapshotHelper::TakeSnapshotTimerCallback,
2017-10-17T04:40:36,Verbose,******,-1,SnapshotHelper::TakeSnapshotInternal - snapshot is newer than freshness threshold ,

That's all that I see regarding the snapshotter though and the only thing logged during that time.

[ruslany]

@PureKrome @ctolkien - the reason the warmup logic does not follow redirects is that because the warmup bypasses our frontends and goes directly to each worker that hosts the site. The workers do not have knowledge of HTTPS and custom domains, only frontends do. So if a site has rewrite rules to enforce a domain name or https then warmup code won't be able to make requests to the workers after redirect.

The suggestion to define a specific route to hit to initiate a warmup is interesting. I think we can add that capability.

The WARMUP_REQUEST is a server variable set by IIS AppInit module. When the first request to a site is made it starts the appinit module which in turn makes requests to all the URL paths listed in the appinit configuration section in the web.config file. All those requests have the WARMUP_REQUEST server variable set to 1.

[ruslany]

@ctolkien - when a first warmup requests is made to a site's worker process the AppInit module in that worker process starts and it makes internal child requests to all the URL paths listed in the configuration in web.config file. This appinit configuration that you used just means that when it makes HTTP request to the "/" page it will set the HTTP host header to myclient.azurewebsites.net. It does not mean that it will hit the production slot.

[ruslany]

@xt0rted - I assume you are still swapping this site ("dummy1326 and it's the site with portal"). I'll check our logs today to see what's going on.

[xt0rted]

@ruslany correct, same site

[ctolkien]

OK,

So I spent all of yesterday running every scenario and writing up a giant doc of everything I'd learned.. only to discover only one of the deployment slots was running the correct config and it was all for nought.

I _have_ managed 0 impact swaps on an S1 instance. Here you can see a user seamlessly transition from version 722 to 733:

Which is:

However it's the lead up to this swap that is the issue. I haven't nailed down the exact specifics, but it seems like rebooting the staging slot prior to swapping can put enough load to cause major issues for your production users - with response times peaking up to 30 seconds.

Then again, I've also had the CPU maxed and have no discernible impact on production users:

(Couldn't easily get a screen grab of the previous 40 seconds, but all requests were < 1 sec, some much faster).

So as things stand right now - the below is probably all wrong:

• Warmup _is_ working. I think. It seems the warmup request is fired to the staging slot at standard foo-slotname.azurewebsites.net hostname - this should not be impacted by CloudFlare.
• We had a canonical host name redirect in place which _would_ have stopped warmup requests making it through. Have had to add the following conditions:

<add input="{HTTP_HOST}" pattern="[\w\d-]+\.azurewebsites\.net$" negate="true" />
<add input="{WARMUP_REQUEST}" pattern="1" negate="true" />
<add input="{HTTP_USER_AGENT}" pattern="^AlwaysOn$" negate="true" />

• AlwaysOn suffers a similar fate re: not respecting redirects. I disabled CloudFlare and have logs of it hitting a random hostname that we have configured for production. Which makes it effectively useless for this scenario.

End of the day however, I still don't have seamless deploys. Having requests spike to 30 seconds still isn't good enough. More testing required to determine the secret sauce that had us swapping without requests to prod being majorly impacted.

[ruslany]

@xt0rted - for the swap that happened around at 2017-10-17 04:29:39.3249895 UTC I do not see in our logs any subsequent restarts of the site in production 5 minutes later. I see a couple of requests that took around 20 seconds shortly after the swap. One to the "/" and one to "/marketplace".

I've noticed that in your appinit configuration you only have this url path:

    <applicationInitialization>
      <add initializationPage="/heartbeat" />
    </applicationInitialization>

I recommend to add "/" there too. Without this what happens is that swap warmup makes request to the "/" page and gets redirected to HTTPS because at that point "WARMUP_REQUEST" is not set yet. So it does not actually warmup your application's root URL. If you add "/" there then appinit module will make request to the root and "WARMUP_REQUEST" will be set, so your redirect rule won't be executed.

[xt0rted]

@ruslany the reason I removed / is because that will redirect to the login page. I switched it for /heartbeat since that route always returns a 200 response and doesn't require auth. Should I still include an entry for / or does that not work in my setup?

Also there were no deployments on 10/17, the last one was 10/16/2017 around 11:42 PM EST. I guess my math was slightly wrong, isn't my deploy still about an hour earlier from what you're seeing in the logs?

[ruslany]

I see that there were deployments at the following times:
2017-10-17 03:44:34.6635553 UTC (which is close enough to 11:42 PM EST)
2017-10-17 04:26:33.6181898 UTC

In both cases I do not see the logs that would indicate that the site has been restarted any time soon after it got into production slot.

I would still try to include "/" there anyway. The redirect to login page happens from your application code, not from the rewrite rule. This means that at least some code path in app will be executed during warmup.

[npiasecki]

For what it’s worth, I also ran into the problem of cold starts after swaps after migrating some apps to Azure App Service, and I traced it to an HTTPS redirect rule. The request to / would get redirected to HTTPS, but that happens early enough that the juicy stuff in App_Start never ran, leaving it to the first real user request to wait on it. It made sense when I figured it out, but was not intuitive and will probably only get worse as HTTPS becomes the default.

<rewrite>
  <rules>
    <clear />
    <rule name="Do not force HTTPS for application initialization" enabled="true" stopProcessing="true">
      <match url="(.*)" />
      <conditions>
        <add input="{HTTP_HOST}" pattern="localhost" />
        <add input="{HTTP_USER_AGENT}" pattern="Initialization" />
      </conditions>
      <action type="Rewrite" url="{URL}" />
    </rule>
    <rule name="Force HTTPS" enabled="true" stopProcessing="true">
      <match url="(.*)" ignoreCase="false" />
      <conditions>
        <add input="{HTTPS}" pattern="off" />
      </conditions>
      <action type="Redirect" url="https://{HTTP_HOST}/{R:1}" appendQueryString="true" redirectType="Permanent" />
    </rule>
  </rules>
</rewrite>

[xt0rted]

For a few weeks now I've been doing manual swaps (no auto, no swap with preview). This has been giving me a better experience than the auto swap setup I had, but I haven't tried going back to auto swap since the url rewrite rule was updated to handle warm up requests.

What I'm seeing with this setup is all of my pages have a <200 ms load time until shortly after a swap is initiated. Once initiated the load times shoot up to 20-25 seconds. Based on the logs the site is not restarting when this happens. Instead it seems as if the "warmed up" pages need to be warmed back up. I'm not familiar with the inner workings of asp.net in this regard, but it's almost as if something with the swap initiation is invalidating a low level .net cache. The time it takes for this to happen seems to vary, it can be anywhere from a second or two after initiation on up to about 20 seconds later. Once the pages are "warmed up" again they have <200 ms load times until the swap finally happens.

I've adjusted my warm up end points so /, /account/login, and /account/register are all hit before the swap. The login & registration pages take a couple extra seconds and then they're <200 ms from there on out. Everything behind the login page hits the dB. What I've seen on these pages is there's a 20-30 second load time on most of these and then they settle in at <200 ms. While these pages are hanging the login & registration pages are responsive and continue to have <200 ms load times.

Once I realized this was happening I setup MiniProfiler in production. This is showing me that when I hit refresh after the swap my / page starts loading right away, but there's a 20-25 second hang on the first dB hit. Further investigation has shown that EF caches views/metadata on first hit and that there are some ways to pre-compile that but those resources are years old and I just haven't had a chance to try any of it out. The EF docs even mention this and the built-in apis to work around it, but there's no out of the box solution from EF.

As of now I want to try setting up a /warmup route that simply queries a couple of the dB tables for the first row and to include that in my list of warm up pages. I'm not sure how much time that may cut off from the other pages, but for now that's my next step. Once I see how that goes I'll try moving back to auto swap to see how that works.

---

As a side note, the profiling I've been doing has really opened my eyes up to just how poor EF's performance is if you're not really careful with it. For instance source.Skip(result.PageIndex * result.PageSize).Take(result.PageSize) doesn't generate a parameterized query, nor do most of my where clauses, while source.Skip(() => skip).Take(() => take) does. For the most part these things aren't bad without load, but they'll definitely become an issue with the resources available on Azure vs. local dev where most of them aren't even noticeable to me. I really wish the EF team had some Roslyn analyzers for these things since they do mention them deep in the docs where very few will see it.

[PureKrome]

@xt0rted _very_ interesting info there Brian!

One thing that I keep seeing is the HTTPS problem. I'm thinking about starting new side projects with _no_ https anymore. I used to always enforce it, etc. and then have the URL-Rewrite rule to force all http to https.

Instead, maybe now started playing with moving this concern to CLOUDFLARE. so the only public way into my website is via CF which terminates the HTTPS connection and then passes the query to my Azure App Service website as http, accepting that the traffic from CF->Azure _shouldn't_ be acceptable to a ManInTheMiddle attack.

This isn't a solution for all, though ... which means this problem still exists and hopefully can be resolved.

[ctolkien]

Instead, maybe now started playing with moving this concern to CLOUDFLARE.

We have CloudFlare do our HTTP -> HTTPS redirection currently but I'd still hesitate to remove HTTP -> HTTPS redirection rule from our site - if we happen to move away from CloudFlare, or it's temporarily disabled, etc. then it's easy to get overlooked.

At the moment, I think the best course of action is to have an IIS rule which matches on Warmup/AlwaysOn requests and then stops processing all further rules.

Canonical hostname, stripping trailing slashes, etc. there are other rules which can impact this too.

This also doesn't help with Always On either, but that is a discussion for another day.

[npiasecki]

While we're on the topic of restarts, the past week in East US my S2 instance has been booted to 3 different hosts, which seems a higher rate than normal (used to only happen about once every couple weeks).

In each case, the sites seem to warm up, but then I get a flurry of "can't write to filesystem" errors in my logs, and the new "Diagnose and solve problems" shows a double restart due to storage latency issues, causing 2-3 minutes of very slow response times. It's as if the system is booting me to a new host for upgrades (fine), but then after the LB switches to the new host, the new host immediately restarts due to latency, causing everything to go sideways for a few minutes.

Has East US been just having a lot of updates this week?

[ruslany]

I published a blog post that explains in more details how application initialization works and how to fix most common problems related to deployment slots: "Most common deployment slot swap failures and how to fix them"

[ctolkien]

So, what does this do then?

How is this implemented? What knock-ons does it have? etc...

Seems to have popped up in the last few weeks on the Custom Domains tab on App Services.

[davidebbo]

@ctolkien yes, this is a brand new feature, and is now the preferred way of forcing https. It all happens on the Front End server, so there is no need to make any changes to the app itself. This is controlled at ARM API level by the new httpsOnly flag on the site object.

[xt0rted]

Is there some place things like this get announced? I follow Azure/app-service-announcements but didn't see it there.

[davidebbo]

@xt0rted it should have been on there, but this tracker being new, things don't go there consistently enough. Hopefully we'll get better over time :)

[ctolkien]

@davidebbo , can we assume that as this happens on a server in front of our app, that all the app initialising bits discussed above are not impacted as they run local to the app?

[davidebbo]

@ctolkien correct. The redirection happens before the VM that has your code comes in the picture at all.

[xt0rted]

I switched from the https url rewrite rule to the https only option in the portal, and I'm noticing some interesting behavior that I wasn't getting before doing that. Post-swap the staging slot seem to start up but no always on requests come in for it according to the requests chart in the portal. If I curl -I https://thesite-staging.azurewebsites.net I get an instant response back and then the normal ~2 requests every minute or two starts back up.

The spike around 6:40 is when the initial deployment & swap was going on, and then right after 7:00 is when the swap finished. Prior to the swap I was getting ~2 requests consistently coming in from the always on option, but then afterwards they stopped.

When I first enabled the https only option I triggered a deployment that experienced similar issues post deployment but before the swap was initiated. In that instance the staging slot never started up pre-swap which I know for a fact because there's a piece of code that runs in the "staging" environment but not the "production" environment due to a sticky slot setting.

I'm not sure if this happens to the production slot because I have appinsights setup to poll a couple endpoints every 5 minutes since the always-on setting seemed flaky.

[npiasecki]

@davidebbo Does the HTTPS Only feature live at the slot level? I had it enabled, did a swap, and it was suddenly disabled, so it either does or I'm losing my mind

[ruslany]

It is not a slot setting. It stays with the site instance during the swap. So if you had it on for site in production slot and off for site in the staging slot then after swap it will be off in production slot and on in the staging slot. You'll need to explicitly enable it on all slots if you want to enforce https regardless of swap operations.

[xt0rted]

@ruslany @davidebbo I'm seeing mentions of a SnapshotHelper in my log file (this isn't new https://github.com/projectkudu/kudu/issues/2583#issuecomment-337119179), but according to the response I got from [email protected] these entries aren't from the app insights snapshot collector. Do either of you know what causes them? Their showing up in my log seems to almost always correspond to when I experience my slow requests (during & after swapping) but I can't find anything saying where they're coming from or what's causing them.

The log entries I saw earlier are:

SnapshotHelper::RestoreSnapshotInternal   SUCCESS - File.Copy
SnapshotHelper::RestoreSnapshotInternal   SUCCESS - process
SnapshotHelper::TakeSnapshotTimerCallback
SnapshotHelper::TakeSnapshotInternal   SUCCESS - Process
SnapshotHelper::TakeSnapshotInternal   SUCCESS - File.Copy

[npiasecki]

Continuing in this theme, I switched my sites to use the new HTTPS Only option and nuked my SSL rewrite rules in hopes that this would solve the cold starts I'm seeing during infrastructure upgrades when I get booted to a new VM. (Swaps work just fine, but I get nailed with cold starts when I get moved to a new VM, which Pingdom confirms by reporting it as a period of timeout > 30 s.)

It happened again today around 3:30 Eastern as I got booted for the Server 2016 upgrade. After studying my Application Insights logs, I noticed that my staging slots start once, but my production slots start twice (with different AppDomains), about 2 minutes apart, and Pingdom reports (and I experienced, since it was in the middle of the day) slow requests around the timestamps of the last restart.

I had enabled WEBSITE_LOCAL_CACHE_OPTION on my production slots some time ago in an attempt to minimize the number of restarts I experience, and now I feel it could explain why I'm getting hit with these double restarts on infrastructure upgrades.

Is it all possible that the load balancer is switching to the new VM when the normal content share is ready, serves a few requests successfully, then 1-2 minutes later the local cache is ready and the whole thing restarts, and bam! I see a cold start in production?

[pollax]

Hello, just checking in to see if there are any updates to this issue? We are too experiencing restart issues when swapping slots. Similar setup as previously mentioned, web-apps that enforce HTTPS but we also have Cloudflare.

I read the blog post by Ruslany, I tried to apply it, but I don't think it's working 100% for us still so wondering if there are any updates or what the suggested way forward is? With daily or multiple deploys per day, this becomes a severe issue that we will need to solve very soon.

[bsimser]

Just want to chime in. I have an open premier issue that has been going on for weeks now with our swaps. I've got a Teams call today to do some real-time diagnostics, but on one of our sites (I have a node in Canada East and one in Canada Central, load balanced behind Front Door) I have autoswap turned on. It seems that after we deploy to both nodes (using Octopus) it's literally 10 minutes before the swap "finishes" (even though the logs said they did 10 minutes ago) and the site shows the newly deployed code. The other sites in question (that I have the support call on) I've turned off autoswap (by Microsoft's request) and doing a manual stop, start, warmup, etc. and the swap is "better" (down to about 2-3 minutes after we deploy from 10) but the other issue is that a 2 minute swap overlaps between nodes, so Front Door sees the entire site down for 1-2 minutes. Less than desirable. I'll post any new findings today and information on autoswap vs. manual. These are all just web apps so no VMs involved.

[tmmueller]

@bsimser Any news? We can't figure out how to swap app service slots behind Front Door without downtime. It worked perfectly without Front Door.

[bsimser]

@tmmueller no word yet. There is a default 30 second timeout in Front Door that will cause a timeout. It's hard coded by default. The PG team just pushed a change out that allows you to change this value to something other than 30 seconds but there's no UI for it. Has to be done with PowerShell. I haven't tried it because as I told premier support (many times) this doesn't actually fix the problem of having both nodes go down at the same time. I've asked many times that I'm willing to manipulate Front Door with PowerShell to take a node down, do the deployment, bring the node back up (in the backend service) but haven't found any PowerShell to do this. Support continues to believe that increasing the default timeout beyond 30 seconds will fix this problem but I don't see how it can.

I've got two systems now, one using a series of steps to deploy the app node by node, and other just to push the updated app to the slot and let autoswap take care of it. Both nodes end up with an overlap of about 2 minutes when both nodes go down which IMHO is wrong. And deployment to the autoswap nodes finishes (as far as returning from the PowerShell command) but still doesn't actually kick in (i.e. you won't see the new site) until at least 10 minutes after that (and then both nodes kick in on top of each other and the entire system is down for 1-2 minutes with a lovely non-configurable non-brandable message from Front Door). Nobody seems to be able to answer me in support on my original questions.

Still trying to figure out a solution.

[tmmueller]

@bsimser Thanks for the details. We're going to try increasing the sendRecvTimeoutSeconds setting to see if we can at least get it to respond eventually rather than throwing errors at the end of the swap.

[cjblomqvist]

I've had the same issues as described above. More specifically, I don't have issues with random restarts, but issues during swapping. I'm on the P1V2 option, with both slots tied to that. It seems when the full swap process starts, the first step is to restart the deploy/stage slot, which causes CPU spikes. This in turn causes performance issues for everything on the same app service plan, since it's the same resources. I've confirmed this by doing the restart manually, which causes similar behavior.

It would be great to be able to isolate the deploy slot resource wise so that it doens't affect the production slot while starting/warming up. By not doing that, the slot swapping becomes much less valuable. The only solution I can see is to load balance between two completely (as in two different app service plans) environments, so you can deploy one environment at a time. Then again, I hoped the point of swapping slots was to not needing that...

PS. It's also very strange that the actual swapping takes so much time. 5+ minutes seems unreasonable. It would also be wonderful if the (re)start of an app doesn't take that long and use up that many resources, albeit I understand that's a trickier thing to deal with.

[bsimser]

@cjblomqvist the CPU spikes are worrysome. Like you mentioned the only option is to separate the nodes. That's what I have setup. I have a P2V2 node in Canada Central with a deployment slot, and the same in Canada East with Front Door load balancing between the two (pro tip: unless you set the latency sensitivity to something other than 0 it won't round-robin and the load will come from the nearest data centre, which in the case of Canada means you're probably always getting served up form one node only).

The problem with this approach (which still exists to this day) is that either using autoswap or manually starting the swap, there's an overlap of 1-2 minutes when both sides are down. Luckily this has decreased with the P2V2 nodes so it's hard to detect (and sometimes we get lucky and there's no downtime) but it's still not 100%. As for load balancing, at some point, hopefully the Traffic Manager AzureRm commands will be available for Front Door then I can just shut down one side, do the deployment to it, then bring the other side down but again in all my testing, there are delays everywhere when you run PowerShell commands and even though they finish you still might see the actual results for a few minutes.

Trying to achieve zero downtime seems almost impossible with the slot swapping behaviour so far for me.

[ctolkien]

1-2 minutes when both sides are down is in no way acceptable, especially running multiple instances with frontdoor!

We need to deploy updates and have them be seamless midway through users making purchasing decisions on our site. Likewise, we've discerned that it is the restarting of the staging slots which can wreak havoc on the CPU, which in turn impacts production users.

Would be awesome, to ... perhaps set the priority of that task to lower so that it doesn't impact production. I don't care if warming up staging takes another 30 seconds.

[pollax]

Another 3 months with no updates. Anyone heard anything?

[raaviiqbal]

We are trying to migrate from cloud services classic to app services and I ran into this exact issue - my production slot performance goes totally out of wack during a swap. It seems that the CPU on the staging spikes and causes the production response time to 10x.

Is there now a way to use 2 different app service plans one for prod and one for staging?

if not, how can people run production sites on app services? I'm going to have to abort this and keep my site on cloud services...

[cjblomqvist]

@raaviiqbal load balancing is most likely your only alternative to avoid the spikes (which will give you basically the same effect as swapping with two different resources, but less convenient)

[raaviiqbal]

@cjblomqvist gotcha - so the staging swap built into the app service stuff isn't really designed for a production system where it is unacceptable to have impacts to the production response time during swap?

I'm using Azure FrontDoor so would it basically work like this?

1) use ARM template to deploy an entirely new app service with it's own app service plan
2) warm it up and run automated tests on it
3) add it into the frontdoor as a backend
4) tell frontdoor to route all the traffic to the new backend
5) destroy the old backend

Sort of like what's described in @philliproux's article here: https://philliproux.com/post/azure-front-door-blue-green-deployments/

[cjblomqvist]

Yep, although it might make more sense to keep both up unless you're very budget constrained. @raaviiqbal

[raaviiqbal]

@cjblomqvist @bsimser @pollax @ctolkien - you can split the app service across app service plans now such that the prod slot is on a different plan than the staging slot - thereby eliminating the issue of the slot warmup bogging the CPU and affecting prod traffic. @ruslany cleared this up for me on his blog and I confirmed it has the desired effect.