I've recently been running a v10 upgraded site for a couple weeks. Over the weekend we had an outage: HTTP Error 500.37 - ASP.NET Core app failed to start within startup time limit.
There really wasn't much in the Umbraco logs. Just a random stop notification, with nothing for hours before it.
This issue was reconciled by rebooting the server.
We only have 2 .net core apps running on this machine and there were no CPU/memory spikes at the time of the outage. Are there any other recommendations on how to diagnose the cause? Or should I look into increasing the ANCM startup time limit?
{"@t":"2022-09-11T02:00:41.1491731Z","@mt":"Stopping ({SignalSource})","SignalSource":"environment","SourceContext":"Umbraco.Cms.Core.Runtime.MainDom","ProcessId":19816,"ProcessName":"w3wp","ThreadId":190,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:00:41.1628988Z","@mt":"Released from MainDom","SourceContext":"Umbraco.Cms.Infrastructure.PublishedCache.PublishedSnapshotService","ProcessId":19816,"ProcessName":"w3wp","ThreadId":190,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:00:41.1633185Z","@mt":"Released ({SignalSource})","SignalSource":"environment","SourceContext":"Umbraco.Cms.Core.Runtime.MainDom","ProcessId":19816,"ProcessName":"w3wp","ThreadId":190,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:00:41.1640756Z","@mt":"Application is shutting down...","SourceContext":"Microsoft.Hosting.Lifetime","ProcessId":19816,"ProcessName":"w3wp","ThreadId":190,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:00:41.1659641Z","@mt":"Queued Hosted Service is stopping.","SourceContext":"Umbraco.Cms.Infrastructure.HostedServices.QueuedHostedService","ProcessId":19816,"ProcessName":"w3wp","ThreadId":203,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:15.4176264Z","@mt":"Acquiring MainDom.","SourceContext":"Umbraco.Cms.Core.Runtime.MainDom","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:15.4831404Z","@mt":"Acquired MainDom.","SourceContext":"Umbraco.Cms.Core.Runtime.MainDom","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:16.6951931Z","@mt":"Starting '{MigrationName}'...","MigrationName":"UrlTracker","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:16.6953293Z","@mt":"At {OrigState}","OrigState":"2.1","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:16.6967792Z","@mt":"Done (pending scope completion).","SourceContext":"Umbraco.Cms.Infrastructure.Migrations.MigrationPlanExecutor","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:16.7084097Z","@mt":"Profiler is VoidProfiler, not profiling (must run debug mode to profile).","SourceContext":"Umbraco.Cms.Web.Common.Profiler.InitializeWebProfiling","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:17.8645511Z","@mt":"Application started. Press Ctrl+C to shut down.","SourceContext":"Microsoft.Hosting.Lifetime","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:17.8646355Z","@mt":"Hosting environment: {envName}","envName":"Production","SourceContext":"Microsoft.Hosting.Lifetime","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:17.8646671Z","@mt":"Content root path: {contentRoot}","contentRoot":"C:\\inetpub\\thecurestartsnow.org_10","SourceContext":"Microsoft.Hosting.Lifetime","ProcessId":5436,"ProcessName":"w3wp","ThreadId":1,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO "}
{"@t":"2022-09-11T02:41:18.4162501Z","@mt":"Registered with MainDom, localContentDbExists? {LocalContentDbExists}, localMediaDbExists? {LocalMediaDbExists}","LocalContentDbExists":true,"LocalMediaDbExists":true,"SourceContext":"Umbraco.Cms.Infrastructure.PublishedCache.PublishedSnapshotService","RequestId":"80000006-0000-e900-b63f-84710c7967bb","RequestPath":"/dipg-facts/what-is-dipg/","ProcessId":5436,"ProcessName":"w3wp","ThreadId":13,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO ","HttpRequestId":"7b4b698d-8f96-4ecf-8c57-3afe3ea5be3d","HttpRequestNumber":1,"HttpSessionId":"0"}
{"@t":"2022-09-11T02:41:18.4210675Z","@mt":"Creating the content store, localContentDbExists? {LocalContentDbExists}","LocalContentDbExists":true,"SourceContext":"Umbraco.Cms.Infrastructure.PublishedCache.PublishedSnapshotService","RequestId":"80000006-0000-e900-b63f-84710c7967bb","RequestPath":"/dipg-facts/what-is-dipg/","ProcessId":5436,"ProcessName":"w3wp","ThreadId":13,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO ","HttpRequestId":"7b4b698d-8f96-4ecf-8c57-3afe3ea5be3d","HttpRequestNumber":1,"HttpSessionId":"0"}
{"@t":"2022-09-11T02:41:18.4348747Z","@mt":"Creating the media store, localMediaDbExists? {LocalMediaDbExists}","LocalMediaDbExists":true,"SourceContext":"Umbraco.Cms.Infrastructure.PublishedCache.PublishedSnapshotService","RequestId":"80000006-0000-e900-b63f-84710c7967bb","RequestPath":"/dipg-facts/what-is-dipg/","ProcessId":5436,"ProcessName":"w3wp","ThreadId":13,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO ","HttpRequestId":"7b4b698d-8f96-4ecf-8c57-3afe3ea5be3d","HttpRequestNumber":1,"HttpSessionId":"0"}
{"@t":"2022-09-11T02:41:19.4808586Z","@mt":"{StartMessage} [Timing {TimingId}]","StartMessage":"Loading content from local cache file","TimingId":"fd7f795","SourceContext":"Umbraco.Cms.Core.Logging.ProfilingLogger","RequestId":"80000006-0000-e900-b63f-84710c7967bb","RequestPath":"/dipg-facts/what-is-dipg/","ProcessId":5436,"ProcessName":"w3wp","ThreadId":13,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO ","HttpRequestId":"7b4b698d-8f96-4ecf-8c57-3afe3ea5be3d","HttpRequestNumber":1,"HttpSessionId":"0"}
{"@t":"2022-09-11T02:41:20.0112126Z","@mt":"{EndMessage} ({Duration}ms) [Timing {TimingId}]","EndMessage":"Completed.","Duration":530,"TimingId":"fd7f795","SourceContext":"Umbraco.Cms.Core.Logging.ProfilingLogger","RequestId":"80000006-0000-e900-b63f-84710c7967bb","RequestPath":"/dipg-facts/what-is-dipg/","ProcessId":5436,"ProcessName":"w3wp","ThreadId":13,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO ","HttpRequestId":"7b4b698d-8f96-4ecf-8c57-3afe3ea5be3d","HttpRequestNumber":1,"HttpSessionId":"0"}
{"@t":"2022-09-11T02:41:20.0289668Z","@mt":"{StartMessage} [Timing {TimingId}]","StartMessage":"Loading media from local cache file","TimingId":"8a7bf83","SourceContext":"Umbraco.Cms.Core.Logging.ProfilingLogger","RequestId":"80000006-0000-e900-b63f-84710c7967bb","RequestPath":"/dipg-facts/what-is-dipg/","ProcessId":5436,"ProcessName":"w3wp","ThreadId":13,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO ","HttpRequestId":"7b4b698d-8f96-4ecf-8c57-3afe3ea5be3d","HttpRequestNumber":1,"HttpSessionId":"0"}
{"@t":"2022-09-11T02:41:20.4034002Z","@mt":"{EndMessage} ({Duration}ms) [Timing {TimingId}]","EndMessage":"Completed.","Duration":374,"TimingId":"8a7bf83","SourceContext":"Umbraco.Cms.Core.Logging.ProfilingLogger","RequestId":"80000006-0000-e900-b63f-84710c7967bb","RequestPath":"/dipg-facts/what-is-dipg/","ProcessId":5436,"ProcessName":"w3wp","ThreadId":13,"ApplicationId":"e9d8132d4c00605df5279d0626cc80ccc0f9f2cb","MachineName":"CSNWEB1","Log4NetLevel":"INFO ","HttpRequestId":"7b4b698d-8f96-4ecf-8c57-3afe3ea5be3d","HttpRequestNumber":1,"HttpSessionId":"0"}
You should go to the advanced settings of your App pool and set the Idle Time-out (minutes) to 0. This will prevent IIS on shutting down the application when there is no trafic. This will prevent a random startup issue from happening.
To try and fix the actual problem, I recommend searching for errors logs in the "Event Viewer".
According to the MSDN for 500.37.
This error can occur when starting a large number of apps on the same machine. Check for CPU/Memory usage spikes on the server during startup. You may need to stagger the startup process of multiple apps.
Your server might simply be overloaded to handle the startup of the app at that time. With above settings it shouldn't shut down out of of itself.
The server was not under high load during this timeframe and this occurred during an app recycle, not a server startup.
Pertinent event viewer logs are below:
10:00:26 A worker process with process id of '19816' serving application pool 'X' has requested a recycle because the worker process reached its allowed processing time limit.
10:03:46 An ISAPI reported an unhealthy condition to its worker process. Therefore, the worker process with process id of '11376' serving application pool 'X' has requested a recycle.
10:06:57 An ISAPI reported an unhealthy condition to its worker process. Therefore, the worker process with process id of '21392' serving application pool 'X' has requested a recycle.
10:09:54 An ISAPI reported an unhealthy condition to its worker process. Therefore, the worker process with process id of '15756' serving application pool 'X' has requested a recycle.
10:12:56 An ISAPI reported an unhealthy condition to its worker process. Therefore, the worker process with process id of '15472' serving application pool 'X' has requested a recycle.
10:15:58 An ISAPI reported an unhealthy condition to its worker process. Therefore, the worker process with process id of '19768' serving application pool 'X' has requested a recycle.
The ISAPI error kept repeating until I manually rebooted the server.
The app recycling obviously through it into a bad state, but I'd prefer not to turn off recycling entirely. I did a few searches online about how to diagnose the ISAPI errors, but there was nothing particularly helpful.
I had the same issue, in my case i looked into the Windows Events log and found out that a Windows Update have been running that closed down different events/services and caused Umbraco to have issues to reconnect to the SQL and restart the app.
I just restarted the App pool and website and all was good to go again.
I recently upgraded to Umbraco 11.0.4, the issue have never occured before that on the website ..
Random HTTP Error 500.37 on v10
Umbraco version: 10.1.1 IIS 10
I've recently been running a v10 upgraded site for a couple weeks. Over the weekend we had an outage: HTTP Error 500.37 - ASP.NET Core app failed to start within startup time limit.
There really wasn't much in the Umbraco logs. Just a random stop notification, with nothing for hours before it.
This issue was reconciled by rebooting the server.
We only have 2 .net core apps running on this machine and there were no CPU/memory spikes at the time of the outage. Are there any other recommendations on how to diagnose the cause? Or should I look into increasing the ANCM startup time limit?
You should go to the advanced settings of your App pool and set the
Idle Time-out (minutes)to0. This will prevent IIS on shutting down the application when there is no trafic. This will prevent a random startup issue from happening.To try and fix the actual problem, I recommend searching for errors logs in the "Event Viewer".
According to the MSDN for 500.37.
Your server might simply be overloaded to handle the startup of the app at that time. With above settings it shouldn't shut down out of of itself.
Thanks for your response Roy.
The server was not under high load during this timeframe and this occurred during an app recycle, not a server startup.
Pertinent event viewer logs are below:
The ISAPI error kept repeating until I manually rebooted the server.
The app recycling obviously through it into a bad state, but I'd prefer not to turn off recycling entirely. I did a few searches online about how to diagnose the ISAPI errors, but there was nothing particularly helpful.
Any other suggesions?
Any luck, having the same issue. No tangible clues anywhere in any of the logs. Brutal.
I had the same issue, in my case i looked into the Windows Events log and found out that a Windows Update have been running that closed down different events/services and caused Umbraco to have issues to reconnect to the SQL and restart the app.
I just restarted the App pool and website and all was good to go again.
I recently upgraded to Umbraco 11.0.4, the issue have never occured before that on the website ..
is working on a reply...