Copied to clipboard

Flag this post as spam?

This post will be reported to the moderators as potential spam to be looked at


  • Malith Jayawardana 6 posts 88 karma points
    Oct 04, 2016 @ 15:01
    Malith Jayawardana
    2

    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
    

    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!

  • Nicholas Westby 2054 posts 7100 karma points c-trib
    Oct 04, 2016 @ 15:22
    Nicholas Westby
    0

    You could try disabling models builder (web.config change):

    <add key="Umbraco.ModelsBuilder.Enable" value="false" />
    <add key="Umbraco.ModelsBuilder.ModelsMode" value="Nothing" />
    

    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.

  • Malith Jayawardana 6 posts 88 karma points
    Oct 04, 2016 @ 16:50
    Malith Jayawardana
    0

    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.

  • Nicholas Westby 2054 posts 7100 karma points c-trib
    Oct 05, 2016 @ 04:32
    Nicholas Westby
    1

    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.

  • Cimplex 113 posts 576 karma points
    Oct 06, 2016 @ 16:46
    Cimplex
    0

    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()
    
  • Mac McDell 73 posts 148 karma points
    Oct 07, 2016 @ 22:12
    Mac McDell
    0

    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
    
  • Mac McDell 73 posts 148 karma points
    Oct 08, 2016 @ 19:08
    Mac McDell
    0

    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

    <step title="Startup Request" date="2016-10-08T18:24:22.237" instance="PRUMWE" url="/api/commandstream/reconnect?transport=webSockets&amp;messageId=d-DE582F57-E%2C0%7CF%2C12%7CG%2C0&amp;clientProtocol=1.4&amp;shell=CMD&amp;connectionToken=YJYDEyzN1oZigFRGHIkity9Z4QU7%iuURf%2BCkslel3Eu%2B7cRWGL9EX0CzpWM8g%2FZ%2F6J&amp;tid=0" method="GET" type="request" pid="17636,2,7" SCM_SCRIPT_GENERATOR_ARGS="--basic" ScmType="LocalGit" >
        <step title="Cleanup Xml Logs" date="2016-10-08T18:24:22.237" />
        <!-- duration: 0ms -->
    </step>
    

    10 minutes later the w3wp process gets shutdown with the following

    <step title="Process Shutdown" date="2016-10-08T18:34:22.426" instance="PRUMWE" pid="17636,2,30" uptime="00:10:00.2672099" lastrequesttime="00:00:02.5001625" >
        <step title="Cleanup Xml Logs" date="2016-10-08T18:34:22.442" />
        <!-- duration: 16ms -->
    </step>
    <!-- duration: 31ms -->
    

    Note that it kills pid 17636, 2,30

    The next step instantly starts another w3wp process with a new pid.

  • Cimplex 113 posts 576 karma points
    Oct 08, 2016 @ 20:22
    Cimplex
    0

    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

  • Mac McDell 73 posts 148 karma points
    Oct 08, 2016 @ 21:19
    Mac McDell
    0

    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 .

  • Nicholas Westby 2054 posts 7100 karma points c-trib
    Oct 08, 2016 @ 23:14
    Nicholas Westby
    0

    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.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 10, 2016 @ 09:36
    Shannon Deminick
    0

    Nicholas,

    The "Terminating" log is normal, we write out that entry.

  • Mac McDell 73 posts 148 karma points
    Oct 09, 2016 @ 00:13
    Mac McDell
    0

    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.

  • Cimplex 113 posts 576 karma points
    Oct 09, 2016 @ 08:02
    Cimplex
    0

    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.

  • Mac McDell 73 posts 148 karma points
    Oct 09, 2016 @ 15:32
    Mac McDell
    0

    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

    `2016-10-09T15-23-24_PRUMWE_002_Shutdown_0s.xml
    <step title="Process Shutdown" date="2016-10-09T15:23:24.151" instance="PRUMWE" pid="22124,3,59" uptime="00:09:40.1265050" lastrequesttime="00:00:04.0450779" >
        <step title="Cleanup Xml Logs" date="2016-10-09T15:23:24.151" />
        <!-- duration: 0ms -->
    </step>
    <!-- duration: 16ms -->
    

    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.

  • Cimplex 113 posts 576 karma points
    Oct 09, 2016 @ 18:44
    Cimplex
    0

    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:

    2016-10-09T17-03-10_PRUMWE_002_Shutdown_0s.xml  2016-10-09 19:03:11 1 KB
    2016-10-09T17-03-46_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml   2016-10-09 19:03:46 1 KB
    2016-10-09T17-13-46_PRUMWE_002_Shutdown_0s.xml  2016-10-09 19:13:46 1 KB
    2016-10-09T17-14-23_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml   2016-10-09 19:14:23 1 KB
    2016-10-09T17-24-23_PRUMWE_002_Shutdown_0s.xml  2016-10-09 19:24:23 1 KB
    2016-10-09T17-24-58_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml   2016-10-09 19:24:59 1 KB
    

    Here is an example from the PRUMWE_001 log:

    <step title="Startup Request" date="2016-10-09T17:03:46.505" instance="PRUMWE" url="/api/commandstream/reconnect?transport=webSockets&messageId=xxxxxx&clientProtocol=1.4&shell=CMD&connectionToken=xxxx&tid=8" method="GET" type="request" pid="35412,2,13" SCM_SCRIPT_GENERATOR_ARGS="--basic" ScmType="LocalGit">
    <step title="Cleanup Xml Logs" date="2016-10-09T17:03:46.505"/>
    <!--  duration: 16ms  -->
    </step>
    <!--  duration: 31ms  -->
    

    And from PRUMWE_002:

    <step title="Process Shutdown" date="2016-10-09T17:03:10.790" instance="PRUMWE" pid="4060,2,19" uptime="00:10:02.7058702" lastrequesttime="00:00:07.0164280">
    <step title="Cleanup Xml Logs" date="2016-10-09T17:03:10.821"/>
    <!--  duration: 63ms  -->
    </step>
    <!--  duration: 109ms  -->
    

    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.

    2016-10-09T17-03-10_PRUMWE_002_Shutdown_0s.xml  2016-10-09 19:03:11 1 KB
    

    Mac, can you please send me your contacts to [email protected]?

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 10, 2016 @ 08:00
    Shannon Deminick
    0

    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.

  • Cimplex 113 posts 576 karma points
    Oct 10, 2016 @ 09:32
    Cimplex
    0

    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:

    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"

    Mine:

    <Examine>
      <ExamineIndexProviders>
        <providers>
          <add name="InternalIndexer" type="UmbracoExamine.UmbracoContentIndexer, UmbracoExamine" supportUnpublished="true" supportProtected="true" analyzer="Lucene.Net.Analysis.WhitespaceAnalyzer, Lucene.Net" useTempStorage="LocalOnly" />
          <add name="InternalMemberIndexer" type="UmbracoExamine.UmbracoMemberIndexer, UmbracoExamine" supportUnpublished="true" supportProtected="true" analyzer="Lucene.Net.Analysis.Standard.StandardAnalyzer, Lucene.Net" useTempStorage="LocalOnly" />
          <!-- default external indexer, which excludes protected and unpublished pages-->
          <add name="ExternalIndexer" type="UmbracoExamine.UmbracoContentIndexer, UmbracoExamine" useTempStorage="LocalOnly" />
        </providers>
      </ExamineIndexProviders>
      <ExamineSearchProviders defaultProvider="ExternalSearcher">
        <providers>
          <add name="InternalSearcher" type="UmbracoExamine.UmbracoExamineSearcher, UmbracoExamine" analyzer="Lucene.Net.Analysis.WhitespaceAnalyzer, Lucene.Net" useTempStorage="LocalOnly" />
          <add name="ExternalSearcher" type="UmbracoExamine.UmbracoExamineSearcher, UmbracoExamine" useTempStorage="LocalOnly" />
          <add name="InternalMemberSearcher" type="UmbracoExamine.UmbracoExamineSearcher, UmbracoExamine" analyzer="Lucene.Net.Analysis.Standard.StandardAnalyzer, Lucene.Net" enableLeadingWildcard="true" useTempStorage="LocalOnly" />
        </providers>
      </ExamineSearchProviders>
    </Examine>
    

    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

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 10, 2016 @ 09:34
    Shannon Deminick
    0

    Thanks, those settings all look fine for UaaS.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 10, 2016 @ 09:55
    Shannon Deminick
    0

    @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?

  • Cimplex 113 posts 576 karma points
    Oct 10, 2016 @ 10:24
    Cimplex
    0

    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

  • Mac McDell 73 posts 148 karma points
    Oct 10, 2016 @ 13:11
    Mac McDell
    0

    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.

  • Nicholas Westby 2054 posts 7100 karma points c-trib
    Oct 11, 2016 @ 03:53
    Nicholas Westby
    0

    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.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 11, 2016 @ 08:14
    Shannon Deminick
    0

    UaaS does not do any Scaling.

    With regards to these logs. What you are seeing is these:

     <step title="Startup Request" date="2016-10-08T18:24:22.237" instance="PRUMWE" url="/api/commandstream/reconnect?transport=webSockets&amp;messageId=d-DE582F57-E%2C0%7CF%2C12%7CG%2C0&amp;clientProtocol=1.4&amp;shell=CMD&amp;connectionToken=YJYDEyzN1oZigFRGHIkity9Z4QU7%iuURf%2BCkslel3Eu%2B7cRWGL9EX0CzpWM8g%2FZ%2F6J&amp;tid=0" method="GET" type="request" pid="17636,2,7" SCM_SCRIPT_GENERATOR_ARGS="--basic" ScmType="LocalGit" >
    

    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.

  • Cimplex 113 posts 576 karma points
    Oct 11, 2016 @ 08:25
    Cimplex
    0

    Hi, I just got this email from Mac, it might help

    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:

    Herman@Herman-Laptop MINGW32 ~/Desktop/Cimplex/Bitbucket/Axelent (master)
    $ git branch -a
    * master
      remotes/origin/HEAD -> origin/master
      remotes/origin/master
    

    // Herman

  • Mac McDell 73 posts 148 karma points
    Oct 11, 2016 @ 15:37
    Mac McDell
    0

    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
    

    ohhhhhh this sucks so much...

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 11, 2016 @ 15:47
    Shannon Deminick
    0

    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?

  • Mac McDell 73 posts 148 karma points
    Oct 11, 2016 @ 16:01
    Mac McDell
    0

    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) enter image description here

    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.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 12, 2016 @ 07:31
    Shannon Deminick
    0

    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.

  • Mac McDell 73 posts 148 karma points
    Oct 11, 2016 @ 16:31
    Mac McDell
    0

    This is the shutdown request:

    2016-10-11T15-37-16_PRUMWE_003_Shutdown_0s.xml
    <step title="Process Shutdown" date="2016-10-11T15:37:16.563" instance="PRUMWE" pid="13556,2,28" uptime="00:10:00.3254872" lastrequesttime="00:00:39.6312739" >
        <step title="Cleanup Xml Logs" date="2016-10-11T15:37:16.595" />
        <!-- duration: 0ms -->
    </step>
    <!-- duration: 47ms -->
    

    this is the startup

    2016-10-11T16-16-40_PRUMWE_001_Startup_GET__0s.xml
    <step title="Startup Request" date="2016-10-11T16:16:40.492" instance="PRUMWE" url="/" method="GET" type="request" pid="30768,3,26" SCM_SCRIPT_GENERATOR_ARGS="--basic" ScmType="LocalGit" >
        <step title="Cleanup Xml Logs" date="2016-10-11T16:16:40.492" />
        <!-- duration: 0ms -->
    </step>
    <!-- duration: 16ms -->
    

    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

    2016-10-11T16-16-40_PRUMWE_001_Startup_GET__0s.xml
    <step title="Startup Request" date="2016-10-11T16:16:40.492" instance="PRUMWE" url="/" method="GET" type="request" pid="30768,3,26" SCM_SCRIPT_GENERATOR_ARGS="--basic" ScmType="LocalGit" >
        <step title="Cleanup Xml Logs" date="2016-10-11T16:16:40.492" />
        <!-- duration: 0ms -->
    </step>
    <!-- duration: 16ms -->
    

    Rinse...Repeat..lather as necessary... (this is what killed the process again. )

     2016-10-11T16-20-07_PRUMWE_002_Shutdown_0s.xml 10/11/2016, 9:20:08 AM  1 KB
    
     2016-10-11T16-21-11_PRUMWE_001_Startup_GET_api-commandstream-reconnect_0s.xml  10/11/2016, 9:21:12 AM  1 KB
    

    The only 400s I see in the http raw logs are kudu connection issues:

    2016-10-11 16:21:22 ~103D2D935-1B6E-4B18-8652-221B944DD8BC GET /api/commandstream/reconnect transport=webSockets&messageId=d-33EAC879-E%2C0%7CF%2C14%7CG%2C0&clientProtocol=1.4&shell=CMD&connectionToken=E3pF1iMn%2Fo%2BHq1%2B7SCrNBsA%2FE62yBh0F3AG%2Bt2Ue8DNdcLbfjqxK5JI4E4FteXAebdP%2BLGfdaUQ9%2FumlN&tid=3&X-ARR-LOG-ID=8157111f-2d24-4db2-942b-79ec3538037a 80 - 250.92.98.119 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/53.0.2785.143+Safari/537.36 _ga=GA1.2.791594010.1475583862;+intercom-session-cipxe1hw=VWbjZ3QT09--935d5cb4a1560ee1a174f96f071d12a4e4d81aa0d2 - xxx.scm.s1.umbraco.io 400 0 0 341 1671 7681
    

    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.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 12, 2016 @ 07:28
    Shannon Deminick
    0

    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:

    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.

  • Mac McDell 73 posts 148 karma points
    Oct 12, 2016 @ 16:11
    Mac McDell
    0

    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.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 12, 2016 @ 17:07
    Shannon Deminick
    0

    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.

  • Mac McDell 73 posts 148 karma points
    Oct 12, 2016 @ 19:39
    Mac McDell
    0

    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) . Why is the git listener listening for any branch other than master??

    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. enter image description here

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 12, 2016 @ 20:07
    Shannon Deminick
    0

    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.

  • Mac McDell 73 posts 148 karma points
    Oct 12, 2016 @ 20:12
    Mac McDell
    0

    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.

  • Eric Schrepel 161 posts 226 karma points
    Oct 20, 2016 @ 23:13
    Eric Schrepel
    0

    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
    
  • Mac McDell 73 posts 148 karma points
    Oct 21, 2016 @ 02:58
    Mac McDell
    0

    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.

  • Phill 115 posts 288 karma points
    Oct 21, 2016 @ 03:34
    Phill
    0

    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

  • Mac McDell 73 posts 148 karma points
    Oct 23, 2016 @ 17:47
    Mac McDell
    0

    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.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Oct 21, 2016 @ 07:01
    Shannon Deminick
    1

    Hi All,

    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
  • Eric Schrepel 161 posts 226 karma points
    Oct 21, 2016 @ 18:14
    Eric Schrepel
    0

    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
    
  • philw 99 posts 434 karma points
    Oct 30, 2016 @ 10:25
    philw
    0

    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. ...

    useTempStorage="Sync"

    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

  • Mac McDell 73 posts 148 karma points
    Oct 30, 2016 @ 15:14
    Mac McDell
    0

    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.

  • Kris Janssen 210 posts 569 karma points c-trib
    Dec 03, 2016 @ 10:44
    Kris Janssen
    0

    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:

    _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.

  • Kris Janssen 210 posts 569 karma points c-trib
    Dec 03, 2016 @ 12:27
    Kris Janssen
    0

    FWIW, after the introducing the changes:

    <add key="Umbraco.ModelsBuilder.Enable" value="false" />
    <add key="Umbraco.ModelsBuilder.ModelsMode" value="Nothing" />
    

    Things seem to have improved for me and response seems OK now... bizarre.

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Dec 04, 2016 @ 04:56
    Shannon Deminick
    0

    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-shutd

    There is probably a Models Builder update too which I would suggest you should try https://www.nuget.org/packages/Umbraco.ModelsBuilder/

  • DonZalmrol 220 posts 833 karma points
    Mar 15, 2017 @ 16:56
    DonZalmrol
    0

    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

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Mar 15, 2017 @ 22:08
    Shannon Deminick
    1

    Try using 7.5.11 and see if the issue is resolved: http://issues.umbraco.org/issue/U4-9257

  • DonZalmrol 220 posts 833 karma points
    Mar 22, 2017 @ 08:14
    DonZalmrol
    0

    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.

             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
    
  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Mar 23, 2017 @ 01:09
    Shannon Deminick
    0

    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

  • DonZalmrol 220 posts 833 karma points
    Mar 23, 2017 @ 08:47
    DonZalmrol
    0

    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/

  • DonZalmrol 220 posts 833 karma points
    Mar 17, 2017 @ 07:19
    DonZalmrol
    0

    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.

    <add key="Umbraco.ModelsBuilder.Enable" value="false" />
    <add key="Umbraco.ModelsBuilder.ModelsMode" value="Nothing" />
    

    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
    
  • DonZalmrol 220 posts 833 karma points
    Mar 17, 2017 @ 08:14
    DonZalmrol
    0

    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#

  • Shannon Deminick 1524 posts 5269 karma points MVP 2x
    Mar 23, 2017 @ 01:10
    Shannon Deminick
    0

    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

  • DonZalmrol 220 posts 833 karma points
    Mar 23, 2017 @ 08:34
    DonZalmrol
    0

    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.

        _shutDownMessage=CONFIG change
    HostingEnvironment initiated shutdown
    CONFIG change
    CONFIG change
    CONFIG change
    HostingEnvironment caused shutdown
    
  • Bendik Engebretsen 105 posts 202 karma points
    May 10, 2018 @ 22:12
    Bendik Engebretsen
    0

    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

  • Nicholas Westby 2054 posts 7100 karma points c-trib
    May 10, 2018 @ 23:02
    Nicholas Westby
    2

    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:

    IIS Recycling Screen

  • Bendik Engebretsen 105 posts 202 karma points
    May 11, 2018 @ 08:42
    Bendik Engebretsen
    0

    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...

  • Michaela Ivanova 12 posts 104 karma points
    Oct 30, 2018 @ 09:18
    Michaela Ivanova
    0

    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

Please Sign in or register to post replies

Write your reply to:

Draft