Bug Relating to Overlapping Application Pool Recycling in IIS and Nopcommerce 4.1 UsePluginShadowCopy

This post is to report bugs as described #1 here and #2 here relating to NopCommerce 4.1.  

This is a reproducible issue which occurs at random every 1740 minutes.  The quickest and easiest way to reproduce is to run a fresh copy of NopCommerce 4.1 and modify the IIS application pool advanced settings and reduce the "Regular Time Invertal (minutes)" setting to a shorter period of time.  

A 500 error will be thrown, with something similar to the following displayed when stout is enabled:

Application startup exception: System.Exception: Plugin 'Pickup in store'. Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied.
Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied.
 ---> System.Exception: Plugin 'Pickup in store'. Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied. ---> System.UnauthorizedAccessException: Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied.
   at System.IO.FileSystem.CopyFile(String sourceFullPath, String destFullPath, Boolean overwrite)
   at System.IO.File.Copy(String sourceFileName, String destFileName, Boolean overwrite)
   at Nop.Core.Infrastructure.NopFileProvider.FileCopy(String sourceFileName, String destFileName, Boolean overwrite) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Infrastructure\NopFileProvider.cs:line 192
   at Nop.Core.Plugins.PluginManager.ShadowCopyFile(String pluginFilePath, String shadowCopyPlugFolder) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 307
   at Nop.Core.Plugins.PluginManager.PerformFileDeploy(String plug, ApplicationPartManager applicationPartManager, NopConfig config, String shadowCopyPath) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 214
   at Nop.Core.Plugins.PluginManager.Initialize(ApplicationPartManager applicationPartManager, NopConfig config) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 479
   --- End of inner exception stack trace ---
   at Nop.Core.Plugins.PluginManager.Initialize(ApplicationPartManager applicationPartManager, NopConfig config) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 515
   --- End of inner exception stack trace ---
   at Nop.Core.Plugins.PluginManager.Initialize(ApplicationPartManager applicationPartManager, NopConfig config) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 526
   at Nop.Core.Infrastructure.NopEngine.Initialize(IServiceCollection services) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Infrastructure\NopEngine.cs:line 150
   at Nop.Web.Framework.Infrastructure.Extensions.ServiceCollectionExtensions.ConfigureApplicationServices(IServiceCollection services, IConfiguration configuration) in E:\nopCommerce\sources\src\Presentation\Nop.Web.Framework\Infrastructure\Extensions\ServiceCollectionExtensions.cs:line 56
   at Nop.Web.Startup.ConfigureServices(IServiceCollection services) in E:\nopCommerce\sources\src\Presentation\Nop.Web\Startup.cs:line 39
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Hosting.ConventionBasedStartup.ConfigureServices(IServiceCollection services)
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.EnsureApplicationServices()
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.Initialize()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.BuildApplication()
crit: Microsoft.AspNetCore.Hosting.Internal.WebHost[6]
      Application startup exception
System.Exception: Plugin 'Pickup in store'. Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied.
Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied.
 ---> System.Exception: Plugin 'Pickup in store'. Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied. ---> System.UnauthorizedAccessException: Access to the path 'D:\home\site\wwwroot\Plugins\bin\Nop.Plugin.Pickup.PickupInStore.dll' is denied.
   at System.IO.FileSystem.CopyFile(String sourceFullPath, String destFullPath, Boolean overwrite)
   at System.IO.File.Copy(String sourceFileName, String destFileName, Boolean overwrite)
   at Nop.Core.Infrastructure.NopFileProvider.FileCopy(String sourceFileName, String destFileName, Boolean overwrite) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Infrastructure\NopFileProvider.cs:line 192
   at Nop.Core.Plugins.PluginManager.ShadowCopyFile(String pluginFilePath, String shadowCopyPlugFolder) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 307
   at Nop.Core.Plugins.PluginManager.PerformFileDeploy(String plug, ApplicationPartManager applicationPartManager, NopConfig config, String shadowCopyPath) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 214
   at Nop.Core.Plugins.PluginManager.Initialize(ApplicationPartManager applicationPartManager, NopConfig config) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 479
   --- End of inner exception stack trace ---
   at Nop.Core.Plugins.PluginManager.Initialize(ApplicationPartManager applicationPartManager, NopConfig config) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 515
   --- End of inner exception stack trace ---
   at Nop.Core.Plugins.PluginManager.Initialize(ApplicationPartManager applicationPartManager, NopConfig config) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Plugins\PluginManager.cs:line 526
   at Nop.Core.Infrastructure.NopEngine.Initialize(IServiceCollection services) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Infrastructure\NopEngine.cs:line 150
   at Nop.Web.Framework.Infrastructure.Extensions.ServiceCollectionExtensions.ConfigureApplicationServices(IServiceCollection services, IConfiguration configuration) in E:\nopCommerce\sources\src\Presentation\Nop.Web.Framework\Infrastructure\Extensions\ServiceCollectionExtensions.cs:line 56
   at Nop.Web.Startup.ConfigureServices(IServiceCollection services) in E:\nopCommerce\sources\src\Presentation\Nop.Web\Startup.cs:line 39
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Hosting.ConventionBasedStartup.ConfigureServices(IServiceCollection services)
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.EnsureApplicationServices()
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.Initialize()
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Hosting.Internal.WebHost.BuildApplication()
Hosting environment: Production
Content root path: D:\home\site\wwwroot
Now listening on: http://127.0.0.1:8161
Application started. Press Ctrl+C to shut down.
crit: Microsoft.AspNetCore.Hosting.Internal.WebHost[11]
      Hosting startup assembly exception
System.InvalidOperationException: Startup assembly Microsoft.AspNetCore.AzureAppServices.HostingStartup failed to execute. See the inner exception for more details. ---> System.IO.FileNotFoundException: Could not load file or assembly 'Microsoft.AspNetCore.AzureAppServices.HostingStartup, Culture=neutral, PublicKeyToken=null'. The system cannot find the file specified.
   at System.Reflection.RuntimeAssembly.nLoad(AssemblyName fileName, String codeBase, RuntimeAssembly locationHint, StackCrawlMark& stackMark, IntPtr pPrivHostBinder, Boolean throwOnFileNotFound, IntPtr ptrLoadContextBinder)
   at System.Reflection.RuntimeAssembly.InternalLoadAssemblyName(AssemblyName assemblyRef, RuntimeAssembly reqAssembly, StackCrawlMark& stackMark, IntPtr pPrivHostBinder, Boolean throwOnFileNotFound, IntPtr ptrLoadContextBinder)
   at System.Reflection.Assembly.Load(AssemblyName assemblyRef)
   at Microsoft.AspNetCore.Hosting.WebHostBuilder.BuildCommonServices(AggregateException& hostingStartupErrors)
   --- End of inner exception stack trace ---

The expected behavior is that the overlapping application pool recycling will complete without error.  This error crashes the NopCommerce application and the only way to recover is to fully restart the application.  It appears that the NopCommerce application is caused to crash due to access being denied to a plugin DLL.  

There are two workarounds to this primary error contained in the Nopcommerce appsettings.json file.  The first is to modify "UsePluginsShadowCopy" from "True" to "False".  When modifying the flag to "False" and restarting the application to remedy the primary issue, the following secondary error is encountered in stout:

Microsoft.AspNetCore.Mvc.Razor.Compilation.CompilationFailedException: One or more compilation failures occurred:
4kk3veac.aa3(37,109): error CS0234: The type or namespace name 'Plugin' does not exist in the namespace 'Nop' (are you missing an assembly reference?)
4kk3veac.aa3(229,75): error CS0234: The type or namespace name 'Plugin' does not exist in the namespace 'Nop' (are you missing an assembly reference?)
   at Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler.CompileAndEmit(RazorCodeDocument codeDocument, String generatedCode)
   at Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler.CompileAndEmit(String relativePath)
   at Microsoft.AspNetCore.Mvc.Razor.Internal.RazorViewCompiler.OnCacheMiss(String normalizedPath)
--- End of stack trace from previous location where exception was thrown ---
   at Microsoft.AspNetCore.Mvc.Razor.Internal.DefaultRazorPageFactoryProvider.CreateFactory(String relativePath)
   at Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine.CreateCacheResult(HashSet`1 expirationTokens, String relativePath, Boolean isMainPage)
   at Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine.LocatePageFromPath(String executingFilePath, String pagePath, Boolean isMainPage)
   at Microsoft.AspNetCore.Mvc.Razor.RazorViewEngine.GetView(String executingFilePath, String viewPath, Boolean isMainPage)
   at Microsoft.AspNetCore.Mvc.ViewEngines.CompositeViewEngine.GetView(String executingFilePath, String viewPath, Boolean isMainPage)
   at Microsoft.AspNetCore.Mvc.ViewComponents.ViewViewComponentResult.ExecuteAsync(ViewComponentContext context)
   at Microsoft.AspNetCore.Mvc.ViewComponents.DefaultViewComponentInvoker.InvokeAsync(ViewComponentContext context)
   at StackExchange.Profiling.Internal.ProfilingViewComponentInvoker.InvokeAsync(ViewComponentContext context) in C:\projects\dotnet\src\MiniProfiler.AspNetCore.Mvc\Internal\ProfilingViewComponentInvoker.cs:line 30
   at Microsoft.AspNetCore.Mvc.ViewComponents.DefaultViewComponentHelper.InvokeCoreAsync(ViewComponentDescriptor descriptor, Object arguments)
   at AspNetCore.Views_Shared_Components_Widget_Default.ExecuteAsync() in D:\home\site\wwwroot\Views\Shared\Components\Widget\Default.cshtml:line 4
   at Microsoft.AspNetCore.Mvc.Razor.RazorView.RenderPageCoreAsync(IRazorPage page, ViewContext context)
   at Microsoft.AspNetCore.Mvc.Razor.RazorView.RenderPageAsync(IRazorPage page, ViewContext context, Boolean invokeViewStarts)
   at Microsoft.AspNetCore.Mvc.Razor.RazorView.RenderAsync(ViewContext context)
   at Microsoft.AspNetCore.Mvc.ViewComponents.ViewViewComponentResult.ExecuteAsync(ViewComponentContext context)
   at Microsoft.AspNetCore.Mvc.ViewComponents.DefaultViewComponentInvoker.InvokeAsync(ViewComponentContext context)
   at StackExchange.Profiling.Internal.ProfilingViewComponentInvoker.InvokeAsync(ViewComponentContext context) in C:\projects\dotnet\src\MiniProfiler.AspNetCore.Mvc\Internal\ProfilingViewComponentInvoker.cs:line 30
   at Microsoft.AspNetCore.Mvc.ViewComponents.DefaultViewComponentHelper.InvokeCoreAsync(ViewComponentDescriptor descriptor, Object arguments)
   at AspNetCore.Views_Home_Index.ExecuteAsync() in D:\home\site\wwwroot\Views\Home\Index.cshtml:line 9
   at Microsoft.AspNetCore.Mvc.Razor.RazorView.RenderPageCoreAsync(IRazorPage page, ViewContext context)
   at Microsoft.AspNetCore.Mvc.Razor.RazorView.RenderPageAsync(IRazorPage page, ViewContext context, Boolean invokeViewStarts)
   at Microsoft.AspNetCore.Mvc.Razor.RazorView.RenderAsync(ViewContext context)
   at Microsoft.AspNetCore.Mvc.ViewFeatures.ViewExecutor.ExecuteAsync(ViewContext viewContext, String contentType, Nullable`1 statusCode)
   at Microsoft.AspNetCore.Mvc.ViewFeatures.ViewExecutor.ExecuteAsync(ActionContext actionContext, IView view, ViewDataDictionary viewData, ITempDataDictionary tempData, String contentType, Nullable`1 statusCode)
   at Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor.ExecuteAsync(ActionContext context, ViewResult result)
   at Microsoft.AspNetCore.Mvc.ViewResult.ExecuteResultAsync(ActionContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeResultAsync(IActionResult result)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResultFilterAsync[TFilter,TFilterAsync]()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResultExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.ResultNext[TFilter,TFilterAsync](State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeResultFilters()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync()
   at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync()
   at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext)
   at StackExchange.Profiling.MiniProfilerMiddleware.Invoke(HttpContext context) in C:\projects\dotnet\src\MiniProfiler.AspNetCore\MiniProfilerMiddleware.cs:line 94
   at Nop.Services.Authentication.AuthenticationMiddleware.Invoke(HttpContext context) in E:\nopCommerce\sources\src\Libraries\Nop.Services\Authentication\AuthenticationMiddleware.cs:line 79
   at Microsoft.AspNetCore.Localization.RequestLocalizationMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Session.SessionMiddleware.Invoke(HttpContext context)
   at Nop.Core.Http.InstallUrlMiddleware.Invoke(HttpContext context, IWebHelper webHelper) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Http\InstallUrlMiddleware.cs:line 51
   at Nop.Core.Http.KeepAliveMiddleware.Invoke(HttpContext context, IWebHelper webHelper) in E:\nopCommerce\sources\src\Libraries\Nop.Core\Http\KeepAliveMiddleware.cs:line 50
   at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.StatusCodePagesMiddleware.Invoke(HttpContext context)
   at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.Invoke(HttpContext context)

The expected behavior is that upon setting the flag to "False", the application will run correctly and the primary error will be resolved.  Instead, the front end of the application breaks, though it is possible to access the admin panel of the application and appears to operate correctly.  

In alternative to the "UsePluginsShadowCopy" setting to resolve primary issue, there is another setting which may be manipulated: "CopyLockedPluginAssembilesToSubdirectoriesOnStartup".  When flagging this from the default "False" to "True" another secondary error is thrown as described here.  I do not have stout for this error as I haven't attempted to reproduce it, however, user @angeor has documented it in the link provided.  The expected behavior would be upon setting the flag from "False" to "True" that the application will run correctly and the primary error will be resolved.

We already fixed the problem with UsePluginsShadowCopy parameter, please see this commit for more details

What are recommended setting for that in appsetting.json file ?

    //Do not edit this element. For advanced users only
    "DisableSampleDataDuringInstallation": false,
    "UseFastInstallationService": false,
    "PluginsIgnoredDuringInstallation": "",

    //Indicates whether to ignore startup tasks
    "IgnoreStartupTasks": false,

    //Enable if you want to clear /Plugins/bin directory on application startup
    "ClearPluginShadowDirectoryOnStartup": true,
    //Enable if you want to copy "locked" assemblies from /Plugins/bin directory to temporary subdirectories on application startup
    "CopyLockedPluginAssembilesToSubdirectoriesOnStartup": false,
    //Enable if you want to copy plugins library to the /Plugins/bin directory on application startup
    "UsePluginsShadowCopy": true,
    //Enable if you want to load an assembly into the load-from context, by passing some security checks
    "UseUnsafeLoadAssembly": true,

    //Enable for backwards compatibility with SQL Server 2008 and SQL Server 2008R2
    "UseRowNumberForPaging": false,

    //Enable to store TempData in the session state
    "UseSessionStateTempDataProvider": false
  }
}

@Sergei-k, may I implement these changes in 4.1 without breaking the application?

One of my customer has the same bug too....

@Sergei-K, the "ApplicationPartManagerExtensions.cs" file you recommended and the "Extensions" folder it resides in doesn't exist in 4.1:

4.2:  src/Libraries/Nop.Core/Infrastructure/Extensions/ApplicationPartManagerExtensions.cs

4.1:  src/Libraries/Nop.Core/Infrastructure/   ???

What is the solution to this bug for 4.1?

Unfortunately, our development cycle does not include changes to the current version of the product. You can find a place in which to make the proposed changes in the PluginManager class

>alldogsoffroad
I'll try this solution for nop 4.10 and write you.

Backup old DLL and try this new one

http://foxnetsoft.com/content/files/Nop.Core.dll.zip

Write me about result.

Thanks @foxnetsoft!  Can you provide the code changes so we can integrate them into our repository and then we'll give it a test.