Azure WebApp Custom Module Installation Doesn't Complete - Dnn.PersonaBar.ExtensionsErrors

[tpperlman]

Description of bug

Not sure if anyone has come across this before on an Azure WebApp, but when we install one of our custom modules the installation never completes with the success message or creates the Host Alert with the install details.

We provisioned an exact replica of the production server in our local environment and the installs complete as expected with the proper confirmation and host alert.

There are errors from Log4Net (provided below), and the module's Temp folder under Install isn't deleting (which is probably a result of the issue). This has continued to occur across a couple of subsequent release builds.

This poses an uncomfortable situation in that we're not able to get any confirmation that the SQL scripts have completed and that all the files have been copied successfully. The only way we can kind of guess it has been updated is by the version that appears in Extensions, reviewing some of our code updates or even manually running the SQL update scripts.

The installerlog files only includes references like these on both the Azure WebApp and our local server following an install. No further details are provided:

06/09/2023 02:36:02 [INFO] DotNetNuke.Services.Installer.XmlMerge Start UpdateNode: keyAttribute=name
06/09/2023 02:38:40 [INFO] DotNetNuke.Services.Installer.XmlMerge Start UpdateNode: keyAttribute=name

Here are some of the log entries we see, which seem to relate to the deletion of either temp data or files in the custom module's folder under DesktopModules:

2023-06-09 02:36:14,361 [MYSERVERID][Thread:48][ERROR] Dnn.PersonaBar.Extensions.Services.ExtensionsController - SchwabenCode.QuickIO.PathNotFoundException: The system cannot find the file specified.
   at SchwabenCode.QuickIO.Internal.InternalQuickIOCommon.NativeExceptionMapping(String path, Int32 errorCode)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerationHandleInvalidFileHandle(String path, QuickIOEnumerateOptions enumerateOptions, Int32 win32Error)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.FindPaths(String uncDirectoryPath, String pattern, SearchOption searchOption, Nullable`1 filterType, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerateDirectoryPaths(String path, String pattern, SearchOption searchOption, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Services.Installer.Installer.Install()
   at Dnn.PersonaBar.Extensions.Components.InstallController.InstallPackage(PortalSettings portalSettings, UserInfo user, String legacySkin, String filePath, Stream stream, Boolean isPortalPackage)
   at Dnn.PersonaBar.Extensions.Services.ExtensionsController.InstallPackageFile(String filePath)
   at Dnn.PersonaBar.Extensions.Services.ExtensionsController.InstallAvailablePackage(DownloadPackageDto package)
2023-06-09 02:38:50,370 [MYSERVERID][Thread:180][ERROR] Dnn.PersonaBar.Extensions.Components.InstallController - SchwabenCode.QuickIO.PathNotFoundException: The system cannot find the file specified.
   at SchwabenCode.QuickIO.Internal.InternalQuickIOCommon.NativeExceptionMapping(String path, Int32 errorCode)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerationHandleInvalidFileHandle(String path, QuickIOEnumerateOptions enumerateOptions, Int32 win32Error)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.FindPaths(String uncDirectoryPath, String pattern, SearchOption searchOption, Nullable`1 filterType, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerateDirectoryPaths(String path, String pattern, SearchOption searchOption, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at Dnn.PersonaBar.Extensions.Components.InstallController.DeleteTempInstallFiles(Installer installer)
2023-06-09 02:38:50,448 [MYSERVERID][Thread:180][ERROR] Dnn.PersonaBar.Extensions.Services.ExtensionsController - SchwabenCode.QuickIO.PathNotFoundException: The system cannot find the file specified.
   at SchwabenCode.QuickIO.Internal.InternalQuickIOCommon.NativeExceptionMapping(String path, Int32 errorCode)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerationHandleInvalidFileHandle(String path, QuickIOEnumerateOptions enumerateOptions, Int32 win32Error)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.FindPaths(String uncDirectoryPath, String pattern, SearchOption searchOption, Nullable`1 filterType, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerateFilePaths(String path, String pattern, SearchOption searchOption, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
   at DotNetNuke.Services.Installer.Installer.Install()
   at Dnn.PersonaBar.Extensions.Components.InstallController.InstallPackage(PortalSettings portalSettings, UserInfo user, String legacySkin, String filePath, Stream stream, Boolean isPortalPackage)
   at Dnn.PersonaBar.Extensions.Services.ExtensionsController.InstallPackageFile(String filePath)
   at Dnn.PersonaBar.Extensions.Services.ExtensionsController.InstallAvailablePackage(DownloadPackageDto package)

This is deep in DNN's internals and being an Azure production environment we're not sure how to diagnose the issue any further.

We've verified that all the files (e.g. DLLs, license, ReleaseNotes) and SQL providers in the manifest are included in the install file, so we're not sure what the "The system cannot find the file specified" is referencing.

This is a list of the folders and files that remain in the temp folder under installs, which is leading me to believe that perhaps deleting the backup files may point to the source of the issue:

• \Backup
• \bin
• \Providers
• [MyAppsName].dnn
• LICENSE.TXT
• ReleaseNotes.txt
• Resources.zip

Thank you for any pointers!

Affected version

• 09.11.00

We don't believe it is related to the DNN version since we upgraded sometime around December 2022 and we've done a couple of installs of the same custom module afterwards.

[valadas]

This is kinda hard to diagnose without having that specific module and the starting situation which makes this issue not really actionable, for that reason, I'll move it to a discussion until something actionable can be establishes. When you install the module, in the DNN UI do you get any errors ?

[tpperlman]

Thank you, @valadas. Yes, it is hard to diagnose and just wish that there were some additional logging somewhere that could provide more detail. I've done installer build file comparisons between previous versions that did upgrade successfully and subsequent ones that haven't without any pointers.

It is a weird situation that just popped up back in April in some of our builds. We were hoping that someone had experienced this before in Azure WebApps (e.g. permissions issues, timeouts) as a cause since we can't replicate it in our dev environment with the exact same DB and files.

Perhaps it isn't ideal for the installer to completely fail without a response simply due to a file error and at least have a Host Alert with logging of any failures.

[tpperlman]

@valadas as far as errors in the UI, there aren't any.

I'll be upgrading the custom module tonight and will keep Dev Tools open and check the Console and Network tabs to see if anything pops up. I'll also install an upgrade of a separate module to see if the same issue occurs.

If there are any other logging/debugging methods you think may provide more visibility that would be welcomed. We have Log4Net set to Error, but will set it to Debug just in case it provides more info.

Thank you again, and have a great evening!

[mitchelsellers]

This one is interesting. I'm curious as I thought we switched in 9.11.0 to using .net internals for the zip processes.

Are you doing anything special with reads on files that are. Wing deployed. Any thing that may keep a read lock on a file?

[tpperlman]

@mitchelsellers This is a standard Christoc template module install, and we're not doing anything out of the ordinary (e.g. UpgradeModule routines). I'm going to provide some additional findings below.

[bdukes]

@mitchelsellers I'm not seeing anything about zip in the stack trace, are you mistaking QuickIO for zip?

[tpperlman]

We only get a few opportunities to update the production environment, but I took some extra time tonight to garner any additional info I could. We set the Log4Net to DEBUG and can see some additional log entries, but not much of significance. I'll get into that below.

We ran the updated custom module install, and the first run it returned the same errors as above. We ran it a second time as a repair install and it miraculously worked and the success message/Host Alert appeared as expected. We ran it a third time as a repair install and it failed like the first time.

When it failed, this is what we see in the UI (no confirmation) and in dev tools:

Similar to the Log4Net log, here's the full error response we see from dev tools:

Server Error in '/' Application.
The system cannot find the file specified.
Description: An unhandled exception occurred during the execution of the current web request. Please review the stack trace for more information about the error and where it originated in the code.

Exception Details: SchwabenCode.QuickIO.PathNotFoundException: The system cannot find the file specified.

Source Error:

An unhandled exception was generated during the execution of the current web request. Information regarding the origin and location of the exception can be identified using the exception stack trace below.

Stack Trace:

[PathNotFoundException: The system cannot find the file specified.]
   SchwabenCode.QuickIO.Internal.InternalQuickIOCommon.NativeExceptionMapping(String path, Int32 errorCode) +272
   SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerationHandleInvalidFileHandle(String path, QuickIOEnumerateOptions enumerateOptions, Int32 win32Error) +131
   SchwabenCode.QuickIO.Internal.InternalQuickIO.FindPaths(String uncDirectoryPath, String pattern, SearchOption searchOption, Nullable`1 filterType, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn) +254
   SchwabenCode.QuickIO.Internal.InternalQuickIO.EnumerateDirectoryPaths(String path, String pattern, SearchOption searchOption, QuickIOEnumerateOptions enumerateOptions, QuickIOPathType pathFormatReturn) +127
   DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot) +274
   DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot) +355
   DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot) +355
   DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot) +355
   DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot) +355
   DotNetNuke.Services.Installer.Installer.Install() +548
   Dnn.PersonaBar.Extensions.Components.InstallController.InstallPackage(PortalSettings portalSettings, UserInfo user, String legacySkin, String filePath, Stream stream, Boolean isPortalPackage) +408
   Dnn.PersonaBar.Extensions.Services.<>c__DisplayClass18_0.<InstallPackage>b__0(PortalSettings portalSettings, UserInfo userInfo, String filePath, Stream stream) +96
   Dnn.PersonaBar.Extensions.Services.<>c__DisplayClass42_1.<UploadFileAction>b__1(Object <p0>) +47
   System.Web.Util.SynchronizationHelper.SafeWrapCallback(Action action) +118

Version Information: Microsoft .NET Framework Version:4.0.30319; ASP.NET Version:4.8.4494.0 

With Log4Net set to DEBUG, we did get some addition info like this which is rather curious (e.g. there is no 01.01.00 file in the manifest or providers, but that's where this 1 of 3 errors is popping up):

2023-06-10 02:30:14,336 [RD408E2CCF11E4][Thread:187][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: D:\home\site\wwwroot\Install\Temp\1t4kvuwk\Providers\DataProviders\SqlDataProvider
2023-06-10 02:30:14,352 [RD408E2CCF11E4][Thread:164][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: D:\home\site\wwwroot\Install\Temp\1t4kvuwk\Providers\DataProviders\SqlDataProvider\01.00.99.SqlDataProvider
2023-06-10 02:30:14,352 [RD408E2CCF11E4][Thread:214][INFO] DotNetNuke.Common.Utilities.FileSystemUtils - D:\home\site\wwwroot\Install\Temp\1t4kvuwk\Providers\DataProviders\SqlDataProvider does not exist.
2023-06-10 02:30:14,368 [RD408E2CCF11E4][Thread:164][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: D:\home\site\wwwroot\Install\Temp\1t4kvuwk\Providers\DataProviders\SqlDataProvider
2023-06-10 02:30:14,368 [RD408E2CCF11E4][Thread:214][ERROR] DotNetNuke.Common.Utilities.FileSystemUtils - SchwabenCode.QuickIO.PathNotFoundException: The system cannot find the file specified.
   at SchwabenCode.QuickIO.Internal.InternalQuickIOCommon.NativeExceptionMapping(String path, Int32 errorCode)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.GetFindDataFromPath(QuickIOPathInfo pathInfo)
   at SchwabenCode.QuickIO.QuickIOPathInfo.get_FindData()
   at SchwabenCode.QuickIO.QuickIOPathInfo.get_Attributes()
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.RemoveAttribute(QuickIOPathInfo pathInfo, FileAttributes attribute)
   at SchwabenCode.QuickIO.Internal.InternalQuickIO.DeleteFile(QuickIOPathInfo pathInfo)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFile(String fileName)
   at DotNetNuke.Common.Utilities.FileSystemUtils.DeleteFolderRecursive(String strRoot)
2023-06-10 02:30:14,383 [RD408E2CCF11E4][Thread:164][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: D:\home\site\wwwroot\Install\Temp\1t4kvuwk\Providers\DataProviders\SqlDataProvider\01.01.01.SqlDataProvider
2023-06-10 02:30:14,399 [RD408E2CCF11E4][Thread:164][INFO] DotNetNuke.Web.Common.Internal.DotNetNukeShutdownOverload - Watcher Activity: Changed. Path: D:\home\site\wwwroot\Install\Temp\1t4kvuwk\Providers\DataProviders\SqlDataProvider

We wouldn't think that the same module install would have different results, but somehow it is. I recall reading somewhere in a different thread that possibly the number of files may have something to do with it.

The release install is about 6MB, with:

• 24 DLLs of about 16MB
• 187 SQL Data Provider Files of about 5MB
• 236 files in Resources.zip of about 2.5MB

I recall reading somewhere a couple months back when this first occurred (but can't find it now) where someone reported that if a module had too many files or too many files of a particular type, that installs could fail. If they broke them up into separate installs then it would work. Perhaps this has something to do with the Azure environment, resources, memory, etc. but we've been able to reliably run the module install on our replicated local environment and each time we test on the VPS we use for testing where this issue has never arisen.