U4-9257 - HostingEnvironment shutdown on node publish - fcnMode issue

Created by Jbam4d 07 Dec 2016, 18:07:27 Updated by Shannon Deminick 07 Mar 2017, 17:55:00

Relates to: U4-9586

Hello,

When publishing multiple nodes within a short timeframe, our application restarts.

I had similar issues early in 2015 when I submitted this issue on StackOverflow: http://stackoverflow.com/questions/28933078/application-domain-restarts-on-node-publish-umbraco/

I resolved the issue by installing KB3052480 and had no further issues until I upgraded from 7.3.2 to 7.5.4. The server experiencing these issues still has KB3052480 installed.

fcnMode = single

Changing fncMode = Default has resolved the issue, but I'm still concerned with these issues popping up again.

We do have a large # of media nodes, 20K+.

2016-12-07 08:56:36,864 [P5140/D4/T6] WARN GeocodeHelper - 2016-12-07 08:56:36,864 [P5140/D4/T6] WARN GeocodeHelper - GeoLocateStores Running for State Code : AZ 2016-12-07 08:56:36,864 [P5140/D4/T6] WARN GeocodeHelper - 2016-12-07 08:56:44,426 [P5140/D4/T6] WARN GeocodeHelper - 2016-12-07 08:56:44,426 [P5140/D4/T6] WARN GeocodeHelper - GeoLocateStores Completed for State Code : AZ 2016-12-07 08:56:44,426 [P5140/D4/T6] WARN GeocodeHelper - 2016-12-07 08:56:44,426 [P5140/D4/T6] INFO Umbraco.Core.Publishing.PublishingStrategy - Content 'Map Stores - Arizona' with Id '31112' has been published. 2016-12-07 08:56:44,473 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: InternalIndexSet 2016-12-07 08:56:44,739 [P5140/D4/T6] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-07 08:56:44,817 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: InternalIndexSet 2016-12-07 08:56:44,817 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=StoreIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: StoreIndexSet 2016-12-07 08:56:44,817 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=ExternalIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: ExternalIndexSet 2016-12-07 08:56:44,817 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=AuthorsIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: AuthorsIndexSet 2016-12-07 08:56:44,817 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=ProductReviewsIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: ProductReviewsIndexSet 2016-12-07 08:56:44,817 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=BlogsIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: BlogsIndexSet 2016-12-07 08:56:44,817 [P5140/D4/T6] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=StrainProfilesIndexer, NodeId=-1 System.Exception: App is shutting down so index batch operation is ignored,, IndexSet: StrainProfilesIndexSet 2016-12-07 08:56:44,973 [P5140/D4/T17] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: ConfigurationChange

_shutDownMessage=CONFIG change HostingEnvironment initiated shutdown CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change CONFIG change CONFIG change Overwhelming Change Notification in CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_Code CONFIG change Change Notification for critical directories. Overwhelming Change Notification in bin CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_WebReferences CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_Browsers CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change CONFIG change CONFIG change CONFIG change Overwhelming Change Notification in D:\websites\production\http CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_GlobalResources CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change CONFIG change CONFIG change CONFIG change CONFIG change Change Notification for critical directories. Overwhelming Change Notification in App_LocalResources CONFIG change CONFIG change CONFIG change CONFIG change User code called UnloadAppDomain User code called UnloadAppDomain 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.Configuration.WebConfigurationHostFileChange.OnFileChanged(Object sender, FileChangeEvent e) at System.Web.DirectoryMonitor.FireNotifications() at System.Web.Util.WorkItem.CallCallbackWithAssert(WorkItemCallback callback) at System.Web.Util.WorkItem.OnQueueUserWorkItemCompletion(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()

1 Attachments

Comments

Jbam4d 24 Dec 2016, 18:09:24

Just an update:

While fcnMode="Default" resolved the 'Change Notification for critical directories. Overwhelming Change Notification in App_Code' errors. Publishing any nodes still does cause an application restart.

This issue did not exist in 7.3.4.

We upgraded to 7.5.4 and the issue starting appearing. No windows updates were applied during this time, so it is not related to a new MS patch. Same hosting environment. Only change was the Umbraco upgrade version to 7.5.4.

Sounds like others are having similar issues, and no solution has been found.

https://our.umbraco.org/forum/using-umbraco-and-getting-started/80488-recurring-application-shutdown-issue-on-umbraco-753

2016-12-23 15:24:35,319 [P3272/D4/T1] INFO Umbraco.Core.DatabaseContext - CanConnect = True 2016-12-23 15:24:35,757 [P3272/D3/T22] INFO umbraco.content - Loading content from database... 2016-12-23 15:24:35,350 [P3272/D4/T1] INFO Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing 2016-12-23 15:24:35,522 [P3272/D4/T1] INFO Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events 2016-12-23 15:24:35,522 [P3272/D4/T1] INFO Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 8 2016-12-23 15:24:36,710 [P3272/D4/T1] INFO umbraco.content - Load Xml from file... 2016-12-23 15:24:37,257 [P3272/D3/T22] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor 2016-12-23 15:24:37,272 [P3272/D3/T22] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 1ms) 2016-12-23 15:24:38,007 [P3272/D4/T1] INFO umbraco.content - Loaded Xml from file. 2016-12-23 15:24:38,960 [P3272/D4/T1] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor 2016-12-23 15:24:39,194 [P3272/D4/T1] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 221ms) 2016-12-23 15:24:39,632 [P3272/D3/T22] INFO Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 15848ms) 2016-12-23 15:24:40,538 [P3272/D4/T1] INFO Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 15148ms) 2016-12-23 15:24:40,897 [P3272/D4/T30] INFO Umbraco.Core.Sync.ApplicationUrlHelper - ApplicationUrl: http://dev.domain.com/umbraco (using scheduledTasks/@baseUrl) 2016-12-23 15:24:41,100 [P3272/D3/T25] INFO Umbraco.Core.Sync.ApplicationUrlHelper - ApplicationUrl: http://dev.domain.com/umbraco (using scheduledTasks/@baseUrl) 2016-12-23 15:24:48,491 [P3272/D3/T25] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.ICacheRefresher 2016-12-23 15:24:48,491 [P3272/D3/T25] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.ICacheRefresher, found 0 (took 0ms) 2016-12-23 15:24:48,975 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:49,162 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:49,287 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:49,553 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:49,662 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:49,787 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:49,975 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:50,631 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:50,725 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:50,834 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:50,975 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:51,772 [P3272/D3/T25] INFO umbraco.content - Loading content from database... 2016-12-23 15:24:52,475 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:52,584 [P3272/D3/T25] INFO umbraco.content - Loading content from database... 2016-12-23 15:24:54,647 [P3272/D3/T25] WARN Umbraco.Web.PublishedCache.XmlPublishedCache.XmlCacheFilePersister - Cannot write now because we are going down, changes may be lost. 2016-12-23 15:24:55,928 [P3272/D3/T33] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: InternalIndexSet 2016-12-23 15:24:55,928 [P3272/D3/T33] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=StoreIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: StoreIndexSet 2016-12-23 15:24:55,928 [P3272/D3/T33] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=ExternalIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: ExternalIndexSet 2016-12-23 15:24:55,928 [P3272/D3/T33] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=AuthorsIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: AuthorsIndexSet 2016-12-23 15:24:55,928 [P3272/D3/T33] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=ProductReviewsIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: ProductReviewsIndexSet 2016-12-23 15:24:55,928 [P3272/D3/T33] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=BlogsIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: BlogsIndexSet 2016-12-23 15:24:55,928 [P3272/D3/T33] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=StrainProfilesIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: StrainProfilesIndexSet 2016-12-23 15:25:10,552 [P3272/D4/T30] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper 2016-12-23 15:25:10,552 [P3272/D4/T30] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 1ms) 2016-12-23 15:25:12,162 [P3272/D4/T30] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Macros.XsltExtensionAttribute 2016-12-23 15:25:12,162 [P3272/D4/T30] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Macros.XsltExtensionAttribute, found 0 (took 0ms) 2016-12-23 15:25:12,209 [P3272/D4/T30] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.cms.businesslogic.macro.IMacroEngine 2016-12-23 15:25:12,209 [P3272/D4/T30] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.cms.businesslogic.macro.IMacroEngine, found 0 (took 0ms) 2016-12-23 15:25:22,021 [P3272/D3/T19] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=InternalIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: InternalIndexSet 2016-12-23 15:25:22,021 [P3272/D3/T19] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=StoreIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: StoreIndexSet 2016-12-23 15:25:22,021 [P3272/D3/T19] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=ExternalIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: ExternalIndexSet 2016-12-23 15:25:22,021 [P3272/D3/T19] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=AuthorsIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: AuthorsIndexSet 2016-12-23 15:25:22,021 [P3272/D3/T19] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=ProductReviewsIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: ProductReviewsIndexSet 2016-12-23 15:25:22,021 [P3272/D3/T19] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=BlogsIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: BlogsIndexSet 2016-12-23 15:25:22,021 [P3272/D3/T19] ERROR UmbracoExamine.DataServices.UmbracoLogService - Provider=StrainProfilesIndexer, NodeId=-1 System.Exception: Cannot index queue items, the index is currently locked,, IndexSet: StrainProfilesIndexSet 2016-12-23 15:25:22,021 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating 2016-12-23 15:25:22,021 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Waiting for tasks to complete 2016-12-23 15:25:22,021 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating 2016-12-23 15:25:22,021 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Waiting for tasks to complete 2016-12-23 15:25:22,036 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Terminating 2016-12-23 15:25:22,036 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Waiting for tasks to complete 2016-12-23 15:25:22,036 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Terminating 2016-12-23 15:25:22,036 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Waiting for tasks to complete 2016-12-23 15:25:22,036 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Terminating 2016-12-23 15:25:22,036 [P3272/D3/T19] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Waiting for tasks to complete 2016-12-23 15:25:22,036 [P3272/D3/T32] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Tasks completed, terminated 2016-12-23 15:25:22,036 [P3272/D3/T32] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Tasks completed, terminated 2016-12-23 15:25:22,036 [P3272/D3/T32] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Tasks completed, terminated 2016-12-23 15:25:22,036 [P3272/D3/T32] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Tasks completed, terminated 2016-12-23 15:25:22,036 [P3272/D3/T25] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Tasks completed, terminated 2016-12-23 15:25:45,239 [P3272/D4/T23] INFO umbraco.BusinessLogic.Log - Log scrubbed. Removed all items older than 2016-12-22 15:25:45 2016-12-23 15:25:52,145 [P3272/D3/T19] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: ConfigurationChange

_shutDownMessage=IIS configuration change 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() at System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr pHandler, RequestNotificationStatus& notificationStatus) at System.Web.Hosting.UnsafeIISMethods.MgdIndicateCompletion(IntPtr pHandler, RequestNotificationStatus& notificationStatus) at System.Web.Hosting.PipelineRuntime.ProcessRequestNotificationHelper(IntPtr rootedObjectsPointer, IntPtr nativeRequestContext, IntPtr moduleData, Int32 flags) at System.Web.Hosting.PipelineRuntime.ProcessRequestNotification(IntPtr rootedObjectsPointer, IntPtr nativeRequestContext, IntPtr moduleData, Int32 flags) 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Waiting for tasks to complete 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Tasks completed, terminated 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Terminating 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Waiting for tasks to complete 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Tasks completed, terminated 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Terminating 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Waiting for tasks to complete 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Tasks completed, terminated 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Waiting for tasks to complete 2016-12-23 15:25:55,832 [P3272/D2/T11] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Tasks completed, terminated 2016-12-23 15:26:25,862 [P3272/D2/T32] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: ConfigurationChange

_shutDownMessage=CONFIG change HostingEnvironment initiated shutdown Change in C:\Windows\Microsoft.NET\Framework64\v4.0.30319\Temporary ASP.NET Files\root\1cb48e58\f4bebe\hash\hash.web 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.HttpRuntime.OnConfigChange(String message) at System.Configuration.BaseConfigurationRecord.OnStreamChanged(String streamname) at System.Web.DirectoryMonitor.FireNotifications() at System.Web.Util.WorkItem.CallCallbackWithAssert(WorkItemCallback callback) 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()

We do have a large number of nodes. Setting fcnMode="Disabled" has resolved the application restarts on publish.


Shannon Deminick 28 Dec 2016, 03:22:02

Thanks for reporting the issue.

I'm not sure if you've seen my previous blog posts about FCN but I posted a new one a couple weeks ago: http://shazwazza.com/post/fcn-file-change-notification-viewer-for-aspnet/

You can install that package to see where all of the file watchers are listed in your site. I would recommend not activating this unless you are in debug mode since it can expose sensitive data to the public but it's a good way to see where the problem could be. You'll see some notes about Image Processor in there too and a new release has been made yesterday so I would strongly advise upgrading to that to see if that fixes you issue: https://twitter.com/James_M_South/status/813590757172883456

That said, if you have a solution that replicates this problem consistently that you could share that would be most ideal since to-date nobody has been able to share a solution with me that replicates the issue consistently. If you could, I would also need to replicate your server environment so would need to know those details too. Let me know if you can share, you can email me a link at shannon at umbraco dot com.


Dušan Janošík 30 Jan 2017, 10:54:27

I've just upgraded to 7.5.8 and started to see this issue. The AppDomain is restarting pretty often and there are also issues with umbraco.config file being locked ("Failed to enter the lock within timeout.").


Sebastiaan Janssen 30 Jan 2017, 11:01:17

@djanosik I think you need to read this issue: http://issues.umbraco.org/issue/U4-6626 Make sure that the appropriate updates are installed on your server, see this comment specifically: http://issues.umbraco.org/issue/U4-6626#comment=67-33893

Related to that is this issue with a lot of information at the top: http://issues.umbraco.org/issue/U4-6338


Dušan Janošík 30 Jan 2017, 11:33:27

The site is running on Windows Server 2012 (not R2). I don't have hotfixes KB3000850 or KB3007507 installed. It looks like the KB3052480 solves the issue, but it is not applicable in my case.


Sebastiaan Janssen 30 Jan 2017, 12:13:34

Alright, those links will give you plenty of reading material and things to try though. Let us know if you can find anything.

Here's some hints, they say "Azure" but apply to any hosted site really: https://cultiv.nl/blog/making-sure-your-umbraco-site-performs-on-azure/

Also, you might be doing some things that cause high load (CPU/memory), make sure to check out and act on these tips: https://our.umbraco.org/documentation/Reference/Common-Pitfalls/


Dušan Janošík 30 Jan 2017, 13:07:41

Thanks, I'll take a look.


Dušan Janošík 01 Feb 2017, 09:34:08

Nothing helped so far.

From time to time it starts refreshing examine indexes and umbraco.config file. And then it starts restarting. Also it happens often that examine indexes and / or umbraco.config does not contain all published contents. I will try to set fcnMode=Disabled to at least prevent restarts. Everything worked before I upgraded to 7.5.x.

What has changed? Should I try to upgrade to Win Server 2016?


Jbam4d 01 Feb 2017, 23:02:12

I just wanted to follow up on this ticket. We ended up setting fcnMode=Disabled while running 7.5.4 which prevented the application restarts.

We then upgraded to 7.5.6 and changed fcnMode=Default. This resolved all of our issues.


Shannon Deminick 02 Feb 2017, 01:44:36

Hi, There's been a few folks saying that after upgrading they have an issue, however in many of these cases the cause wasn't just upgrading, and in fact quite a lot had changed from the version and environment being upgraded from. Perhaps this isn't everyone's case but there's really nothing that Umbraco Core does regarding FCN, but I can tell you what does affect FCN:

  • The number of folders in your web root
  • The FCN mode set in your web.config
  • Bugs in some Windows releases
  • In some cases - how you are hosting your website, for example if you are using a network file system to host your website

I'll re-post these 2 articles which talk at length about what FCN means:

*http://shazwazza.com/post/all-about-aspnet-file-change-notification-fcn/ *http://shazwazza.com/post/fcn-file-change-notification-viewer-for-aspnet/

Having a network file share hosting your website can cause your file server to slow down your website when running FcnMode="NotSet" (which is the default) because of how many folder watchers are created, however with this mode the buffers won't get overrun and cause the problem you are seeing. So depending on where you are hosting your site you can set FcnMode="NotSet". Having FcnMode="Single" will have less folder watchers but it's easier for the buffer to overrun if you have a zillion folders in your website.

The main cause for too many folders in your website is the ImageProcessor cache files located at /app_data/cache which is why we've worked with the ImageProcessor team to be able to store these cache files outside of the webroot which means folder watches are not added by ASP.NET. Another reason could potentially be too many files in /media but currently there is no way to change this location.

Please read the above 2 articles, they contain all of this information and more.


Dušan Janošík 02 Feb 2017, 08:01:59

Ok, thank you! I will also try to set fcnMode=Default (or NotSet). We have already moved our media files outside of the Umbraco web site. There is nothing in /media folder and almost nothing in /app_data/cache. We have used FileSystemProviders.config to change the location. I guess folders like /Views containing tens of files won't be a problem.


Rasmus Fjord 03 Feb 2017, 12:27:12

Just to check in here, we have a large solution running on a large windows server 2012, and we were seeing this issue when we reindexed the index.

Testing right now to see if it has changed.

7.5.7


Shannon Deminick 06 Feb 2017, 03:08:05

@rasmusfjord@gmail.com Let me know how you go once you've tested that. What would be very interesting is if you do experience this problem when re-indexing then I'd need you to test to see if MS have a regression issue since re-indexing is just writing a lot of files which is essentially the original issue for KB3000850 or KB3007507. The original MS bug report I created for them with regards to KB3000850 is here: http://issues.umbraco.org/issue/U4-6338#comment=67-21171 It contains a link to a demo project that demonstrated the problem (found here: https://dl.dropboxusercontent.com/u/47577000/WebsiteRestarter.zip)


Shannon Deminick 17 Feb 2017, 00:34:17

@rasmusfjord@gmail.com any luck?


Rasmus Fjord 17 Feb 2017, 07:18:04

Hey @Shandem

The short answer yeah it helped, all problems solved.

Since the server was not an R2 i couldnt use the windows patch but when i flipped the switch on fcnMode and pushed the reindexing all was good, also on the solution we have log4net set to warn, but still it creates some decent log files. The server is just a VM on Azure.

So in short it fixed it.

What is it you want me to test? :)


Shannon Deminick 22 Feb 2017, 02:43:02

@rasmusfjord@gmail.com I would like to check if the version of your Windows Service (with whatever KBs are installed) has a MS regression issue, to do that I would like to know if you can cause an IIS site to restart just by writing a bunch of files to App_Data. That zip file I mentioned above is a website that does just this and reports back if a restart occurs. Would you be able to test that?


Rasmus Fjord 22 Feb 2017, 07:57:45

@Shandem sure thing, ill test it today.


Rasmus Fjord 22 Feb 2017, 13:25:19

@Shandem just did the test.

started with a 100, and the one crash happend here but it was because of missing folder permissions, then did 500 and 10k went fine.


Shannon Deminick 22 Feb 2017, 23:00:33

Thanks @rasmusfjord@gmail.com , much appreciated. I would suggest then that your site is affected by FCN issues when you say:

Just to check in here, we have a large solution running on a large windows server 2012, and we were seeing this issue when we reindexed the index

If this issue goes away with fcnMode="Disabled" and your server is not affected then I would suggest:

*Change fcnMode="NotSet" (which is the default) which will be fine so long as you are not hosting your site on a remote file share - then see if your site behaves normally. "Single" is more prone to buffer overflows which cause the site to restart but is the safer setting with regards to file system performance *If you still have issues with fcnMode not being disabled, you can try the FcnViewer to see where all of the watchers are coming from (most likely tons of ImageProcessor cache files), you can now store Image Processor cache files outside of the web root which means that they are not affected by fcn (less watchers = less buffers = less buffer overflows = less prone to fcn restarts)


Rasmus Fjord 23 Feb 2017, 08:05:22

Your welcome @Shandem !

It was tested on the liveserver, and the site on the server is running with fcnMode="Default" and that runs smooth as butter, never ran better actually.


Kevin Duong 07 Mar 2017, 16:07:04

@Shandem I just started getting these errors on 7.5.6, I've had fcnMode set to Single for about a week now. So it was fine for a week, then all of a sudden we got these errors. I'm on Azure, so I don't think it would be wise to set it to Default since we have a lot of folders under out cache directory. Any recommendations on what to do from here?


Shannon Deminick 07 Mar 2017, 17:53:51

Hi, this issue should be resolved in U4-9586 and 7.5.11 was released today (if this is the specific thing affecting your environment)


Priority: Major

Type: Bug

State: Fixed

Assignee:

Difficulty: Normal

Category:

Backwards Compatible: True

Fix Submitted:

Affected versions: 7.5.4, 7.5.7

Due in version: 7.5.11

Sprint:

Story Points:

Cycle: