18

Background:

I've deployed an ASP.NET MVC 3 app that works on my machine to a shared hosting provider and am discovering some problems that appear to be related to the application pool being recycled. The host has configured recycling to occur under any of these circumstances:

  • Memory usage exceeds 200MB
  • CPU usage exceeds 75% (presumably over a sustained period)
  • 20 minutes of idle time

The restrictions are more relaxed on my development machine so I wasn't seeing recycling like this during development. I don't have admin access to the shared hosting box (understandably) so I can't read the event log to see why this recycling is occurring.

Question:

Is there a way I can find out why my app was recycled (in Application_End for example) so that I can log it to help my debugging?

Community
  • 1
  • 1
Drew Noakes
  • 300,895
  • 165
  • 679
  • 742

4 Answers4

12

Without access to the event logs (because you're in a shared hosting environment) the most information you're going to get is from the Application_End event and by asking the HttpRuntime (via reflection) for the values of one or two private members that are sadly not exposed publicly.

To do this add the following code to your Application_End event:

BindingFlags staticFlags = 
    BindingFlags.NonPublic | BindingFlags.Static | BindingFlags.GetField;
BindingFlags instanceFlags = 
    BindingFlags.NonPublic | BindingFlags.Instance | BindingFlags.GetField;

HttpRuntime runtime = (HttpRuntime)typeof(System.Web.HttpRuntime)
                        .InvokeMember("_theRuntime", staticFlags, null, null, null);
if(runtime != null) 
{
    string shutDownMessage = (string)runtime.GetType()
         .InvokeMember("_shutDownMessage", instanceFlags, null, runtime, null);

    string shutDownStack = (string)runtime.GetType()
         .InvokeMember("_shutDownStack", instanceFlags, null, runtime, null);

    // Log shutDownMessage & shutDownStack somewhere
}

If I shutdown or recycle my app's application pool I see the following:

HostingEnvironment initiated shutdown
HostingEnvironment caused shutdown -    
   at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
   at System.Environment.get_StackTrace()
   at System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal()
   at System.Web.Hosting.HostingEnvironment.InitiateShutdownWithoutDemand()
   at System.Web.Hosting.PipelineRuntime.StopProcessing()

That's probably about as good as it gets.

Update:

I couldn't remember where I found this code but Drew helpfully reminded me it was from a Scott Guthrie blog post.

There are some other private members that could be useful such as:

private ApplicationShutdownReason _shutdownReason;

You can examine these fields in .NET Reflector (if you still have a copy that isn't time-bombed) or one of the alternatives (Open Source Alternatives to Reflector?).

Community
  • 1
  • 1
Kev
  • 118,037
  • 53
  • 300
  • 385
  • 1
    Did you find this on [ScottGu's blog](http://weblogs.asp.net/scottgu/archive/2005/12/14/433194.aspx)? I tried this approach before posting the question but it doesn't provide much useful data. The message I get is _HostingEnvironment initiated shutdown_ which doesn't help me work out what I need to do to satisfy the hosting environment. – Drew Noakes Mar 26 '11 at 16:41
  • You can access this data, generally speaking, via the `System.Web.Hosting.HostingEnvironment.ShutdownReason` property (it's an enum.) – Drew Noakes Mar 26 '11 at 16:49
  • No problem. BTW it's Scott Guthrie, not Hanselman. A link to his blog post was in my first comment: http://weblogs.asp.net/scottgu/archive/2005/12/14/433194.aspx – Drew Noakes Mar 26 '11 at 17:06
  • @drew - I am complete #fail today :) – Kev Mar 26 '11 at 20:01
  • 2
    Indeed there's a detailed comment for that _shutdownReason enum that can be seen with reflector. Here's a snippet to get that enum value: `string shutDownReason = runtime.GetType().GetField("_shutdownReason", BindingFlags.NonPublic | BindingFlags.Instance | BindingFlags.GetField) .GetValue(runtime).ToString();` – BornToCode May 26 '17 at 12:56
7

Research - 1

Firstly I tried using System.Web.ProcessModelInfo.GetCurrentProcessInfo() and System.Web.ProcessModelInfo.GetHistory(int). The results of these methods return info such as the PID, start time, age, status, and peak memory usage. Unfortunately these were unavailable in my hosting environment:

HttpException 0x80004005 - Process metrics are available only when the ASP.NET process model is enabled. When running on versions of IIS 6 or newer in worker process isolation mode, this feature is not supported.

This approach might work for others though, so if you're in this situation, give it a shot.

Research - 2

The property System.Web.Hosting.HostingEnvironment.ShutdownReason is an enum with lots of values, but unfortunately all the cases I outline in my question are bundled into a single enum value:

ApplicationShutdownReason.HostingEnvironment: The hosting environment shut down the application domain.

Research - 3

ScottGu has an approach on his blog (which is the same code Kev posted) that uses reflection to access internal state of the HttpApplication. Unfortunately in this case it only reports the same detail as #2 above:

_shutDownMessage =
  HostingEnvironment initiated shutdown
  HostingEnvironment caused shutdown

_shutDownStack =
  at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
  at System.Environment.get_StackTrace()
  at System.Web.Hosting.HostingEnvironment.InitiateShutdownInternal()
  at System.Web.Hosting.HostingEnvironment.InitiateShutdownWithoutDemand()
  at System.Web.Hosting.PipelineRuntime.StopProcessing()
Community
  • 1
  • 1
Drew Noakes
  • 300,895
  • 165
  • 679
  • 742
  • 4
    I don't get it. You described something that was unavailable in your environment, then an enum that didn't help, and a reflected property that didn't help. So what was the final reason for your app restarts? – anon Mar 04 '15 at 16:24
5

Below is good code find from https://mitchelsellers.com/blog/article/logging-asp-net-application-restarts

//  obtain the shutdown reason
System.Web.ApplicationShutdownReason shutdownReason = System.Web.Hosting.HostingEnvironment.ShutdownReason;
string shutdownDetail = "";

//Evaluate which option caused the error
switch (shutdownReason)
{
    case ApplicationShutdownReason.BinDirChangeOrDirectoryRename:
        shutdownDetail = "A change was made to the bin directory or the directory was renamed";
        break;
    case ApplicationShutdownReason.BrowsersDirChangeOrDirectoryRename:
        shutdownDetail = "A change was made to the App_browsers folder or the files contained in it";
        break;
    case ApplicationShutdownReason.ChangeInGlobalAsax:
        shutdownDetail = "A change was made in the global.asax file";
        break;
    case ApplicationShutdownReason.ChangeInSecurityPolicyFile:
        shutdownDetail = "A change was made in the code access security policy file";
        break;
    case ApplicationShutdownReason.CodeDirChangeOrDirectoryRename:
        shutdownDetail = "A change was made in the App_Code folder or the files contained in it";
        break;
    case ApplicationShutdownReason.ConfigurationChange:
        shutdownDetail = "A change was made to the application level configuration";
        break;
    case ApplicationShutdownReason.HostingEnvironment:
        shutdownDetail = "The hosting environment shut down the application";
        break;
    case ApplicationShutdownReason.HttpRuntimeClose:
        shutdownDetail = "A call to Close() was requested";
        break;
    case ApplicationShutdownReason.IdleTimeout:
        shutdownDetail = "The idle time limit was reached";
        break;
    case ApplicationShutdownReason.InitializationError:
        shutdownDetail = "An error in the initialization of the AppDomain";
        break;
    case ApplicationShutdownReason.MaxRecompilationsReached:
        shutdownDetail = "The maximum number of dynamic recompiles of a resource limit was reached";
        break;
    case ApplicationShutdownReason.PhysicalApplicationPathChanged:
        shutdownDetail = "A change was made to the physical path to the application";
        break;
    case ApplicationShutdownReason.ResourcesDirChangeOrDirectoryRename:
        shutdownDetail = "A change was made to the App_GlobalResources foldr or the files contained within it";
        break;
    case ApplicationShutdownReason.UnloadAppDomainCalled:
        shutdownDetail = "A call to UnloadAppDomain() was completed";
        break;
    default:
        shutdownDetail = "Unknown shutdown reason";
        break;
}
Holistic Developer
  • 2,458
  • 1
  • 18
  • 27
KMR
  • 101
  • 2
  • 3
5

This answer can provide extra insight for those having similar problems on IIS 7.x or above.

1. Finding when application pool is starting to shutdown - the following code can be used to find out when the application pool start its shutdown. Actual shutdown occurs in a maximum of Shutdown limit (seconds, default 90) after this event.

public class ApplicationPoolService : IApplicationPoolService
{
    public bool IsShuttingDown()
    {
        return System.Web.Hosting.HostingEnvironment.ShutdownReason != ApplicationShutdownReason.None;
    }

    public ApplicationShutdownReason GetShutdownReason()
    {
        return System.Web.Hosting.HostingEnvironment.ShutdownReason;
    }
}

public class HostingEnvironmentRegisteredObject : IRegisteredObject
{
    public void Stop(bool immediate)
    {
        // second call is done when the Stop is imminent 
        if (immediate)
            return;

        var reason = appPoolService.GetShutdownReason().ToString();
        logger.Log(LogLevel.Info, $"HostingEnvironmentRegisteredObject.stop called with shutdown reason {reason}");
    }
}

// this code should be placed in global.asax.cs
protected void Application_Start()
{
    HostingEnvironment.RegisterObject(new HostingEnvironmentRegisteredObject());
}

This helps to find the general reason and exactly when it was triggered. In your case, I think HostingEnvironment is the value. Unfortunately, the underlying cause is not unique. It can be periodic recycle, recycle due to memory limit (most probable reason in OP's question), recycle due to fixed hour etc.

2. Finding the exact cause - one way to find out the exact cause is to search for it in the EventLog. If this is not accessible, it can be requested from the hosting provider by providing the following details to narrow their search.

  • Exact time of shutdown initiation
  • Event log filter:
    • Event sources = WAS
    • Event level = Information
    • Logged = custom range including exact time of shutdown +/- 1 minute or so

Event log should return more relevant information like the ones below:

A worker process with process id of 'xxx' serving application pool 'xxx' has requested a recycle because it reached its scheduled recycle time.


A worker process with process id of 'xxx' serving application pool 'xxx' has requested a recycle because it reached its virtual memory limit.

Nimantha
  • 6,405
  • 6
  • 28
  • 69
Alexei - check Codidact
  • 22,016
  • 16
  • 145
  • 164