ERROR Umbraco.Core.MainDom - Error while running callback, remaining callbacks will not run.
Hi All,
I have spent the last 24 hours trying to debug various issues appearing in a client's UmbracoTraceLog file and now seem to be down to the last issue (there were quite a few!)
I've not come across this issue and can't find anything using by Googling the issue, so I was hoping someone in the community might be able to help?
The full log below is a single clean start up of the application, you can see that after the above error message, the application terminates and restarts it's self.
This site is running Umbraco 7.4.3
Thanks in advance for any help you can give :)
Chris
2016-06-29 09:22:34,774 [1] INFO Umbraco.Core.CoreBootManager - Umbraco 7.4.3 application starting on UK867416
2016-06-29 09:22:34,937 [1] INFO Umbraco.Core.PluginManager - Determining hash of code files on disk
2016-06-29 09:22:34,972 [1] INFO Umbraco.Core.PluginManager - Hash determined (took 34ms)
2016-06-29 09:22:35,078 [1] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2016-06-29 09:22:35,108 [1] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 30ms)
2016-06-29 09:22:35,238 [1] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2016-06-29 09:22:35,239 [1] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 1ms)
2016-06-29 09:22:35,240 [1] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
2016-06-29 09:22:35,261 [1] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 20ms)
2016-06-29 09:22:35,300 [1] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2016-06-29 09:22:35,327 [1] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 27ms)
2016-06-29 09:22:35,330 [1] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
2016-06-29 09:22:35,350 [1] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 20ms)
2016-06-29 09:22:35,696 [1] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2016-06-29 09:22:35,700 [1] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 4ms)
2016-06-29 09:22:35,702 [1] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2016-06-29 09:22:35,705 [1] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 3ms)
2016-06-29 09:22:39,186 [1] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-06-29 09:22:40,448 [1] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-06-29 09:22:40,979 [1] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-06-29 09:22:41,047 [1] INFO Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
2016-06-29 09:22:41,057 [1] INFO Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
2016-06-29 09:22:41,209 [1] INFO Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 4
2016-06-29 09:22:41,265 [1] INFO Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 6789ms)
2016-06-29 09:22:50,108 [8] INFO Umbraco.Core.Sync.ApplicationUrlHelper - ApplicationUrl: http://localhost:53956/umbraco (UmbracoModule request)
2016-06-29 09:22:51,155 [8] INFO umbraco.content - Load Xml from file...
2016-06-29 09:22:51,312 [8] INFO umbraco.content - Loaded Xml from file.
2016-06-29 09:22:58,870 [8] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2016-06-29 09:22:58,874 [8] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 4ms)
2016-06-29 09:23:20,400 [9] ERROR Umbraco.Core.MainDom - Error while running callback, remaining callbacks will not run.
System.NullReferenceException: Object reference not set to an instance of an object.
at Umbraco.Web.Scheduling.BackgroundTaskRunner`1.Shutdown(Boolean force, Boolean wait)
at umbraco.content.<>c__DisplayClass2.<.ctor>b__1()
at Umbraco.Core.MainDom.OnSignal(String source)
2016-06-29 09:23:20,682 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating (immediate)
2016-06-29 09:23:20,682 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Cancelling tasks
2016-06-29 09:23:20,784 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Tasks cancelled, terminated
2016-06-29 09:23:20,785 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating (immediate)
2016-06-29 09:23:20,785 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Cancelling tasks
2016-06-29 09:23:20,888 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Tasks cancelled, terminated
2016-06-29 09:23:20,888 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Terminating (immediate)
2016-06-29 09:23:20,889 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Cancelling tasks
2016-06-29 09:23:20,996 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [Umbraco.Web.Scheduling.IBackgroundTask] Tasks cancelled, terminated
2016-06-29 09:23:20,996 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Terminating (immediate)
2016-06-29 09:23:20,996 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Cancelling tasks
2016-06-29 09:23:21,097 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Tasks cancelled, terminated
2016-06-29 09:23:21,097 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Terminating (immediate)
2016-06-29 09:23:21,097 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Cancelling tasks
2016-06-29 09:23:21,261 [9] INFO Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Tasks cancelled, terminated
2016-06-29 09:23:21,511 [17] INFO Umbraco.Core.UmbracoApplicationBase - Application shutdown. Details: BinDirChangeOrDirectoryRename
_shutDownMessage=Change Notification for critical directories.
bin dir change or directory rename
HostingEnvironment initiated shutdown
Change Notification for critical directories.
bin dir change or directory rename
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.HttpRuntime.ShutdownAppDomainWithStackTrace(ApplicationShutdownReason reason, String message, String stackTrace)
at System.Web.HttpRuntime.ShutdownAppDomain(ApplicationShutdownReason reason, String message)
at System.Web.HttpRuntime.OnCriticalDirectoryChange(Object sender, FileChangeEvent e)
at System.Web.FileChangesMonitor.OnCriticaldirChange(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()
2016-06-29 09:23:25,986 [18] INFO Umbraco.Core.CoreBootManager - Umbraco 7.4.3 application starting on UK867416
2016-06-29 09:23:26,041 [18] INFO Umbraco.Core.PluginManager - Determining hash of code files on disk
2016-06-29 09:23:26,062 [18] INFO Umbraco.Core.PluginManager - Hash determined (took 21ms)
2016-06-29 09:23:26,138 [18] INFO Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.IApplicationStartupHandler
2016-06-29 09:23:26,165 [18] INFO Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.IApplicationStartupHandler, found 0 (took 26ms)
2016-06-29 09:23:26,208 [18] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter
2016-06-29 09:23:26,210 [18] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyEditorValueConverter, found 0 (took 1ms)
2016-06-29 09:23:26,211 [18] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IPropertyValueConverter
2016-06-29 09:23:26,217 [18] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IPropertyValueConverter, found 0 (took 6ms)
2016-06-29 09:23:26,231 [18] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.Mvc.SurfaceController
2016-06-29 09:23:26,235 [18] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.Mvc.SurfaceController, found 0 (took 4ms)
2016-06-29 09:23:26,236 [18] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Web.WebApi.UmbracoApiController
2016-06-29 09:23:26,250 [18] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Web.WebApi.UmbracoApiController, found 0 (took 14ms)
2016-06-29 09:23:26,308 [18] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IThumbnailProvider
2016-06-29 09:23:26,309 [18] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IThumbnailProvider, found 0 (took 1ms)
2016-06-29 09:23:26,311 [18] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Media.IImageUrlProvider
2016-06-29 09:23:26,313 [18] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Media.IImageUrlProvider, found 0 (took 1ms)
2016-06-29 09:23:27,767 [18] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-06-29 09:23:28,310 [18] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-06-29 09:23:29,016 [18] INFO Umbraco.Core.DatabaseContext - CanConnect = True
2016-06-29 09:23:29,160 [18] INFO Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
2016-06-29 09:23:29,188 [18] INFO Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
2016-06-29 09:23:29,506 [18] INFO Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 4
2016-06-29 09:23:29,552 [18] INFO Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 4081ms)
2016-06-29 09:23:37,995 [15] INFO Umbraco.Core.Sync.ApplicationUrlHelper - ApplicationUrl: http://localhost:53956/umbraco (UmbracoModule request)
2016-06-29 09:23:38,271 [15] INFO umbraco.content - Load Xml from file...
2016-06-29 09:23:38,365 [15] INFO umbraco.content - Loaded Xml from file.
2016-06-29 09:23:48,746 [15] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
2016-06-29 09:23:48,751 [15] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 5ms)
2016-06-29 09:24:08,902 [15] INFO Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
2016-06-29 09:24:08,904 [15] INFO Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 1ms)
2016-06-29 09:24:10,125 [15] INFO Project.Web.Services.ActiveUserService - Logout - siteminderId.IsNullOrWhiteSpace
2016-06-29 09:24:10,125 [15] INFO Project.Web.Services.ActiveUserService - Logout - IsCookieValueNotNullAndValidGuid
2016-06-29 09:24:10,430 [15] INFO Project.Web.Services.ActiveUserService - Logout - gvoSMSessionIdCookie
2016-06-29 09:24:38,791 [8] INFO umbraco.BusinessLogic.Log - Log scrubbed. Removed all items older than 2016-06-28 09:24:38
The "MainDom" is a mechanism that we use to identify the "main domain" in case there are several app domains running for a single app. Although rare, this can happen, eg when the app domain is restarting. Some tasks (schedule publishing, managing the xml cache...) can be executed by only one single domain at a time.
When one app domain goes down, it needs to release the MainDom. So that the next app domain can acquire it. When releasing, we have some callbacks to run, to clean up the situation. For example, we want to make sure that all currently running tasks are stopped.
It seems that, in your case, a callback related to a background task runner is crashing. This is not what triggers the shutdown. It usually mean that the background task runner did not respond properly to the shutdown order.
This can happen and is hard to troubleshoot. If it happens once in a while, with no impact... it is best to simply ignore it. If it happens regularly, it probably means something's wrong.
Thank you for your reply, we seem to be having quite a few occurrences of the application shutting down and they all seem to occur in the logs just after the BackgroundTaskRunner tasks.
These are the different errors (obviously I've just cut each one out of the log file)
Application shutdown. Details: BuildManagerChange
Application shutdown. Details: BinDirChangeOrDirectoryRename
Application shutdown. Details: ConfigurationChange
Umbraco.Core.MainDom - Error while running callback, remaining callbacks will not run.
ERROR Umbraco.Core.MainDom - Error while running callback, remaining callbacks will not run.
Hi All,
I have spent the last 24 hours trying to debug various issues appearing in a client's UmbracoTraceLog file and now seem to be down to the last issue (there were quite a few!)
I've not come across this issue and can't find anything using by Googling the issue, so I was hoping someone in the community might be able to help?
The full log below is a single clean start up of the application, you can see that after the above error message, the application terminates and restarts it's self.
This site is running Umbraco 7.4.3
Thanks in advance for any help you can give :)
Chris
The "MainDom" is a mechanism that we use to identify the "main domain" in case there are several app domains running for a single app. Although rare, this can happen, eg when the app domain is restarting. Some tasks (schedule publishing, managing the xml cache...) can be executed by only one single domain at a time.
When one app domain goes down, it needs to release the MainDom. So that the next app domain can acquire it. When releasing, we have some callbacks to run, to clean up the situation. For example, we want to make sure that all currently running tasks are stopped.
It seems that, in your case, a callback related to a background task runner is crashing. This is not what triggers the shutdown. It usually mean that the background task runner did not respond properly to the shutdown order.
This can happen and is hard to troubleshoot. If it happens once in a while, with no impact... it is best to simply ignore it. If it happens regularly, it probably means something's wrong.
How often do you see this?
Hi Stephen,
Thank you for your reply, we seem to be having quite a few occurrences of the application shutting down and they all seem to occur in the logs just after the BackgroundTaskRunner tasks.
These are the different errors (obviously I've just cut each one out of the log file)
Cheers,
Chris
is working on a reply...