Recurring application shutdown issue on Umbraco 7.5.3
Hi guys,
We are faced with an issue where quite a few application shutdowns are being encountered on Umbraco v7.5.3. Does anyone have any similar experience and if so is there a way to fix this?
The setup is as follows:
Umbraco V7.5.3 (Nuget installed)
Windows Server 2012 R2 Standard
Database: MSSQL Server 2014
The Umbraco installation is used to host multiple domains. Two domains are set up on two nodes using Culture and Hostnames. One site is set up in IIS for Umbraco, and it has it's own application pool.
Site bindings in IIS are used to point multiple domains to the Umbraco instance, and Culture and Hostnames are used to resolve which node to load.
The problem:
Loading one site initially takes about 8 seconds, after that if we were to refresh the page the site loads up fast in under one second. Then when we try to load a different domain on another node
the load time is again about 8 seconds. It appears that loading a different node causes a lag every single time.
In the logs we can see that the following is happening :
Application shutdown. Details: HostingEnvironment
_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.PipelineRuntime.StopProcessing()
There is also the following but not as regularly as the above.
Application shutdown. Details: MaxRecompilationsReached
_shutDownMessage=Recompilation limit of 15 reached
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.HttpRuntime.ShutdownAppDomain(String stackTrace)
at System.Web.Compilation.DiskBuildResultCache.ShutdownCallBack(Object state)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
at System.Threading.ThreadPoolWorkQueue.Dispatch()
Also there is an error from UmbracoExamine.DataServices.UmbracoLogService that keeps showing up.
Provider=InternalMemberIndexer, NodeId=-1
System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: InternalMemberIndexSet
Might help with the "recompilation limit". Otherwise, I'd just make sure every single Windows update, including the recommended/optional ones, are installed.
Also, there is a setting in IIS that will recycle the application pool if too many errors occur on threads that causes those threads to abort. You can change the setting to increase the threshold so those recycles are less likely.
Disabling models builder definitely made a big difference. Sites are loading much faster and the errors seem to have disappeared, although I did still get the HostingEnvironment initiated shutdown once.
I've slightly increased the failure threshold on the application pool to reduce likelihood of it being recycled.
FYI, I think the default for IIS is to recycle the application pool when there are 5 errors in 5 minutes (or roundabouts). I typically change that to 100 errors in 5 minutes.
Let me know if you are still getting the HostingEnvironment initiated shutdown periodically and I can give you some more ideas.
I experience shutdowns as well running on UaaS. This log keeps recurring each 10 minutes and it takes like 10 seconds for the site to start again. Any ideas?
2016-10-06 16:26:22,061 [P28560/D3/T3] INFO Umbraco.Core.CoreBootManager - Umbraco 7.5.3 application starting on PRUMWEWORKER016
2016-10-06 16:26:22,092 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Determining hash of code files on disk
2016-10-06 16:26:22,139 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Hash determined (took 39ms)
2016-10-06 16:26:22,202 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2016-10-06 16:26:22,249 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 52ms)
2016-10-06 16:26:22,296 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2016-10-06 16:26:22,296 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 1ms)
2016-10-06 16:26:22,296 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
2016-10-06 16:26:22,296 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 5ms)
2016-10-06 16:26:22,311 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2016-10-06 16:26:22,311 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 3ms)
2016-10-06 16:26:22,311 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
2016-10-06 16:26:22,327 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 16ms)
2016-10-06 16:26:22,374 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2016-10-06 16:26:22,374 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 1ms)
2016-10-06 16:26:22,374 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2016-10-06 16:26:22,374 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 1ms)
2016-10-06 16:26:23,639 [P28560/D3/T3] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-10-06 16:26:23,780 [P28560/D3/T3] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-10-06 16:26:23,796 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
2016-10-06 16:26:23,811 [P28560/D3/T3] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 2ms)
2016-10-06 16:26:23,967 [P28560/D3/T3] INFO Umbraco.Forms.Core.Cache.CacheEventHandler - Initializing Umbraco Forms Events to trigger Cache Refreshers
2016-10-06 16:26:26,389 [P28560/D3/T3] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-10-06 16:26:26,421 [P28560/D3/T3] INFO Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
2016-10-06 16:26:26,483 [P28560/D3/T3] INFO Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
2016-10-06 16:26:26,483 [P28560/D3/T3] INFO Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 3
2016-10-06 16:26:26,499 [P28560/D3/T3] INFO Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 4463ms)
2016-10-06 16:26:29,499 [P28560/D3/T17] INFO Umbraco.Core.Sync.ApplicationUrlHelper - ApplicationUrl: http://www.domain.com:80/umbraco (UmbracoModule request)
2016-10-06 16:26:30,811 [P28560/D3/T17] INFO umbraco.content - Load Xml from file...
2016-10-06 16:26:31,249 [P28560/D3/T17] INFO umbraco.content - Loaded Xml from file.
2016-10-06 16:26:31,921 [P28560/D3/T17] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2016-10-06 16:26:31,936 [P28560/D3/T17] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 3ms)
2016-10-06 16:27:31,273 [P28560/D3/T7] INFO umbraco.BusinessLogic.Log - Log scrubbed. Removed all items older than 2016-10-05 16:27:31
2016-10-06 16:36:23,853 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating
2016-10-06 16:36:23,853 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Waiting for tasks to complete
2016-10-06 16:36:23,916 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Terminating
2016-10-06 16:36:23,916 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Waiting for tasks to complete
2016-10-06 16:36:23,916 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating
2016-10-06 16:36:23,916 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Waiting for tasks to complete
2016-10-06 16:36:23,916 [P28560/D3/T39] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Tasks completed, terminated
2016-10-06 16:36:23,932 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Terminating
2016-10-06 16:36:23,932 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Waiting for tasks to complete
2016-10-06 16:36:23,932 [P28560/D3/T7] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Tasks completed, terminated
2016-10-06 16:36:23,932 [P28560/D3/T20] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Tasks completed, terminated
2016-10-06 16:36:23,963 [P28560/D3/T21] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Tasks completed, terminated
2016-10-06 16:36:23,978 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Terminating
2016-10-06 16:36:23,978 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Waiting for tasks to complete
2016-10-06 16:36:23,978 [P28560/D3/T16] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Tasks completed, terminated
2016-10-06 16:36:54,093 [P28560/D3/T16] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: HostingEnvironment
_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()
We are experiencing the exact same issue. Let us know if you come up with any ideas. We are trying the models builder config change as well.
Umbraco 7.4.3
---updatee--
We changed the models builder settings and did not get any changes of the site still restarting literally every ten minutes on UAAS.
Pretty disappointing.
_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()
2016-10-08 12:13:07,025 [P24140/D2/T5] INFO Umbraco.Core.CoreBootManager - Umbraco 7.4.3 application starting on PRUMWEWORKER005
2016-10-08 12:13:07,072 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Determining hash of code files on disk
2016-10-08 12:13:07,088 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Hash determined (took 19ms)
2016-10-08 12:13:07,150 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2016-10-08 12:13:07,197 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 43ms)
2016-10-08 12:13:07,228 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2016-10-08 12:13:07,228 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 1ms)
2016-10-08 12:13:07,228 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
2016-10-08 12:13:07,228 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 2ms)
2016-10-08 12:13:07,244 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2016-10-08 12:13:07,244 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 2ms)
2016-10-08 12:13:07,244 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
2016-10-08 12:13:07,259 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 17ms)
2016-10-08 12:13:07,291 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2016-10-08 12:13:07,306 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 1ms)
2016-10-08 12:13:07,306 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2016-10-08 12:13:07,306 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 1ms)
2016-10-08 12:13:08,276 [P24140/D2/T5] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-10-08 12:13:08,525 [P24140/D2/T5] INFO UmbracoExamine.LocalStorage.LocalTempStorageIndexer - Successfully sync'd main index to local temp storage for index: ~/App_Data/TEMP/ExamineIndexes/PRUMWEWORKER005/Internal/
2016-10-08 12:13:08,572 [P24140/D2/T5] INFO UmbracoExamine.LocalStorage.LocalTempStorageIndexer - Successfully sync'd main index to local temp storage for index: ~/App_Data/TEMP/ExamineIndexes/PRUMWEWORKER005/InternalMember/
2016-10-08 12:13:08,634 [P24140/D2/T5] INFO UmbracoExamine.LocalStorage.LocalTempStorageIndexer - Successfully sync'd main index to local temp storage for index: ~/App_Data/TEMP/ExamineIndexes/PRUMWEWORKER005/External/
2016-10-08 12:13:08,681 [P24140/D2/T5] INFO UmbracoExamine.LocalStorage.LocalTempStorageIndexer - Successfully sync'd main index to local temp storage for index: ~/App_Data/TEMP/ExamineIndexes/PRUMWEWORKER005/ExpertArticleSet/
2016-10-08 12:13:08,713 [P24140/D2/T5] INFO Umbraco.Core.Persistence.Database - New table 'xx3' was created
2016-10-08 12:13:08,713 [P24140/D2/T5] INFO Umbraco.Core.Persistence.Database - New table 'xx2' was created
2016-10-08 12:13:08,713 [P24140/D2/T5] INFO Umbraco.Core.Persistence.Database - New table 'xx1' was created
2016-10-08 12:13:09,291 [P24140/D2/T5] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-10-08 12:13:09,306 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
2016-10-08 12:13:09,306 [P24140/D2/T5] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 2ms)
2016-10-08 12:13:12,275 [P24140/D2/T5] INFO Umbraco.Forms.Core.Cache.CacheEventHandler - Initializing Umbraco Forms Events to trigger Cache Refreshers
2016-10-08 12:13:12,275 [P24140/D2/T5] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-10-08 12:13:12,307 [P24140/D2/T5] INFO Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
2016-10-08 12:13:12,322 [P24140/D2/T5] INFO Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
2016-10-08 12:13:12,322 [P24140/D2/T5] INFO Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 4
2016-10-08 12:13:12,338 [P24140/D2/T5] INFO Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 5315ms)
2016-10-08 12:13:14,572 [P24140/D2/T13] INFO Umbraco.Core.Sync.ApplicationUrlHelper - ApplicationUrl: http://someotherdomain.ca:80/umbraco (UmbracoModule request)
2016-10-08 12:13:14,822 [P24140/D2/T13] INFO umbraco.content - Load Xml from file...
2016-10-08 12:13:14,885 [P24140/D2/T13] INFO umbraco.content - Loaded Xml from file.
2016-10-08 12:13:15,604 [P24140/D2/T7] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2016-10-08 12:13:15,604 [P24140/D2/T7] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 5ms)
2016-10-08 12:13:40,628 [P24140/D2/T19] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2016-10-08 12:13:40,628 [P24140/D2/T19] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 0ms)
2016-10-08 12:13:40,659 [P24140/D2/T19] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.cms.businesslogic.macro.IMacroEngine
2016-10-08 12:13:40,659 [P24140/D2/T19] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 0 (took 2ms)
2016-10-08 12:14:22,312 [P24140/D2/T18] INFO umbraco.BusinessLogic.Log - Log scrubbed. Removed all items older than 2016-10-07 12:14:22
2016-10-08 12:23:08,000 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating
2016-10-08 12:23:08,000 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Waiting for tasks to complete
2016-10-08 12:23:08,000 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Terminating
2016-10-08 12:23:08,000 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Waiting for tasks to complete
2016-10-08 12:23:08,000 [P24140/D2/T18] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Tasks completed, terminated
2016-10-08 12:23:08,000 [P24140/D2/T40] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Tasks completed, terminated
2016-10-08 12:23:08,000 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating
2016-10-08 12:23:08,000 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Waiting for tasks to complete
2016-10-08 12:23:08,015 [P24140/D2/T45] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Tasks completed, terminated
2016-10-08 12:23:08,093 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Terminating
2016-10-08 12:23:08,093 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Waiting for tasks to complete
2016-10-08 12:23:08,093 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Terminating
2016-10-08 12:23:08,093 [P24140/D2/T13] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Waiting for tasks to complete
2016-10-08 12:23:08,093 [P24140/D2/T12] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Tasks completed, terminated
2016-10-08 12:23:08,093 [P24140/D2/T25] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Tasks completed, terminated
2016-10-08 12:23:38,205 [P24140/D2/T13] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: HostingEnvironment
_shutDownMessage=HostingEnvironment initiated shutdown
HostingEnvironment caused shutdown
I have been doing more research into what might be happening with our constant restarts every 10 minutes in production. These are my findings.: from kudu I observe the following: in Logfiles > Kudu > Trace you will see the log is filled with 'server'StartupGETapi-commandstream-reconnect0s.xml and 22PRUMWE002Shutdown_0s.xml
Both of these events happen roughly 10 minutes apart from each other.
the first one (command stream reconnect)
this step essentially creates/starts the w3wp worker pid 17636,2,7
Interesting, I have a cuple of those as well and they occur with a 10 minute interval. I found this in the CourierTraceLog file (wwwroot/App_Data/Logs/CourierTraceLog.txt) this is happening to our site with a interval of 10 minutes:
2016-10-08 20:11:11,754 [8] INFO Umbraco.Courier.Core.BackgroundTaskRunner - [Thread 39] Application is shutting down, waiting for tasks to complete
2016-10-08 20:11:11,754 [8] INFO Umbraco.Courier.Core.BackgroundTaskRunner - [Thread 39] Shutdown
2016-10-08 20:11:11,754 [8] INFO Umbraco.Courier.Core.BackgroundTaskRunner - [Thread 39] Application is shutting down, waiting for tasks to complete
2016-10-08 20:11:11,754 [8] INFO Umbraco.Courier.Core.BackgroundTaskRunner - [Thread 39] Shutdown
2016-10-08 20:11:49,149 [9] DEBUG Concorde.CacheHandler.Managers.ActivationManager - [Thread 4] Run :: Instance Key 084a1bf0-7c8e-4e3a-9454-0a61f00466eb
2016-10-08 20:11:49,149 [9] INFO Concorde.CacheHandler.Managers.ActivationManager - [Thread 4] Run :: Is running remote? True, Is using Sql Azure? True
2016-10-08 20:11:49,149 [9] DEBUG Concorde.CacheHandler.Managers.ActivationManager - [Thread 4] Run :: Umbraco Version 7.5.3
2016-10-08 20:11:51,009 [9] DEBUG Concorde.CacheHandler.Managers.ActivationManager - [Thread 4] ApplicationInitialized :: Instance Key 084a1bf0-7c8e-4e3a-9454-0a61f00466eb
2016-10-08 20:11:51,274 [9] DEBUG Concorde.CacheHandler.Managers.ActivationManager - [Thread 4] ApplicationStarted :: Instance Key 084a1bf0-7c8e-4e3a-9454-0a61f00466eb
2016-10-08 20:11:51,743 [9] DEBUG Concorde.CacheHandler.Managers.ActivationManager - [Thread 4] ApplicationStarting :: Running Courier on Umbraco-as-a-service
2016-10-08 20:11:51,743 [9] DEBUG Concorde.CacheHandler.Managers.ActivationManager - [Thread 4] ApplicationStarting :: Starting CacheHandler: data
2016-10-08 20:11:51,743 [9] INFO Concorde.CacheHandler.Managers.UmbracoEventManager - [Thread 4] Initializing manager and subscribing to events
2016-10-08 20:11:51,946 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'SavedContentType' in type 'Umbraco.Core.Services.ContentTypeService' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,946 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'DeletedContentType' in type 'Umbraco.Core.Services.ContentTypeService' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,946 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'SavedMediaType' in type 'Umbraco.Core.Services.ContentTypeService' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,946 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'DeletedMediaType' in type 'Umbraco.Core.Services.ContentTypeService' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,962 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'Saved' in type 'Umbraco.Core.Services.MemberTypeService' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '7.1.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,962 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'Deleted' in type 'Umbraco.Core.Services.MemberTypeService' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '7.1.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'New' in type 'umbraco.cms.businesslogic.member.MemberType' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.1.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterSave' in type 'umbraco.cms.businesslogic.member.MemberType' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.1.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterDelete' in type 'umbraco.cms.businesslogic.member.MemberType' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.1.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'New' in type 'umbraco.cms.businesslogic.member.MemberGroup' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.1.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterSave' in type 'umbraco.cms.businesslogic.member.MemberGroup' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.1.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterDelete' in type 'umbraco.cms.businesslogic.member.MemberGroup' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.1.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'New' in type 'umbraco.cms.businesslogic.language.Language' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterSave' in type 'umbraco.cms.businesslogic.language.Language' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterDelete' in type 'umbraco.cms.businesslogic.language.Language' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'New' in type 'umbraco.cms.businesslogic.Dictionary+DictionaryItem' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'Saving' in type 'umbraco.cms.businesslogic.Dictionary+DictionaryItem' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'Deleted' in type 'umbraco.cms.businesslogic.Dictionary+DictionaryItem' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterSave' in type 'umbraco.cms.businesslogic.macro.Macro' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.0.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterDelete' in type 'umbraco.cms.businesslogic.macro.Macro' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.0.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'New' in type 'umbraco.cms.businesslogic.template.Template' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterSave' in type 'umbraco.cms.businesslogic.template.Template' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterDelete' in type 'umbraco.cms.businesslogic.template.Template' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'New' in type 'umbraco.cms.businesslogic.web.StyleSheet' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterSave' in type 'umbraco.cms.businesslogic.web.StyleSheet' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterDelete' in type 'umbraco.cms.businesslogic.web.StyleSheet' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.3.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'New' in type 'umbraco.cms.businesslogic.web.StylesheetProperty' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.2.0'.
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.EventSubscriber - [Thread 4] Event with name 'AfterSave' in type 'umbraco.cms.businesslogic.web.StylesheetProperty' did not Subscribe, because it didn't match the version filter: Current version '7.5.3' >= '6.0.0' AND '7.5.3' < '7.2.0'.
2016-10-08 20:11:51,978 [9] INFO Concorde.CacheHandler.Managers.UmbracoEventManager - [Thread 4] Completed event subscription (took 221ms)
2016-10-08 20:11:51,978 [9] DEBUG Concorde.CacheHandler.Managers.DeployManager - [Thread 4] Initializing
2016-10-08 20:11:51,993 [9] INFO Concorde.CacheHandler.Managers.DeployManager - [Thread 4] Trying to deploy. Running: False. Deploy marker was set: False
2016-10-08 20:11:51,993 [9] DEBUG Concorde.CacheHandler.Managers.DeployManager - [Thread 4] Deploy manager & watcher initialized
2016-10-08 20:11:52,009 [9] INFO Concorde.CacheHandler.LiveEdit.Initializer - [Thread 4] Starting LiveEdit
2016-10-08 20:11:52,024 [9] DEBUG Concorde.CacheHandler.LiveEdit.Initializer - [Thread 4] Turned off foreverFrame and long polling
2016-10-08 20:11:52,024 [9] DEBUG Concorde.CacheHandler.LiveEdit.Initializer - [Thread 4] Mapping routes for hub
2016-10-08 20:11:52,071 [9] INFO Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Connecting to hub
2016-10-08 20:11:53,712 [9] INFO Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to FileService and ContentService events
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'SavedTemplate' on 'FileService'
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'SavedPartialView' on 'Umbraco.Core.Services.FileService' by reflection
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'SavedScript' on 'FileService'
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'SavedStylesheet' on 'FileService'
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'Saved' on 'MacroService'
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'DeletedPartialView' on 'Umbraco.Core.Services.FileService' by reflection
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'DeletedScript' on 'FileService'
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'DeletedTemplate' on 'FileService'
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'DeletedStylesheet' on 'FileService'
2016-10-08 20:11:53,712 [9] DEBUG Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] Subscribing to 'Published' on 'ContentService'
2016-10-08 20:11:53,712 [9] INFO Concorde.CacheHandler.LiveEdit.EventSubscriber - [Thread 4] All events successfully subscribed
Maybe that is only the initiation of Courier.
Do you have any plugins installed? We are using:
imagegen, rjp multiurlpicker, YouTube (a video picker), uSkySlider. U7 Content Grid editor
we are not using any of those plugins. If you look at your dev- kudu interface you will see that you have many git listeners in the kudu trace logs. these are missing from the production version. I have no idea why. What I can see is that this interval is far from being random so I have to wonder what it is doing it. So I assume you as well are losing your w3wp process with a new pid every time? This causes your site to recompile and restart every time. :(
we have done the following to try and remedy:
1 Disable the model builders in web.config as per above. No different.
2 Change our examine settings to use 'sync' instead of local only.
The 10 minute thing makes me think there must be some task that wakes up and initiates this disaster constantly .
Noticed something interesting in some of the above stack traces. In at least one of them, there are 5 lines that say "terminating" just prior to the application pool restart:
2016-10-06 16:36:23,853 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating
2016-10-06 16:36:23,916 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Terminating
2016-10-06 16:36:23,916 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating
2016-10-06 16:36:23,932 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Terminating
2016-10-06 16:36:23,978 [P28560/D3/T41] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Terminating
I find that interesting, because the default for IIS is to restart the application pool after 5 uncaught exceptions (e.g., thread abort exceptions) within a short time period (5 minutes, I think). I'm not sure if "terminating" in these log messages means "aborting a thread", but if it does that would be a good sign that it's IIS that's causing the application pool to restart.
I don't know if Umbraco as a Service (aka, Umbraco Cloud) allows you to configure IIS. If it does, I'd recommend changing the IIS setting so that there is a higher threshold before it causes the app pool to recycle.
As far as what's causing those "terminating" log messages, I have no idea. My best random guess would be that Umbraco intentionally forces long running tasks to quit after 10 minutes.
I cloned our project locally and restored my prod db to a local SQL express to try to reproduce the issue. I could not get it to throw that error. Ever. Completely frustrated.
Should also mention that we have no access to iis or any server patching . Hopefully someone from uaas is watching this thread.
I do not currently have a dev environment, I'm waiting for Courier v3 to be released because it has alot of performance improvements, I created one and stopped the restore process after 20 hours.
The site we are running is quite large, 12 500 content nodes and 2 500 media items. What size is yours?
I find the post from Nicolas really interesting and I've been thinking the same thing. I've looked around but I have not found any way to turn off the default scheduled tasks or the scheduled publishing.
I cloned and published our production website over to another azure web app last night using the same database.
For over 10 hours it is still using the same w3wp process so it is clearly not code that is causing this issue.
My colleague pointed out that when we change the web.config and the site restarts there is no kudu trace log created.
This type of entry
Only gets created when the application is restarted from the portal interface. This to me is not the umbraco restarting but actually the server. Thats why kudu becomes unresponsive during that restart time.
Cimplex. Our site is also large with over 20000 media nodes. We could not restore using courier v2. The guys at UAAS tried v3 on our behalf but it wouldn't work either. We use courier but only in moving our datatypes and settings etc. We can't restore.
I also noticed that there is a two hour time difference between the logfile and the row created in Kudu. That probably wont help us anything but hopefully someone from Umbraco HQ is reading this post.
There are some very important things to note in this document, FCN mode will cause this problem, further more Azure web apps runs on a remote file share, so lots of IO causes issues this issue, so Examine/Lucene needs to be treated differently as well.
Same with Umbraco Cloud (uaas), we have these config policies in place, in some cases we've seen people remove these config settings which can cause problems.
Both me and Mac are running on the Umbraco Cloud. Should the Azure Web Apps best practices be applied when running on UaaS?
When I migrated our site over to UaaS I used the UaaS.cmd to create the .Web and .Core project in our solution and I have only updated the umbracoSettings.config file for the 404 pages and some special character replacements when publishing a node (åäö).
The Azure Web Apps best practices says:
If you have a {machinename} token in your ~/Config/ExamineIndex.config
file remove this part of the path. Example, if you have path that
looks like: "~/AppData/TEMP/ExamineIndexes/{machinename}/External/" it
should be "~/AppData/TEMP/ExamineIndexes/External/"
And mine looks like this:
<ExamineLuceneIndexSets>
<!-- The internal index set used by Umbraco back-office - DO NOT REMOVE -->
<IndexSet SetName="InternalIndexSet" IndexPath="~/App_Data/TEMP/ExamineIndexes/{machinename}/Internal/"/>
<!-- The internal index set used by Umbraco back-office for indexing members - DO NOT REMOVE -->
<IndexSet SetName="InternalMemberIndexSet" IndexPath="~/App_Data/TEMP/ExamineIndexes/{machinename}/InternalMember/">
<IndexAttributeFields>
<add Name="id" />
<add Name="nodeName"/>
<add Name="updateDate" />
<add Name="writerName" />
<add Name="loginName" />
<add Name="email" />
<add Name="nodeTypeAlias" />
</IndexAttributeFields>
</IndexSet>
<!-- Default Indexset for external searches, this indexes all fields on all types of nodes-->
<IndexSet SetName="ExternalIndexSet" IndexPath="~/App_Data/TEMP/ExamineIndexes/{machinename}/External/" />
</ExamineLuceneIndexSets>
Due to the nature of Lucene files and IO latency, you should update
all of your Indexers and Searchers in the
~/Config/ExamineSettings.config file to have these two properties (see
here for more details): useTempStorage="Sync"
tempStorageDirectory="UmbracoExamine.LocalStorage.AzureLocalStorageDirectory,
UmbracoExamine"
@Mac It is correct that IIS is shutting down the site, not ASP.Net. When you see the log entry:
_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()
This means that IIS has shut the site down. If it's ASP.Net (i.e. bumping web.config, deploying to /bin, changing global.asax or App_Code) this log will tell you exactly that.
This makes figuring these issues out quite difficult. For example, to figure out the previous and similar issue that MS caused this issue with KB3000850 was pretty nuts since why would we assume that a Windows Update causes this.
It is very very interesting however about this 10 minute interval, @Herman, can you re-confirm that you're seeing this at 10 minute intervals too?
This happens to our site almost every 10 minutes, sometimes it and happens with a 20 minute gap but mainly 10 minutes between the shutdowns. Please feel free to look in my logfile, our projects name is Axelent registered on my account.
I am 90% sure it is not umbraco causing these restarts. On every other machine or web app I have cloned the project out to it has been 100% stable with zero entries like this happening.
2016-10-10T11-54-25_PRUMWE_002_Shutdown_0s.xml 10/10/2016, 4:54:25 AM 1 KB
2016-10-10T11-55-00_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml 10/10/2016, 4:55:00 AM 1 KB
2016-10-10T12-04-59_PRUMWE_002_Shutdown_0s.xml 10/10/2016, 5:05:00 AM 1 KB
2016-10-10T12-05-37_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml 10/10/2016, 5:05:37 AM 1 KB
2016-10-10T12-15-37_PRUMWE_002_Shutdown_0s.xml 10/10/2016, 5:15:38 AM 1 KB
2016-10-10T12-16-31_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml 10/10/2016, 5:16:32 AM 1 KB
2016-10-10T12-26-13_PRUMWE_002_Shutdown_0s.xml 10/10/2016, 5:26:13 AM 1 KB
2016-10-10T12-27-02_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml 10/10/2016, 5:27:03 AM 1 KB
2016-10-10T12-36-48_PRUMWE_002_Shutdown_0s.xml 10/10/2016, 5:36:49 AM 1 KB
2016-10-10T12-37-26_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml 10/10/2016, 5:37:26 AM 1 KB
2016-10-10T12-47-32_PRUMWE_002_Shutdown_0s.xml 10/10/2016, 5:47:32 AM 1 KB
2016-10-10T12-48-27_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml 10/10/2016, 5:48:27 AM 1 KB
2016-10-10T12-58-27_PRUMWE_002_Shutdown_0s.xml 10/10/2016, 5:58:27 AM 1 KB
2016-10-10T13-00-07_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml 10/10/2016, 6:00:07 AM 1 KB
Editing web.config will not throw this entry because that is just the website restarting. (w3wp process stays the same) .
These entries are the web app restarting. The only reason I can see the web app restarting is a configuration glitch. This glitch is getting expensive however. My site has had zero stability for days.
--edit--
my claim of zero entries is incorrect. I have these entries in other web apps when I restart the webapp, scale the web app etc.
@shannon my indexes and web config files are all as you state they should be.
Just to brainstorm an idea, could it be that some long running operations (e.g., a large Courier job) are causing the websites to auto-scale after 10 minutes of high resource usage, thus interrupting that long running process and leading it to start over again?
Not sure if UaaS does that, but my guess would be that it does do auto scaling of some sort, and I imagine it'd be based on resource usage in a given time interval.
Not sure why it'd do that EVERY 10 minutes, but maybe there could be a bug that would cause that.
The interesting part of this is the SCM_SCRIPT_GENERATOR_ARGS="--basic" ScmType="LocalGit" because that command is specific to the deployments that we do on UaaS and theoretically wouldn't be logged unless an actual deployment is running.
... I will assume that you are not running a deployment every 10 minutes! :)
That provides some information for investigation. I'll see what other info I can get from the team about this. Please keep us posted on any new info.
Hi Herman. I figured out part of the puzzle for my issue of the
constant restarts. It was git listener like I suspected. The issue for
us was having remote development branches. I deleted my remote
origin/branch with the following commands from bash
git branch -a (geta a list of remote branches) git branch -dr
origin/yourremotebranch
See if this solves your issue. Obviously pull all the branches you
want to keep locally first! I have been up for almost one hour now.
600% improvement in uptime!
Hope it helps Mac PS: my site is also running in debug mode but I
don't think you need to do that.
Mac McDell
I'm using Sourcetree and I have not created any new branches. If I type git branch -a I get the following output:
Sadly I didn't solve the issue. It got way better when I deleted and restarted the application from the portal but the problem has returned.
I had almost 13 hours of uptime.
and now every 10 minutes or so i get this
2016-10-11 14:55:07,383 [P24540/D3/T94] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: HostingEnvironment
_shutDownMessage=HostingEnvironment initiated shutdown
HostingEnvironment caused shutdown
_shutDownStack= at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
at System.Environment.get_StackTrace()
2016-10-11 15:05:43,684 [P19992/D2/T22] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: HostingEnvironment
_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()
2016-10-11 15:05:49,106 [P34368/D2/T1] INFO Umbraco.Core.CoreBootManager - Umbraco 7.4.3 application starting on PRUMWEWORKER005
2016-10-11 15:05:49,169 [P34368/D2/T1] INFO Umbraco.Core.PluginManager - Determining hash of code files on disk
2016-10-11 15:16:20,953 [P34368/D2/T32] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: HostingEnvironment
_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()
2016-10-11 15:26:55,518 [P31488/D2/T25] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: HostingEnvironment
_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()
2016-10-11 15:27:14,988 [P13556/D3/T5] INFO Umbraco.Core.CoreBootManager - Umbraco 7.4.3 application starting on PRUMWEWORKER005
We've been gathering some information on your sites to see why the heck this is happening. It does seem odd that these deploy logs sort of coincide with your app shutdowns but we're still unsure if that is a root cause at all.
Can you tell me about these 13 hours of uptime? During that time was anything different to when it started shutting down again now. Even things as mundane as:
During that time my computer was off
I didn't have Kudu open
I was sleeping
There was no traffic to the site
During some testing today I didn't notice the site restarting, so it seems that simple browsing to the site and the site's normal scheduled tasks don't have an impact. I was browsing on the umbraco.io domain, i'm not sure if that would make the site less susceptible to shutdowns or not (i.e. maybe a particular page is executing something that thread aborts).
We've enabled detailed logging of your site(s), you can see the extra logs in Kudu including IIS request logs, you might be able to see if there's a pattern for the a particular request that is made when the app is shutdown.
Do you know if you have something like the logstream (in kudu) open all the time or maybe have something setup against the logstream?
Uptime was between 1900 - 0800 PST (pacific time) on a long weekend.
We had editors on our site working all night.
We would not have had kudu open during this time
at or around the start of business i noticed the site went down again.
I have asked my colleagues to shutdown sourcetree and any other git listener other than git bash and perform a portal restart again to see if it resolves again.
We get constant traffic to the site as we have open APIs that other sites use for canonical reference.
The detailed logs are helping in seeing that the site is behaving as designed. Since it was designed to be used as a reverse proxy with application request routing, many of the external links in the footer/header will be dead as those go to the other websites.
Some of the 400 errors are happening from kudu itself (see attached)
I know that our SQL connection times out due to the size of our site. I have asked UAAS to extend our timeouts to 130 seconds but gotten nowhere on that request as well.
Regarding this SQL timeout issue - you will need to describe what query/process you are executing that times out and requires a timeout increase. This is a cause for concern since this shouldn't be required.
note the pid (process IDs) it kills the w3wp and then creates a new one.
the next entry is this.... argghhhhh I can't get the next entry because kudu has gone dead again. (wait one minute, refresh browser) ...
okay next entry
detailed errors only report commandstream/abort, or reconnect
and finally in the PrumWeWorkerLog file this is the matching entry
2016-10-11 16:20:38,092 [P30768/D2/T4] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: HostingEnvironment
_shutDownMessage=HostingEnvironment initiated shutdown
HostingEnvironment caused shutdown
_shutDownStack= at System.Environment.GetStackTrace(Exception e, Boolean needFileInfo)
at System.Environment.get_StackTrace()
What do you think is going on? I should note that during my uptime I was on the kudu interface and watching intently the uptime. Then this morning it went off again.
We've discovered the issue which is that both of your sites are reaching the upper memory limit reserved for the w3wp process ( > 1GB )
These logs are not bubbled up via kudu unfortunately but only on the web workers itself. For example, this is the entry:
Application pool '03d2d935-1b6e-4b18-8652-221b944dd8bc' (PID 10440,12132,14328) reached the private memory limit with current memory in use 257929216 and peak at 1337802752.
We've checked that both axelent and tradereditorials have these messages before they restart. The Kudu logs you are seeing most likely occur because of this shutdown and are not the actual cause for the shutdown.
I will take memory dumps of both of these sites to see what is using all of the memory. Since the sites shutdown continuously I would suspect there is a memory leak.
Shannon.
Can you scale us up to validate your assumption? We sure would appreciate if this can be done even for the short term. Otherwise we are just wasting time chasing other assumptions. If it is indeed a scaling issue then the answer is to just do that and we pay for that scaling.
The problem is definitely a memory issue, the logs tell us that it's shut down due to the memory limits in place. The next step is to capture a memory dump for when your site is using this much memory. I was monitoring it today and it seemed relatively stable (no more than 400MB). I also browsed around several of the pages and although the memory would increase it wouldn't spike and would also return to < 400 MB.
So something is spiking the memory usage and we need to get a memory dump when this occurs. Your logs indicate that the site hasn't been shutdown for 12 hrs now. I'm interested to know what chain of events cause the memory to increase by so much. A memory dump will definitely show what the cause of the problem is but it needs to be taken when the mem usage is high. I'll try to keep my on it tonight for a bit to see if it increases.
I can see what might be possible regarding the mem limits for this site, alternatively we have reserved workers but these are only for temporary use cases.
We just did a deploy to production to add more memory caches. I can tell you this. We are about to hammer the hell out of the site when I open the api to one of our parent websites. Its gonna start out hitting it at about 380 requests per minute. Guess we will be testing that unlimited bandwidth setting.
What is really weird is we were doing the same thing and clicking around, hitting our APIs again. etc.. Couldn't get the memory above 400mb. We were able to occasionally get the virtual memory above 1.3gb.
When we did a deploy I noticed in the portal that again I was seeing the wrong branch asking to deploy to production. The site would not start for over 5 minutes. Once I deleted the remote branches it started again. I fully realize that this issue could be completely unrelated but weird (in so many ways) .
We are very happy to hear you assume it is memory. Something we can solve. Are you looking at private memory or virtual memory? we can also say we have been stable for hours today.
That follows almost exactly in line with the fact that our site went bonkers when doing a deploy. Our examine indexes needed to be rebuilt and models created. It was completely stalled. I had to try and do portal restart at least 3 times.
Since a NuGet upgrade to 7.5.3 (and 7.5.4 today), we get more shutdowns related to "change notification for critical directories". This is running on our locally-hosted Win2008 SP1 server. Sounds maybe not quite related to the above thread, but we hadn't had as many shutdowns in the past, this occurs about daily for us.
2016-10-20 15:51:58,101 [P6112/D5/T11] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: CodeDirChangeOrDirectoryRename
_shutDownMessage=Change Notification for critical directories.
App_Code dir change or directory rename
HostingEnvironment initiated shutdown
Change Notification for critical directories.
App_Code dir change or directory rename
Change Notification for critical directories.
App_Code dir change or directory rename
Change Notification for critical directories.
bin dir change or directory rename
Change Notification for critical directories.
bin dir change or directory rename
Change Notification for critical directories.
bin dir change or directory rename
HostingEnvironment caused shutdown
I wanted to follow up with some closure regarding our constant 10 minute restarts. It seems we were somehow exceeding memory utilization and that was triggering the restart. The memory was due to misunderstanding of umbraco helper code best practices. Once we cleaned up our usage of statics and started querying much more efficiently our restart issues have disappeared. Also for anyone waiting to move to 7.5.X you should not wait. It is definitely worth moving from 7.4.x.
We still have some issues with courier but UAAS is helping use with that and they are getting dealt with one at a time.
Hey Mac,
Have been following this thread as I have some odd restarts/delays on my local dev machine (but production seems ok), most likely not related. That said, would love to have a bit of insight or example of what your misunderstanding with helper code best practices was. I'm now concerned that maybe I've made the same mistake. Not looking for anything complex, just a general idea of what you were doing and what you changed to in order to improve things.
Hi Phil. I went through some history on a few commits that we could easily measure performance improvement. Consider the following (repositoryHelper is an extension of umbracohelper where we just jump to our article repository. It is static.. bad:
var result = RepositoryHelper.GetExpertArticlesRepo()
.Children
.FirstOrDefault(x => x.GetPropertyValue<string>("wpPostId")
.Equals(PostId.ToString()));
return result != null ? result.Url.Replace("/this/en/","/that/" ) : "";
this took between 1000 and 1500 ms.
this is refactored:
private readonly UmbracoHelper _umbracoHelper = new UmbracoHelper(UmbracoContext.Current);
public string GetCanonical(int postId)
{
try
{
var content = _umbracoHelper
.TypedContentAtXPath($"//{Constants.DocumentTypesAlias.ReviewArticle}[wpPostId='{postId}']")
.FirstOrDefault();
return content?.Url.Replace("/this/en/", "/that/") ?? "";
}...
After refactor the return is roughly 5ms. That is a 300 times improvement!
Note that we also new up the umbraco helper each time vs a single static instance.
This would probably be the most basic example of how to better query content.
Another example of before and after where something was taking upwards of 400ms and was refacted to < 5ms to complete:
refactored:
public static string GetUrlAlias(int nodeId)
{
var xPath = String.Format("//language[@nodeName='{0}']/{1}/{2}[@id='{3}']/umbracoUrlAlias",
CurrentLanguage, DocumentTypesAlias.Repository, DocumentTypesAlias.Article, nodeId);
var nodeIterator = UmbracoContext.Current.ContentCache.GetXPathNavigator().Select(xPath);
if (nodeIterator.MoveNext())
return nodeIterator.Current.Value;
return null;
}
Anything that we use loops or querying we are looking to the xpath or xpathnavigator to help reduce query time. We are also going against our ContentCache. Hope this stuff helps you out a bit.
Just a couple more tips which might help. This is assuming that you are not running on Umbraco Cloud (UaaS):
Ensure that you have anti-virus totally disabled for any active or scheduled scanning of files in your web application, depending on the anti-virus product we've seen issues like app restarts, lucene index, corruption, etc...
Check your ExamineSettings.config - if you are not running on Azure webapps or UaaS then you should not have any useTempStorage settings
Just adding that we have no antivirus auto-scanning (for a host of other conflict reasons), and our ExamineSettings.config doesn't include useTempStorage. Having trouble tracking down what exactly is causing the "CodeDirChangeOrDirectoryRename" shutdown (see tracelog above), but i should add the last line of the tracelog before it restarts is:
Change in C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\b0178927\8300ce6\hash\hash.web
HostingEnvironment caused shutdown
Just jumping on this as I have the same issue with a just-upgraded-to 7.5.4. Symptoms are as described - slow access on initial hit, constant restarts (details below).
I tried the 1st suggestion - turn off the "model" stuff. That appears to have fixed it.
This is stock standard, no plugins or Git or anything fancy. BUT it is on Rackspace Cloud..... which is probably why I'm having the problem.
--
Otherwise, I have not yet implemented the "cloudy" "best practices", which suggest:
If you have a {machinename} token in your ~/Config/ExamineIndex.config
file remove this part of the path. ...
That's interesting that someone told you to remove machine name. We were told to explicitly add it back in and that helped with the recompilation issue. We also use sync setting. If you are using vanilla umbraco having your models set to purelive I think is the recommended. Otherwise if you are using logic libraries or actually using models you might use DLL. There is a good write-up on this. Just search around.
I am not a semi-pro or pro website builder but I sometimes make some sites for our uni research group.
Ages ago, I built:
www.catsense.eu (Umbraco version 7.4.3 assembly: 1.0.5948.18141) and www.econos2015.org (Umbraco version 7.2.1 assembly: 1.0.5462.37503)
The econos site was recently copied to run exactly the same doc types, plugins, whatever over at www.maf15.org. However, maf15 runs the latest and greatest 7.5.4 assembly: 1.0.6136.27241.
Lo and behold, my logs are full of these entries:
_shutDownMessage=Recompilation limit of 15 reached
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.HttpRuntime.ShutdownAppDomain(String stackTrace)
at System.Web.Compilation.DiskBuildResultCache.ShutdownCallBack(Object state)
at System.Threading.QueueUserWorkItemCallback.WaitCallback_Context(Object state)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
at System.Threading.ThreadPoolWorkQueue.Dispatch()
at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()
Performance on maf15 is truly abysmal... Much worse than the almost identical econos2015. Even when the application is started, page loads within the site take forever, even for virtually empty pages.
I have no clue what could be going on.
I will try the early suggestion by Nicolas to disable the ModelsBuilder but I'm actually tempted to just downgrade to some earlier version of Umbraco.
Upgraded to V7.5.11, it still happens, but not that frequent anymore nor does it impact the site and it's active connections.
About the KB3000850 we've applied the MS hotfix for it.
Log from last night, this mornings log was without errors.
2017-03-21 22:11:53,567 [P4464/D13/T16] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: MaxRecompilationsReached
_shutDownMessage=Recompilation limit of 50 reached
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.HttpRuntime.ShutdownAppDomain(String stackTrace)
at System.Web.Compilation.DiskBuildResultCache.ShutdownCallBack(Object state)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
at System.Threading.ThreadPoolWorkQueue.Dispatch()
2017-03-21 22:12:30,815 [P4464/D14/T9] INFO umbraco.BusinessLogic.Log - Log scrubbed. Removed all items older than 2017-03-20 22:12:30
2017-03-21 22:15:07,781 [P4464/D14/T11] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2017-03-21 22:15:07,782 [P4464/D14/T11] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 0ms)
2017-03-21 22:15:07,808 [P4464/D14/T11] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.cms.businesslogic.macro.IMacroEngine
2017-03-21 22:15:07,809 [P4464/D14/T11] INFO Umbraco.Core.PluginManager - Completed resolution of types of umb
raco.cms.businesslogic.macro.IMacroEngine, found 0 (took 1ms)
2017-03-21 22:31:48,252 [P4464/D14/T48] INFO MissingCode.Umbraco.PdfThumbnail.ThumbnailGenerator - Started Creatning Thumbnail
2017-03-21 22:31:48,278 [P4464/D14/T48] ERROR MissingCode.Umbraco.PdfThumbnail.ThumbnailGenerator - Faled generat pdf thumbnail
System.BadImageFormatException: An attempt was made to load a program with an incorrect format. (Exception from HRESULT: 0x8007000B)
at GhostscriptSharp.GhostscriptWrapper.CreateAPIInstance(IntPtr& pinstance, IntPtr caller_handle)
at GhostscriptSharp.GhostscriptWrapper.CallAPI(String[] args)
at GhostscriptSharp.GhostscriptWrapper.GeneratePageThumb(String inputPath, String outputPath, Int32 page, Int32 width, Int32 height)
at MissingCode.Umbraco.PdfThumbnail.ThumbnailGenerator.Generate(String file)
2017-03-21 22:31:48,279 [P4464/D14/T48] INFO MissingCode.Umbraco.PdfThumbnail.ThumbnailGenerator - Completed Creating Thumbnail (took 27ms)
2017-03-21 22:38:19,668 [P4464/D14/T22] INFO Umbraco.Web.Editors.AuthenticationController - User laurens.gregoir from IP address 213.246.234.50 has logged out
Thanks, let me correct myself. We've applied the hotfix. Not removed it, but when you search the KB you no longer find it. Hence I thought it was removed.
Will check out the missingcode error. It's from a plugin that generates thumbnails from PDF files.
Below is the logfile, seems that changing the Umbraco.ModelsBuilder.Enable to false causes the termination of the IIS.
When I set it back to true, it immediatly works again.
So this starts me to believe this is a big bug in Umbraco.
_shutDownMessage=CONFIG change
HostingEnvironment initiated shutdown
CONFIG change
CONFIG change
CONFIG change
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.HttpRuntime.ShutdownAppDomain(String stackTrace)
at System.Web.Configuration.HttpConfigurationSystem.OnConfigurationChanged(Object sender, InternalConfigEventArgs e)
at System.Configuration.Internal.InternalConfigRoot.OnConfigChanged(InternalConfigEventArgs e)
at System.Configuration.BaseConfigurationRecord.OnStreamChanged(String streamname)
at System.Web.DirectoryMonitor.FireNotifications()
at System.Web.Util.WorkItem.CallCallbackWithAssert(WorkItemCallback callback)
at System.Web.Util.WorkItem.OnQueueUserWorkItemCompletion(Object state)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
at System.Threading.ThreadPoolWorkQueue.Dispatch()
2017-03-17 08:34:53,302 [P5472/D19/T15] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
2017-03-17 08:34:53,303 [P5472/D19/T15] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 0ms)
2017-03-17 08:34:53,481 [P5472/D19/T15] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2017-03-17 08:34:53,481 [P5472/D19/T15] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 0ms)
2017-03-17 08:34:53,507 [P5472/D19/T15] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.cms.businesslogic.macro.IMacroEngine
2017-03-17 08:34:53,508 [P5472/D19/T15] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 0 (took 0ms)
2017-03-17 08:35:13,697 [P5472/D18/T59] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: ConfigurationChange
_shutDownMessage=CONFIG change
HostingEnvironment initiated shutdown
CONFIG change
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.HttpRuntime.ShutdownAppDomain(String stackTrace)
at System.Web.Configuration.HttpConfigurationSystem.OnConfigurationChanged(Object sender, InternalConfigEventArgs e)
at System.Configuration.Internal.InternalConfigRoot.OnConfigChanged(InternalConfigEventArgs e)
at System.Configuration.BaseConfigurationRecord.OnStreamChanged(String streamname)
at System.Web.DirectoryMonitor.FireNotifications()
at System.Web.Util.WorkItem.CallCallbackWithAssert(WorkItemCallback callback)
at System.Web.Util.WorkItem.OnQueueUserWorkItemCompletion(Object state)
at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)
at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()
at System.Threading.ThreadPoolWorkQueue.Dispatch()
2017-03-17 08:35:47,364 [P5472/D19/T61] INFO umbraco.BusinessLogic.Log - Log scrubbed. Removed all items older than 2017-03-16 08:35:47
Just deployed a new site now, v7.7.7, and we have had very similar experiences to those described here. Just after we went live, the problem was very frequent application restarts (every 15-60 mins) due to “recompilation limit of 50 reached”. Increased this to 100 in web.config and that problem seems to be gone entirely. Which is kind of weird - is there really a “magical” number of recompilations Umbraco (models builder?) needs to avoid application restarts?
We still have shutdown/restart about once a day, but the reason now is “HostingEnvironment initiated”, as described in the original post. The call stack is identical to this, and it’s the same every time. We would very much like to get rid of these seemingly pointless shutdowns as well, so if anyone has any light to shed or experiences to share, it would be most welcome. There must be a ghost that’s still hiding somewhere...
Umbraco 7.7.7, uSync, Azure VM Windows Server 2017, IIS 10, SQL Server 2017
We still have shutdown/restart about once a day, but the reason now is “HostingEnvironment initiated”, as described in the original post.
IIS by default is configured to shutdown every 29 hours (to clear out memory and such and give the website a "fresh start"). You can change this configuration so it restarts less frequently.
You can change that setting by right clicking on the application pool in IIS, selecting "Recycling", then changing the setting on this screen:
Thanks Nicholas, this explains it! And it's probably a good thing to let IIS clean up regularly, I think we'll leave it as is. After all, it just means there will be a very short window of slow response on the site every 29 hrs. We can live with that.
I still don't understand the recompilation restarts, but it seems not to be a problem any longer, so I'll stop worrying about it for now. I will be keeping an eye on it though...
Recurring application shutdown issue on Umbraco 7.5.3
Hi guys,
We are faced with an issue where quite a few application shutdowns are being encountered on Umbraco v7.5.3. Does anyone have any similar experience and if so is there a way to fix this?
The setup is as follows:
Umbraco V7.5.3 (Nuget installed) Windows Server 2012 R2 Standard Database: MSSQL Server 2014
The Umbraco installation is used to host multiple domains. Two domains are set up on two nodes using Culture and Hostnames. One site is set up in IIS for Umbraco, and it has it's own application pool. Site bindings in IIS are used to point multiple domains to the Umbraco instance, and Culture and Hostnames are used to resolve which node to load.
The problem:
Loading one site initially takes about 8 seconds, after that if we were to refresh the page the site loads up fast in under one second. Then when we try to load a different domain on another node the load time is again about 8 seconds. It appears that loading a different node causes a lag every single time.
In the logs we can see that the following is happening :
There is also the following but not as regularly as the above.
Also there is an error from UmbracoExamine.DataServices.UmbracoLogService that keeps showing up.
There is a similar issue regarding maximum compilations here: https://our.umbraco.org/forum/umbraco-7/using-umbraco-7/73634-umbraco-using-a-lot-of-cpu
The following pages seem to suggest Windows updates may be the cause.
https://our.umbraco.org/forum/core/general/63671-Application-shutdown-Reason-ConfigurationChange
https://our.umbraco.org/forum/getting-started/installing-umbraco/72398-hostingenvironment-initiated-shutdown#comment-232499
According to the above, the following Windows updates have been known to cause issues:
KB3007507 (This was never installed in the first place)
KB3000850 (Removed from server but didn't make a difference)
The following update is a fix that had worked on certain instances:
KB3052480 (Was always installed on the server in our case)
We are starting to run out of ideas. Any feedback is much appreciated!
You could try disabling models builder (web.config change):
Might help with the "recompilation limit". Otherwise, I'd just make sure every single Windows update, including the recommended/optional ones, are installed.
Also, there is a setting in IIS that will recycle the application pool if too many errors occur on threads that causes those threads to abort. You can change the setting to increase the threshold so those recycles are less likely.
Thanks for the suggestions!
Disabling models builder definitely made a big difference. Sites are loading much faster and the errors seem to have disappeared, although I did still get the HostingEnvironment initiated shutdown once.
I've slightly increased the failure threshold on the application pool to reduce likelihood of it being recycled.
Happy to hear it helped somewhat.
FYI, I think the default for IIS is to recycle the application pool when there are 5 errors in 5 minutes (or roundabouts). I typically change that to 100 errors in 5 minutes.
Let me know if you are still getting the HostingEnvironment initiated shutdown periodically and I can give you some more ideas.
I experience shutdowns as well running on UaaS. This log keeps recurring each 10 minutes and it takes like 10 seconds for the site to start again. Any ideas?
We are experiencing the exact same issue. Let us know if you come up with any ideas. We are trying the models builder config change as well. Umbraco 7.4.3
---updatee-- We changed the models builder settings and did not get any changes of the site still restarting literally every ten minutes on UAAS. Pretty disappointing.
I have been doing more research into what might be happening with our constant restarts every 10 minutes in production. These are my findings.: from kudu I observe the following: in Logfiles > Kudu > Trace you will see the log is filled with 'server'StartupGETapi-commandstream-reconnect0s.xml and 22PRUMWE002Shutdown_0s.xml Both of these events happen roughly 10 minutes apart from each other.
the first one (command stream reconnect) this step essentially creates/starts the w3wp worker pid 17636,2,7
10 minutes later the w3wp process gets shutdown with the following
Note that it kills pid 17636, 2,30
The next step instantly starts another w3wp process with a new pid.
Interesting, I have a cuple of those as well and they occur with a 10 minute interval. I found this in the CourierTraceLog file (wwwroot/App_Data/Logs/CourierTraceLog.txt) this is happening to our site with a interval of 10 minutes:
Maybe that is only the initiation of Courier.
Do you have any plugins installed? We are using: imagegen, rjp multiurlpicker, YouTube (a video picker), uSkySlider. U7 Content Grid editor
we are not using any of those plugins. If you look at your dev- kudu interface you will see that you have many git listeners in the kudu trace logs. these are missing from the production version. I have no idea why. What I can see is that this interval is far from being random so I have to wonder what it is doing it. So I assume you as well are losing your w3wp process with a new pid every time? This causes your site to recompile and restart every time. :(
we have done the following to try and remedy:
1 Disable the model builders in web.config as per above. No different.
2 Change our examine settings to use 'sync' instead of local only.
The 10 minute thing makes me think there must be some task that wakes up and initiates this disaster constantly .
Noticed something interesting in some of the above stack traces. In at least one of them, there are 5 lines that say "terminating" just prior to the application pool restart:
I find that interesting, because the default for IIS is to restart the application pool after 5 uncaught exceptions (e.g., thread abort exceptions) within a short time period (5 minutes, I think). I'm not sure if "terminating" in these log messages means "aborting a thread", but if it does that would be a good sign that it's IIS that's causing the application pool to restart.
I don't know if Umbraco as a Service (aka, Umbraco Cloud) allows you to configure IIS. If it does, I'd recommend changing the IIS setting so that there is a higher threshold before it causes the app pool to recycle.
As far as what's causing those "terminating" log messages, I have no idea. My best random guess would be that Umbraco intentionally forces long running tasks to quit after 10 minutes.
Nicholas,
The "Terminating" log is normal, we write out that entry.
I cloned our project locally and restored my prod db to a local SQL express to try to reproduce the issue. I could not get it to throw that error. Ever. Completely frustrated. Should also mention that we have no access to iis or any server patching . Hopefully someone from uaas is watching this thread.
I do not currently have a dev environment, I'm waiting for Courier v3 to be released because it has alot of performance improvements, I created one and stopped the restore process after 20 hours.
The site we are running is quite large, 12 500 content nodes and 2 500 media items. What size is yours?
I find the post from Nicolas really interesting and I've been thinking the same thing. I've looked around but I have not found any way to turn off the default scheduled tasks or the scheduled publishing.
I cloned and published our production website over to another azure web app last night using the same database. For over 10 hours it is still using the same w3wp process so it is clearly not code that is causing this issue. My colleague pointed out that when we change the web.config and the site restarts there is no kudu trace log created. This type of entry
Only gets created when the application is restarted from the portal interface. This to me is not the umbraco restarting but actually the server. Thats why kudu becomes unresponsive during that restart time.
Cimplex. Our site is also large with over 20000 media nodes. We could not restore using courier v2. The guys at UAAS tried v3 on our behalf but it wouldn't work either. We use courier but only in moving our datatypes and settings etc. We can't restore.
Okey, then it might be the size of the website that is causing this problem because that is pretty much what we have in common.
I looked more closely into the /LogFiles/kudu/trace folder and these two events have been occurring for the last 24 hours every 10 minutes:
Here is an example from the PRUMWE_001 log:
And from PRUMWE_002:
I also noticed that there is a two hour time difference between the logfile and the row created in Kudu. That probably wont help us anything but hopefully someone from Umbraco HQ is reading this post.
Mac, can you please send me your contacts to [email protected]?
If people are using azure web apps ensure you've read this: https://our.umbraco.org/documentation/Getting-Started/Setup/Server-Setup/azure-web-apps
There are some very important things to note in this document, FCN mode will cause this problem, further more Azure web apps runs on a remote file share, so lots of IO causes issues this issue, so Examine/Lucene needs to be treated differently as well.
Same with Umbraco Cloud (uaas), we have these config policies in place, in some cases we've seen people remove these config settings which can cause problems.
Hi Shannon,
Both me and Mac are running on the Umbraco Cloud. Should the Azure Web Apps best practices be applied when running on UaaS?
When I migrated our site over to UaaS I used the UaaS.cmd to create the .Web and .Core project in our solution and I have only updated the umbracoSettings.config file for the 404 pages and some special character replacements when publishing a node (åäö).
The Azure Web Apps best practices says:
And mine looks like this:
Mine:
The fcnMode is set to single and the log4net is set to WARN. I don't know how to see the Azure SQL Tier on UaaS.
// Herman
Thanks, those settings all look fine for UaaS.
@Mac It is correct that IIS is shutting down the site, not ASP.Net. When you see the log entry:
This means that IIS has shut the site down. If it's ASP.Net (i.e. bumping web.config, deploying to /bin, changing global.asax or App_Code) this log will tell you exactly that.
This makes figuring these issues out quite difficult. For example, to figure out the previous and similar issue that MS caused this issue with KB3000850 was pretty nuts since why would we assume that a Windows Update causes this.
It is very very interesting however about this 10 minute interval, @Herman, can you re-confirm that you're seeing this at 10 minute intervals too?
Hi Shannon,
This happens to our site almost every 10 minutes, sometimes it and happens with a 20 minute gap but mainly 10 minutes between the shutdowns. Please feel free to look in my logfile, our projects name is Axelent registered on my account.
// Herman
I am 90% sure it is not umbraco causing these restarts. On every other machine or web app I have cloned the project out to it has been 100% stable with zero entries like this happening.
Editing web.config will not throw this entry because that is just the website restarting. (w3wp process stays the same) . These entries are the web app restarting. The only reason I can see the web app restarting is a configuration glitch. This glitch is getting expensive however. My site has had zero stability for days.
--edit-- my claim of zero entries is incorrect. I have these entries in other web apps when I restart the webapp, scale the web app etc.
@shannon my indexes and web config files are all as you state they should be.
Just to brainstorm an idea, could it be that some long running operations (e.g., a large Courier job) are causing the websites to auto-scale after 10 minutes of high resource usage, thus interrupting that long running process and leading it to start over again?
Not sure if UaaS does that, but my guess would be that it does do auto scaling of some sort, and I imagine it'd be based on resource usage in a given time interval.
Not sure why it'd do that EVERY 10 minutes, but maybe there could be a bug that would cause that.
UaaS does not do any Scaling.
With regards to these logs. What you are seeing is these:
The interesting part of this is the
SCM_SCRIPT_GENERATOR_ARGS="--basic" ScmType="LocalGit"
because that command is specific to the deployments that we do on UaaS and theoretically wouldn't be logged unless an actual deployment is running.... I will assume that you are not running a deployment every 10 minutes! :)
That provides some information for investigation. I'll see what other info I can get from the team about this. Please keep us posted on any new info.
Hi, I just got this email from Mac, it might help
I'm using Sourcetree and I have not created any new branches. If I type git branch -a I get the following output:
// Herman
Sadly I didn't solve the issue. It got way better when I deleted and restarted the application from the portal but the problem has returned. I had almost 13 hours of uptime. and now every 10 minutes or so i get this
ohhhhhh this sucks so much...
We've been gathering some information on your sites to see why the heck this is happening. It does seem odd that these deploy logs sort of coincide with your app shutdowns but we're still unsure if that is a root cause at all.
Can you tell me about these 13 hours of uptime? During that time was anything different to when it started shutting down again now. Even things as mundane as:
During some testing today I didn't notice the site restarting, so it seems that simple browsing to the site and the site's normal scheduled tasks don't have an impact. I was browsing on the umbraco.io domain, i'm not sure if that would make the site less susceptible to shutdowns or not (i.e. maybe a particular page is executing something that thread aborts).
We've enabled detailed logging of your site(s), you can see the extra logs in Kudu including IIS request logs, you might be able to see if there's a pattern for the a particular request that is made when the app is shutdown.
Do you know if you have something like the logstream (in kudu) open all the time or maybe have something setup against the logstream?
Uptime was between 1900 - 0800 PST (pacific time) on a long weekend. We had editors on our site working all night. We would not have had kudu open during this time
at or around the start of business i noticed the site went down again. I have asked my colleagues to shutdown sourcetree and any other git listener other than git bash and perform a portal restart again to see if it resolves again.
We get constant traffic to the site as we have open APIs that other sites use for canonical reference. The detailed logs are helping in seeing that the site is behaving as designed. Since it was designed to be used as a reverse proxy with application request routing, many of the external links in the footer/header will be dead as those go to the other websites.
Some of the 400 errors are happening from kudu itself (see attached)
I know that our SQL connection times out due to the size of our site. I have asked UAAS to extend our timeouts to 130 seconds but gotten nowhere on that request as well.
Regarding this SQL timeout issue - you will need to describe what query/process you are executing that times out and requires a timeout increase. This is a cause for concern since this shouldn't be required.
This is the shutdown request:
this is the startup
note the pid (process IDs) it kills the w3wp and then creates a new one.
the next entry is this.... argghhhhh I can't get the next entry because kudu has gone dead again. (wait one minute, refresh browser) ... okay next entry
Rinse...Repeat..lather as necessary... (this is what killed the process again. )
The only 400s I see in the http raw logs are kudu connection issues:
detailed errors only report commandstream/abort, or reconnect
and finally in the PrumWeWorkerLog file this is the matching entry
What do you think is going on? I should note that during my uptime I was on the kudu interface and watching intently the uptime. Then this morning it went off again.
Hi all,
We've discovered the issue which is that both of your sites are reaching the upper memory limit reserved for the w3wp process ( > 1GB )
These logs are not bubbled up via kudu unfortunately but only on the web workers itself. For example, this is the entry:
We've checked that both axelent and tradereditorials have these messages before they restart. The Kudu logs you are seeing most likely occur because of this shutdown and are not the actual cause for the shutdown.
I will take memory dumps of both of these sites to see what is using all of the memory. Since the sites shutdown continuously I would suspect there is a memory leak.
Shannon. Can you scale us up to validate your assumption? We sure would appreciate if this can be done even for the short term. Otherwise we are just wasting time chasing other assumptions. If it is indeed a scaling issue then the answer is to just do that and we pay for that scaling.
The problem is definitely a memory issue, the logs tell us that it's shut down due to the memory limits in place. The next step is to capture a memory dump for when your site is using this much memory. I was monitoring it today and it seemed relatively stable (no more than 400MB). I also browsed around several of the pages and although the memory would increase it wouldn't spike and would also return to < 400 MB.
So something is spiking the memory usage and we need to get a memory dump when this occurs. Your logs indicate that the site hasn't been shutdown for 12 hrs now. I'm interested to know what chain of events cause the memory to increase by so much. A memory dump will definitely show what the cause of the problem is but it needs to be taken when the mem usage is high. I'll try to keep my on it tonight for a bit to see if it increases.
I can see what might be possible regarding the mem limits for this site, alternatively we have reserved workers but these are only for temporary use cases.
We just did a deploy to production to add more memory caches. I can tell you this. We are about to hammer the hell out of the site when I open the api to one of our parent websites. Its gonna start out hitting it at about 380 requests per minute. Guess we will be testing that unlimited bandwidth setting. What is really weird is we were doing the same thing and clicking around, hitting our APIs again. etc.. Couldn't get the memory above 400mb. We were able to occasionally get the virtual memory above 1.3gb. When we did a deploy I noticed in the portal that again I was seeing the wrong branch asking to deploy to production. The site would not start for over 5 minutes. Once I deleted the remote branches it started again. I fully realize that this issue could be completely unrelated but weird (in so many ways) .
We are very happy to hear you assume it is memory. Something we can solve. Are you looking at private memory or virtual memory? we can also say we have been stable for hours today.
At around 7:38 PM tonight (Central European time) we saw the site exceed 1GB and that memory jumped from 400MB to > 1GB very quickly.
I'll respond on Zendesk with some additional information regarding your site.
That follows almost exactly in line with the fact that our site went bonkers when doing a deploy. Our examine indexes needed to be rebuilt and models created. It was completely stalled. I had to try and do portal restart at least 3 times.
Since a NuGet upgrade to 7.5.3 (and 7.5.4 today), we get more shutdowns related to "change notification for critical directories". This is running on our locally-hosted Win2008 SP1 server. Sounds maybe not quite related to the above thread, but we hadn't had as many shutdowns in the past, this occurs about daily for us.
I wanted to follow up with some closure regarding our constant 10 minute restarts. It seems we were somehow exceeding memory utilization and that was triggering the restart. The memory was due to misunderstanding of umbraco helper code best practices. Once we cleaned up our usage of statics and started querying much more efficiently our restart issues have disappeared. Also for anyone waiting to move to 7.5.X you should not wait. It is definitely worth moving from 7.4.x. We still have some issues with courier but UAAS is helping use with that and they are getting dealt with one at a time.
Hey Mac, Have been following this thread as I have some odd restarts/delays on my local dev machine (but production seems ok), most likely not related. That said, would love to have a bit of insight or example of what your misunderstanding with helper code best practices was. I'm now concerned that maybe I've made the same mistake. Not looking for anything complex, just a general idea of what you were doing and what you changed to in order to improve things.
Thanks in advance. Phill
Hi Phil. I went through some history on a few commits that we could easily measure performance improvement. Consider the following (repositoryHelper is an extension of umbracohelper where we just jump to our article repository. It is static.. bad:
this took between 1000 and 1500 ms.
this is refactored:
After refactor the return is roughly 5ms. That is a 300 times improvement! Note that we also new up the umbraco helper each time vs a single static instance.
This would probably be the most basic example of how to better query content.
Another example of before and after where something was taking upwards of 400ms and was refacted to < 5ms to complete:
refactored:
Anything that we use loops or querying we are looking to the xpath or xpathnavigator to help reduce query time. We are also going against our ContentCache. Hope this stuff helps you out a bit.
Hi All,
Just a couple more tips which might help. This is assuming that you are not running on Umbraco Cloud (UaaS):
useTempStorage
settingsJust adding that we have no antivirus auto-scanning (for a host of other conflict reasons), and our ExamineSettings.config doesn't include useTempStorage. Having trouble tracking down what exactly is causing the "CodeDirChangeOrDirectoryRename" shutdown (see tracelog above), but i should add the last line of the tracelog before it restarts is:
Just jumping on this as I have the same issue with a just-upgraded-to 7.5.4. Symptoms are as described - slow access on initial hit, constant restarts (details below).
I tried the 1st suggestion - turn off the "model" stuff. That appears to have fixed it.
This is stock standard, no plugins or Git or anything fancy. BUT it is on Rackspace Cloud..... which is probably why I'm having the problem.
-- Otherwise, I have not yet implemented the "cloudy" "best practices", which suggest:
2016-10-30 00:23:03,259 [P9648/D87/T18] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: MaxRecompilationsReached _shutDownMessage=Recompilation limit of 15 reached HostingEnvironment initiated shutdown HostingEnvironment caused shutdown
That's interesting that someone told you to remove machine name. We were told to explicitly add it back in and that helped with the recompilation issue. We also use sync setting. If you are using vanilla umbraco having your models set to purelive I think is the recommended. Otherwise if you are using logic libraries or actually using models you might use DLL. There is a good write-up on this. Just search around.
Hi guys,
I am not a semi-pro or pro website builder but I sometimes make some sites for our uni research group.
Ages ago, I built:
www.catsense.eu (Umbraco version 7.4.3 assembly: 1.0.5948.18141) and www.econos2015.org (Umbraco version 7.2.1 assembly: 1.0.5462.37503)
The econos site was recently copied to run exactly the same doc types, plugins, whatever over at www.maf15.org. However, maf15 runs the latest and greatest 7.5.4 assembly: 1.0.6136.27241.
Lo and behold, my logs are full of these entries:
Performance on maf15 is truly abysmal... Much worse than the almost identical econos2015. Even when the application is started, page loads within the site take forever, even for virtually empty pages.
I have no clue what could be going on.
I will try the early suggestion by Nicolas to disable the ModelsBuilder but I'm actually tempted to just downgrade to some earlier version of Umbraco.
FWIW, after the introducing the changes:
Things seem to have improved for me and response seems OK now... bizarre.
Thanks for the updated info, there's another setting you could try as well:
numRecompilesBeforeAppRestart
, see: http://stackoverflow.com/questions/39050231/asp-net-mvc-recompilation-limit-of-15-reached-hostingenvironment-initiated-shutdThere is probably a Models Builder update too which I would suggest you should try https://www.nuget.org/packages/Umbraco.ModelsBuilder/
Same issue is happening on my site. We are using V7.5.9
Link to my issue: https://our.umbraco.org/forum/using-umbraco-and-getting-started/84558-when-creating-a-new-document-type-and-template-umbraco-crashes
So how do I best solve this? Increasing the numRecompilesBeforeAppRestart from 15 to 100?
My web.config doesn't have this setting, so is it somewhere else or just a default IIS value?
Cheers,
Laurens
Try using 7.5.11 and see if the issue is resolved: http://issues.umbraco.org/issue/U4-9257
Hi Shannon,
Upgraded to V7.5.11, it still happens, but not that frequent anymore nor does it impact the site and it's active connections.
About the KB3000850 we've applied the MS hotfix for it.
Log from last night, this mornings log was without errors.
Hi,
You shouldn't remove KB3000850 , you should just apply the MS hotfix for it.
The error you are getting is completely different from the other ones, this is a different shutdown error entirely.
I would suggest you have a look at the code that is causing this which is all custom code according to your stack trace:
starting from:
MissingCode.Umbraco.PdfThumbnail.ThumbnailGenerator
Thanks, let me correct myself. We've applied the hotfix. Not removed it, but when you search the KB you no longer find it. Hence I thought it was removed.
Will check out the missingcode error. It's from a plugin that generates thumbnails from PDF files.
https://our.umbraco.org/projects/backoffice-extensions/pdf-thumbnail/
Hi Shannon,
I will upgrade to v7.5.11 on our next maintenance window. As luck will have it, that's next Tuesday.
Thx!
FYI: When I disable the Modelbuilder, my site stops working.
My Umbraco is running on a VPS server with Win 2012 R2, IIS8 and SQL 2014 and patched reguraly.
Below is the logfile, seems that changing the Umbraco.ModelsBuilder.Enable to false causes the termination of the IIS.
When I set it back to true, it immediatly works again. So this starts me to believe this is a big bug in Umbraco.
On another note, is the KB300850 still an issue for Umbraco? Seems that this is installed our webserver.
http://issues.umbraco.org/issue/U4-6338#
Yes it is still an issue for all ASP.NET web applications for that Windows server version. It's beyond me why this is an optional windows update
We've applied the hotfix during our maintenance window :)
Seems that the server and Umbraco are now working better and the restarts are to a minimum.
Erros are low, but it still shuts down now and again. Though its back online very quickly so you don't really notice it.
Just deployed a new site now, v7.7.7, and we have had very similar experiences to those described here. Just after we went live, the problem was very frequent application restarts (every 15-60 mins) due to “recompilation limit of 50 reached”. Increased this to 100 in web.config and that problem seems to be gone entirely. Which is kind of weird - is there really a “magical” number of recompilations Umbraco (models builder?) needs to avoid application restarts?
We still have shutdown/restart about once a day, but the reason now is “HostingEnvironment initiated”, as described in the original post. The call stack is identical to this, and it’s the same every time. We would very much like to get rid of these seemingly pointless shutdowns as well, so if anyone has any light to shed or experiences to share, it would be most welcome. There must be a ghost that’s still hiding somewhere...
Umbraco 7.7.7, uSync, Azure VM Windows Server 2017, IIS 10, SQL Server 2017
IIS by default is configured to shutdown every 29 hours (to clear out memory and such and give the website a "fresh start"). You can change this configuration so it restarts less frequently.
You can change that setting by right clicking on the application pool in IIS, selecting "Recycling", then changing the setting on this screen:
Thanks Nicholas, this explains it! And it's probably a good thing to let IIS clean up regularly, I think we'll leave it as is. After all, it just means there will be a very short window of slow response on the site every 29 hrs. We can live with that.
I still don't understand the recompilation restarts, but it seems not to be a problem any longer, so I'll stop worrying about it for now. I will be keeping an eye on it though...
IIS Idle time out setting was causing the same error with the same error message by defaults it's set for 20 min. More info here: https://stackoverflow.com/questions/19985710/iis-idle-timeout-vs-recycle
is working on a reply...