U4-9775 - AlreadyClosedException is thrown when retrieving media if the app domain is currently in a shutdown state and the site is under heavy load

Created by Shannon Deminick 18 Apr 2017, 02:31:19 Updated by Shannon Deminick 02 May 2017, 03:40:40

Subtask of: U4-9609

The media cache is Lucene and when the app domain is being shutdown/restart,all index readers need to be closed. In this case if the site is under heavy load than in some cases retrieving media from Lucene may end in an AlreadyClosedException exception.

When this occurs, our only option would be to try to load the media from the database.

As an example, here's a log entry for when an app domain is restarting and the old app domain (the one that is shutting down) is still trying to query media. The domain: D68 is the one starting and the D67 is the one shutting down.

 2017-04-11 11:49:10,232 [P3460/D68/T9] INFO  Umbraco.Core.CoreBootManager - Umbraco 7.5.13 application starting on PRUMWEMEDWKR005
 2017-04-11 11:49:10,292 [P3460/D68/T9] INFO  Umbraco.Core.PluginManager - Determining hash of code files on disk
 2017-04-11 11:49:10,662 [P3460/D68/T9] INFO  Umbraco.Core.PluginManager - Hash determined (took 368ms)
 2017-04-11 11:49:10,052 [P3460/D67/T175] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Waiting for tasks to complete
 2017-04-11 11:49:10,052 [P3460/D67/T175] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Terminating
 2017-04-11 11:49:10,052 [P3460/D67/T175] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Waiting for tasks to complete
 2017-04-11 11:49:10,057 [P3460/D67/T48] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [LogScrubber] Tasks completed, terminated
 2017-04-11 11:49:10,062 [P3460/D67/T175] INFO  Umbraco.Core.MainDom - Stopping...
 2017-04-11 11:49:10,062 [P3460/D67/T13] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledTasks] Tasks completed, terminated
 2017-04-11 11:49:12,807 [P3460/D68/T9] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
 2017-04-11 11:49:10,297 [P3460/D67/T175] INFO  Umbraco.Core.MainDom - Released MainDom.
 2017-04-11 11:49:10,652 [P3460/D67/T175] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Waiting for tasks to complete
 2017-04-11 11:49:13,927 [P3460/D68/T9] INFO  Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
 2017-04-11 11:49:13,952 [P3460/D68/T9] INFO  Umbraco.Forms.Core.Cache.CacheEventHandler - Initializing Umbraco Forms Events to trigger Cache Refreshers
 2017-04-11 11:49:10,652 [P3460/D67/T175] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Terminating
 2017-04-11 11:49:10,652 [P3460/D67/T175] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Waiting for tasks to complete
 2017-04-11 11:49:10,652 [P3460/D67/T206] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [ScheduledPublishing] Tasks completed, terminated
 2017-04-11 11:49:10,672 [P3460/D67/T71] INFO  Umbraco.Web.Scheduling.BackgroundTaskRunner - [KeepAlive] Tasks completed, terminated
 2017-04-11 11:49:15,422 [P3460/D69/T153] INFO  Umbraco.Core.DatabaseContext - CanConnect = True
 2017-04-11 11:49:16,342 [P3460/D69/T153] INFO  Umbraco.Core.PluginManager - Starting resolution types of Pegasus.Modules.PegasusModuleAttribute
 2017-04-11 11:49:16,342 [P3460/D69/T153] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Pegasus.Modules.PegasusModuleAttribute, found 0 (took 1ms)
 2017-04-11 11:49:16,442 [P3460/D69/T153] INFO  Umbraco.Web.Cache.CacheRefresherEventHandler - Initializing Umbraco internal event handlers for cache refreshing
 2017-04-11 11:49:16,457 [P3460/D69/T153] INFO  Umbraco.Forms.Core.Cache.CacheEventHandler - Initializing Umbraco Forms Events to trigger Cache Refreshers
 2017-04-11 11:49:18,672 [P3460/D69/T153] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
 2017-04-11 11:49:18,677 [P3460/D69/T153] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 1ms)
 2017-04-11 11:49:19,941 [P3460/D68/T9] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.Persistence.Mappers.BaseMapper
 2017-04-11 11:49:19,946 [P3460/D68/T9] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.Persistence.Mappers.BaseMapper, found 0 (took 2ms)
 2017-04-11 11:49:20,581 [P3460/D69/T153] INFO  Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
 2017-04-11 11:49:20,581 [P3460/D69/T153] INFO  Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 3
 2017-04-11 11:49:21,226 [P3460/D68/T9] INFO  Umbraco.Web.Search.ExamineEvents - Initializing Examine and binding to business logic events
 2017-04-11 11:49:21,226 [P3460/D68/T9] INFO  Umbraco.Web.Search.ExamineEvents - Adding examine event handlers for index providers: 3
 2017-04-11 11:49:21,601 [P3460/D69/T153] INFO  Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 8664ms)
 2017-04-11 11:49:21,991 [P3460/D68/T9] INFO  Umbraco.Core.CoreBootManager - Umbraco application startup complete (took 11873ms)
 2017-04-11 11:49:26,060 [P3460/D69/T197] INFO  umbraco.content - Load Xml from file...
 2017-04-11 11:49:28,329 [P3460/D68/T184] INFO  umbraco.content - Loading content from database...
 2017-04-11 11:49:28,929 [P3460/D69/T197] INFO  umbraco.content - Loaded Xml from file.
 2017-04-11 11:49:28,999 [P3460/D69/T197] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
 2017-04-11 11:49:29,004 [P3460/D69/T197] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 6ms)
 2017-04-11 11:49:30,038 [P3460/D68/T44] INFO  Umbraco.Core.PluginManager - Starting resolution types of Umbraco.Core.PropertyEditors.IParameterEditor
 2017-04-11 11:49:30,043 [P3460/D68/T44] INFO  Umbraco.Core.PluginManager - Completed resolution of types of Umbraco.Core.PropertyEditors.IParameterEditor, found 0 (took 2ms)
 2017-04-11 11:49:30,113 [P3460/D68/T184] INFO  Umbraco.Core.PluginManager - Starting resolution types of umbraco.interfaces.ICacheRefresher
 2017-04-11 11:49:30,228 [P3460/D68/T184] INFO  Umbraco.Core.PluginManager - Completed resolution of types of umbraco.interfaces.ICacheRefresher, found 0 (took 117ms)
 2017-04-11 11:49:30,343 [P3460/D68/T184] INFO  umbraco.content - Loading content from database...
 2017-04-11 11:49:36,290 [P3460/D69/T173] WARN  RJP.MultiUrlPicker.Models.MultiUrls - MultiUrlPicker value converter skipped a link as the node has been upublished/deleted (Id: 2848), 
 2017-04-11 11:49:45,107 [P3460/D67/T68] ERROR Umbraco.Core.UmbracoApplicationBase - An unhandled exception occurred
Lucene.Net.Store.AlreadyClosedException: this IndexReader is closed
   at Umbraco.Core.Cache.HttpRuntimeCacheProvider.GetCacheItem(String cacheKey, Func`1 getCacheItem, Nullable`1 timeout, Boolean isSliding, CacheItemPriority priority, CacheItemRemovedCallback removedCallback, CacheDependency dependency)
   at Umbraco.Core.Cache.HttpRuntimeCacheProvider.GetCacheItem(String cacheKey, Func`1 getCacheItem, Nullable`1 timeout, Boolean isSliding, CacheItemPriority priority, CacheItemRemovedCallback removedCallback, String[] dependentFiles)
   at Umbraco.Core.Cache.DeepCloneRuntimeCacheProvider.GetCacheItem(String cacheKey, Func`1 getCacheItem, Nullable`1 timeout, Boolean isSliding, CacheItemPriority priority, CacheItemRemovedCallback removedCallback, String[] dependentFiles)
   at Umbraco.Web.PublishedCache.XmlPublishedCache.PublishedMediaCache.GetCacheValues(Int32 id, Func`2 func)
   at Umbraco.Web.PublishedCache.XmlPublishedCache.PublishedMediaCache.GetUmbracoMedia(Int32 id)
   at Umbraco.Web.PublishedCache.XmlPublishedCache.PublishedMediaCache.GetById(UmbracoContext umbracoContext, Boolean preview, Int32 nodeId)
   at Umbraco.Web.PublishedCache.ContextualPublishedCache`1.GetById(Boolean preview, Int32 contentId)
   at Our.Umbraco.PropertyConverters.MultipleMediaPickerPropertyConverter.ConvertSourceToObject(PublishedPropertyType propertyType, Object source, Boolean preview)
   at Our.Umbraco.NestedContent.Models.DetachedPublishedProperty.<.ctor>b__1()
   at System.Lazy`1.CreateValue()
   at System.Lazy`1.LazyInitValue()
   at System.Lazy`1.get_Value()
   at Our.Umbraco.NestedContent.Models.DetachedPublishedProperty.get_Value()
   at Our.Umbraco.Ditto.UmbracoPropertyAttribute.GetUmbracoPropertyValue(IPublishedContent content, String umbracoPropertyName, Boolean recursive)
   at Our.Umbraco.Ditto.UmbracoPropertyAttribute.GetPropertyValue(IPublishedContent content, String umbracoPropertyName, Boolean recursive)
   at Our.Umbraco.Ditto.UmbracoPropertyAttribute.ProcessValue()
   at Our.Umbraco.Ditto.DittoCacheableAttribute.GetCacheItem[TOuputType](DittoCacheContext cacheContext, Func`1 refresher)
   at Our.Umbraco.Ditto.DittoProcessorAttribute.ProcessValue(Object value, DittoProcessorContext context)
   at Our.Umbraco.Ditto.PublishedContentExtensions.DoGetProcessedValue(IPublishedContent content, CultureInfo culture, Type targetType, PropertyInfo propertyInfo, PropertyDescriptor propertyDescriptor, Type defaultProcessorType, IEnumerable`1 processorContexts)
   at Our.Umbraco.Ditto.PublishedContentExtensions.GetProcessedValue(IPublishedContent content, CultureInfo culture, Type targetType, PropertyInfo propertyInfo, Object instance, Type defaultProcessorType, IEnumerable`1 processorContexts)
   at Our.Umbraco.Ditto.PublishedContentExtensions.ConvertContent(IPublishedContent content, Type type, CultureInfo culture, Object instance, IEnumerable`1 processorContexts, Action`1 onConverting, Action`1 onConverted)
   at Our.Umbraco.Ditto.PublishedContentExtensions.As(IPublishedContent content, Type type, CultureInfo culture, Object instance, IEnumerable`1 processorContexts, Action`1 onConverting, Action`1 onConverted)
   at Our.Umbraco.Ditto.RecursiveDittoAttribute.ProcessValue()
   at Our.Umbraco.Ditto.DittoCacheableAttribute.GetCacheItem[TOuputType](DittoCacheContext cacheContext, Func`1 refresher)
   at Our.Umbraco.Ditto.DittoProcessorAttribute.ProcessValue(Object value, DittoProcessorContext context)
   at Our.Umbraco.Ditto.PublishedContentExtensions.DoGetProcessedValue(IPublishedContent content, CultureInfo culture, Type targetType, PropertyInfo propertyInfo, PropertyDescriptor propertyDescriptor, Type defaultProcessorType, IEnumerable`1 processorContexts)
   at Our.Umbraco.Ditto.PublishedContentExtensions.GetProcessedValue(IPublishedContent content, CultureInfo culture, Type targetType, PropertyInfo propertyInfo, Object instance, Type defaultProcessorType, IEnumerable`1 processorContexts)
   at Our.Umbraco.Ditto.PublishedContentExtensions.ConvertContent(IPublishedContent content, Type type, CultureInfo culture, Object instance, IEnumerable`1 processorContexts, Action`1 onConverting, Action`1 onConverted)
   at Our.Umbraco.Ditto.PublishedContentExtensions.As(IPublishedContent content, Type type, CultureInfo culture, Object instance, IEnumerable`1 processorContexts, Action`1 onConverting, Action`1 onConverted)
   at Our.Umbraco.Ditto.PublishedContentExtensions.As[T](IPublishedContent content, CultureInfo culture, T instance, IEnumerable`1 processorContexts, Action`1 onConverting, Action`1 onConverted)
   at Our.Umbraco.Ditto.DittoViewModel`1.get_View()
   at Test.cshtml:line 2
   at System.Web.WebPages.WebPageBase.ExecutePageHierarchy()
   at System.Web.Mvc.WebViewPage.ExecutePageHierarchy()
   at System.Web.WebPages.WebPageBase.ExecutePageHierarchy(WebPageContext pageContext, TextWriter writer, WebPageRenderingBase startPage)
   at System.Web.Mvc.RazorView.RenderView(ViewContext viewContext, TextWriter writer, Object instance)
   at System.Web.Mvc.BuildManagerCompiledView.Render(ViewContext viewContext, TextWriter writer)
   at Umbraco.Core.Profiling.ProfilingView.Render(ViewContext viewContext, TextWriter writer)
   at System.Web.Mvc.HtmlHelper.RenderPartialInternal(String partialViewName, ViewDataDictionary viewData, Object model, TextWriter writer, ViewEngineCollection viewEngineCollection)
   at System.Web.Mvc.Html.PartialExtensions.Partial(HtmlHelper htmlHelper, String partialViewName, Object model, ViewDataDictionary viewData)
   at System.Web.Mvc.Html.PartialExtensions.Partial(HtmlHelper htmlHelper, String partialViewName)
   at ASP._Page_Views_Custom_MainLayout_cshtml.Execute() in c:\inetpub\temp\DWASFiles\sites\1b00a7f2-f25e-4ac1-8ab7-fafbc5311928\VirtualDirectory0\site\wwwroot\Views\Custom\MainLayout.cshtml:line 81
   at System.Web.WebPages.WebPageBase.ExecutePageHierarchy()
   at System.Web.Mvc.WebViewPage.ExecutePageHierarchy()
   at System.Web.WebPages.WebPageBase.ExecutePageHierarchy(WebPageContext pageContext, TextWriter writer, WebPageRenderingBase startPage)
   at System.Web.WebPages.WebPageBase.<>c__DisplayClass3.<RenderPageCore>b__2(TextWriter writer)
   at System.Web.WebPages.HelperResult.WriteTo(TextWriter writer)
   at System.Web.WebPages.WebPageBase.Write(HelperResult result)
   at System.Web.WebPages.WebPageBase.RenderSurrounding(String partialViewName, Action`1 body)
   at System.Web.WebPages.WebPageBase.PopContext()
   at System.Web.WebPages.WebPageBase.ExecutePageHierarchy(WebPageContext pageContext, TextWriter writer, WebPageRenderingBase startPage)
   at System.Web.Mvc.RazorView.RenderView(ViewContext viewContext, TextWriter writer, Object instance)
   at System.Web.Mvc.BuildManagerCompiledView.Render(ViewContext viewContext, TextWriter writer)
   at Umbraco.Core.Profiling.ProfilingView.Render(ViewContext viewContext, TextWriter writer)
   at System.Web.Mvc.ViewResultBase.ExecuteResult(ControllerContext context)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResult(ControllerContext controllerContext, ActionResult actionResult)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultFilterRecursive(IList`1 filters, Int32 filterIndex, ResultExecutingContext preContext, ControllerContext controllerContext, ActionResult actionResult)
   at System.Web.Mvc.ControllerActionInvoker.InvokeActionResultWithFilters(ControllerContext controllerContext, IList`1 filters, ActionResult actionResult)
   at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass21.<>c__DisplayClass2b.<BeginInvokeAction>b__1c()
   at System.Web.Mvc.Async.AsyncControllerActionInvoker.<>c__DisplayClass21.<BeginInvokeAction>b__1e(IAsyncResult asyncResult)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResult`1.CallEndDelegate(IAsyncResult asyncResult)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.End()
   at System.Web.Mvc.Async.AsyncControllerActionInvoker.EndInvokeAction(IAsyncResult asyncResult)
   at System.Web.Mvc.Controller.<BeginExecuteCore>b__1d(IAsyncResult asyncResult, ExecuteCoreState innerState)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.End()
   at System.Web.Mvc.Controller.EndExecuteCore(IAsyncResult asyncResult)
   at System.Web.Mvc.Controller.<BeginExecute>b__15(IAsyncResult asyncResult, Controller controller)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.End()
   at System.Web.Mvc.Controller.EndExecute(IAsyncResult asyncResult)
   at System.Web.Mvc.Controller.System.Web.Mvc.Async.IAsyncController.EndExecute(IAsyncResult asyncResult)
   at System.Web.Mvc.MvcHandler.<BeginProcessRequest>b__5(IAsyncResult asyncResult, ProcessRequestState innerState)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncVoid`1.CallEndDelegate(IAsyncResult asyncResult)
   at System.Web.Mvc.Async.AsyncResultWrapper.WrappedAsyncResultBase`1.End()
   at System.Web.Mvc.MvcHandler.EndProcessRequest(IAsyncResult asyncResult)
   at System.Web.Mvc.MvcHandler.System.Web.IHttpAsyncHandler.EndProcessRequest(IAsyncResult result)
   at System.Web.HttpApplication.CallHandlerExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
   at System.Web.HttpApplication.ExecuteStep(IExecutionStep step, Boolean& completedSynchronously)


Comments

Shannon Deminick 18 Apr 2017, 02:35:29

PR for review: https://github.com/umbraco/Umbraco-CMS/pull/1887


Priority: Normal

Type: Bug

State: Fixed

Assignee:

Difficulty: Normal

Category:

Backwards Compatible: True

Fix Submitted:

Affected versions:

Due in version: 7.6.0, 7.5.14

Sprint:

Story Points:

Cycle: 1