Improve logging and error handling for IIS ASP.NET Core module shadow copy

src/Servers/IIS/AspNetCoreModuleV2/AspNetCore/applicationinfo.cpp

@@ -84,6 +84,8 @@ APPLICATION_INFO::CreateApplication(IHttpContext& pHttpContext)
         return S_OK;
     }
 
+    std::wstring pExceptionMessage;
+
     try
     {
         const WebConfigConfigurationSource configurationSource(m_pServer.GetAdminManager(), pHttpApplication);
@@ -138,29 +140,43 @@ APPLICATION_INFO::CreateApplication(IHttpContext& pHttpContext)
         }
         return S_OK;
     }
-    catch (const ConfigurationLoadException &ex)
-    {
-        EventLog::Error(
-            ASPNETCORE_CONFIGURATION_LOAD_ERROR,
-            ASPNETCORE_CONFIGURATION_LOAD_ERROR_MSG,
-            ex.get_message().c_str());
-    }
     catch (...)
     {
         OBSERVE_CAUGHT_EXCEPTION();
+        pExceptionMessage = CaughtExceptionToString();
         EventLog::Error(
             ASPNETCORE_CONFIGURATION_LOAD_ERROR,
             ASPNETCORE_CONFIGURATION_LOAD_ERROR_MSG,
-            L"");
+            pExceptionMessage.c_str());
     }
 
+    ErrorContext errorContext;
+    errorContext.statusCode = 500i16;
+    errorContext.subStatusCode = 30i16;
+    errorContext.generalErrorType = "ASP.NET Core app failed to start - An exception was thrown during startup";
+    if (GetLastError() == ERROR_ACCESS_DENIED)
+    {
+        errorContext.errorReason = "Ensure the application pool process model has write permissions to the shadow copy directory";
+    }
+    // TODO: Depend on show detailed errors or nah?
+    errorContext.detailedErrorContent = to_multi_byte_string(pExceptionMessage, CP_UTF8);
+    auto page = ANCM_ERROR_PAGE;
+
+
+    auto responseContent = FILE_UTILITY::GetHtml(g_hServerModule,
+                                                 page,
+                                                 errorContext.statusCode,
+                                                 errorContext.subStatusCode,
+                                                 errorContext.generalErrorType,
+                                                 errorContext.errorReason,
+                                                 errorContext.detailedErrorContent);
     m_pApplication = make_application<ServerErrorApplication>(
         pHttpApplication,
         E_FAIL,
         false /* disableStartupPage */,
-        "" /* responseContent */,
-        500i16 /* statusCode */,
-        0i16 /* subStatusCode */,
+        responseContent /* responseContent */,
+        errorContext.statusCode /* statusCode */,
+        errorContext.subStatusCode/* subStatusCode */,
         "Internal Server Error");
 
     return S_OK;
@@ -193,7 +209,26 @@ APPLICATION_INFO::TryCreateApplication(IHttpContext& pHttpContext, const ShimOpt
         }
     }
 
-    auto shadowCopyPath = HandleShadowCopy(options, pHttpContext);
+    std::filesystem::path shadowCopyPath;
+
+    // Only support shadow copying for IIS.
+    if (options.QueryShadowCopyEnabled() && !m_pServer.IsCommandLineLaunch())
+    {
+        try
+        {
+            shadowCopyPath = HandleShadowCopy(options, pHttpContext, error);
+        }
+        catch (...)
+        {
+            OBSERVE_CAUGHT_EXCEPTION();
+            throw;
+        }
+
+        if (shadowCopyPath.empty())
+        {
+            return E_FAIL;
+        }
+    }
 
     RETURN_IF_FAILED(m_handlerResolver.GetApplicationFactory(*pHttpContext.GetApplication(), shadowCopyPath, m_pApplicationFactory, options, error));
     LOG_INFO(L"Creating handler application");
@@ -275,74 +310,116 @@ APPLICATION_INFO::ShutDownApplication(const bool fServerInitiated)
  * we will start a thread that deletes all other folders in that directory.
  */
 std::filesystem::path
-APPLICATION_INFO::HandleShadowCopy(const ShimOptions& options, IHttpContext& pHttpContext)
+APPLICATION_INFO::HandleShadowCopy(const ShimOptions& options, IHttpContext& pHttpContext, ErrorContext& error)
 {
-    std::filesystem::path shadowCopyPath;
+    std::filesystem::path shadowCopyPath = options.QueryShadowCopyDirectory();
+    std::wstring physicalPath = pHttpContext.GetApplication()->GetApplicationPhysicalPath();
 
-    // Only support shadow copying for IIS.
-    if (options.QueryShadowCopyEnabled() && !m_pServer.IsCommandLineLaunch())
+    // Make shadow copy path absolute.
+    if (!shadowCopyPath.is_absolute())
     {
-        shadowCopyPath = options.QueryShadowCopyDirectory();
-        std::wstring physicalPath = pHttpContext.GetApplication()->GetApplicationPhysicalPath();
-
-        // Make shadow copy path absolute.
-        if (!shadowCopyPath.is_absolute())
-        {
-            shadowCopyPath = std::filesystem::absolute(std::filesystem::path(physicalPath) / shadowCopyPath);
-        }
+        shadowCopyPath = std::filesystem::absolute(std::filesystem::path(physicalPath) / shadowCopyPath);
+    }
 
-        // The shadow copy directory itself isn't copied to directly.
-        // Instead subdirectories with numerically increasing names are created.
-        // This is because on shutdown, the app itself will still have all dlls loaded,
-        // meaning we can't copy to the same subdirectory. Therefore, on shutdown,
-        // we create a directory that is one larger than the previous largest directory number.
-        auto directoryName = 0;
-        std::string directoryNameStr = "0";
-        auto shadowCopyBaseDirectory = std::filesystem::directory_entry(shadowCopyPath);
-        if (!shadowCopyBaseDirectory.exists())
+    // The shadow copy directory itself isn't copied to directly.
+    // Instead subdirectories with numerically increasing names are created.
+    // This is because on shutdown, the app itself will still have all dlls loaded,
+    // meaning we can't copy to the same subdirectory. Therefore, on shutdown,
+    // we create a directory that is one larger than the previous largest directory number.
+    auto directoryName = 0;
+    std::string directoryNameStr = "0";
+    auto shadowCopyBaseDirectory = std::filesystem::directory_entry(shadowCopyPath);
+    if (!shadowCopyBaseDirectory.exists())
+    {
+        auto ret = CreateDirectory(shadowCopyBaseDirectory.path().wstring().c_str(), nullptr);
+        if (!ret)
         {
-            CreateDirectory(shadowCopyBaseDirectory.path().wstring().c_str(), nullptr);
+            auto pathString = to_multi_byte_string(shadowCopyBaseDirectory.path(), CP_UTF8);
+            auto errorCode = std::error_code(GetLastError(), std::system_category());
+            std::string errorMessage = format("Failed to create shadow copy base directory %s. Error: %s",
+                                              pathString.c_str(),
+                                              errorCode.message().c_str());
+
+            // TODO: Better substatus code
+            error.statusCode = 500i16;
+            error.subStatusCode = 30i16;
+            error.generalErrorType = format("ASP.NET Core app failed to start - Failed to copy to shadow copy directory");
+            error.errorReason = format("Ensure the application pool process model has write permissions for the shadow copy base directory %s",
+                                       pathString.c_str());
+            error.detailedErrorContent = errorMessage;
+            return std::wstring();
         }
+    }
 
-        for (auto& entry : std::filesystem::directory_iterator(shadowCopyPath))
+    for (auto& entry : std::filesystem::directory_iterator(shadowCopyPath))
+    {
+        if (entry.is_directory())
         {
-            if (entry.is_directory())
+            try
             {
-                try
-                {
-                    auto tempDirName = entry.path().filename().string();
-                    int intFileName = std::stoi(tempDirName);
-                    if (intFileName > directoryName)
-                    {
-                        directoryName = intFileName;
-                        directoryNameStr = tempDirName;
-                    }
-                }
-                catch (...)
+                auto tempDirName = entry.path().filename().string();
+                int intFileName = std::stoi(tempDirName);
+                if (intFileName > directoryName)
                 {
-                    OBSERVE_CAUGHT_EXCEPTION();
-                    // Ignore any folders that can't be converted to an int.
+                    directoryName = intFileName;
+                    directoryNameStr = tempDirName;
                 }
             }
+            catch (...)
+            {
+                OBSERVE_CAUGHT_EXCEPTION();
+                // Ignore any folders that can't be converted to an int.
+            }
         }
+    }
 
-        int copiedFileCount = 0;
+    int copiedFileCount = 0;
 
-        shadowCopyPath = shadowCopyPath / directoryNameStr;
-        LOG_INFOF(L"Copying to shadow copy directory %ls.", shadowCopyPath.c_str());
+    shadowCopyPath = shadowCopyPath / directoryNameStr;
+    LOG_INFOF(L"Copying from %ls to shadow copy directory %ls.", physicalPath.c_str(), shadowCopyPath.c_str());
+
+    // Avoid using canonical for shadowCopyBaseDirectory
+    // It could expand to a network drive, or an expanded link folder path
+    // We already made it an absolute path relative to the physicalPath above
+    try {
+        // CopyToDirectory will succeed or throw exception, so return value can be ignored
+        Environment::CopyToDirectory(physicalPath, shadowCopyPath, options.QueryCleanShadowCopyDirectory(), shadowCopyBaseDirectory.path(), copiedFileCount);
+    }
+    catch (const std::system_error& ex)
+    {
+        auto exWideString = to_wide_string(ex.what(), CP_ACP);
 
-        // Avoid using canonical for shadowCopyBaseDirectory
-        // It could expand to a network drive, or an expanded link folder path
-        // We already made it an absolute path relative to the physicalPath above
-        HRESULT hr = Environment::CopyToDirectory(physicalPath, shadowCopyPath, options.QueryCleanShadowCopyDirectory(), shadowCopyBaseDirectory.path(), copiedFileCount);
+        std::wstring logMessage = format(L"Failed to copy files from %s to shadow copy directory %s. Error: %s",
+                                         physicalPath.c_str(),
+                                         shadowCopyPath.c_str(),
+                                         exWideString.c_str());
 
-        LOG_INFOF(L"Finished copying %d files to shadow copy directory %ls.", copiedFileCount, shadowCopyBaseDirectory.path().c_str());
+        LOG_ERRORF(L"%ls", logMessage.c_str());
+        EventLog::Error(ASPNETCORE_CONFIGURATION_LOAD_ERROR,
+                        ASPNETCORE_CONFIGURATION_LOAD_ERROR_MSG,
+                        logMessage.c_str());
 
-        if (hr != S_OK)
+        // TODO: Better substatus code
+        error.statusCode = 500i16;
+        error.subStatusCode = 30i16;
+
+        std::string errorMessage = "Failed to copy to shadow copy directory";
+        auto exceptionCode = ex.code().value();
+        if (exceptionCode == ERROR_ACCESS_DENIED || exceptionCode == ERROR_PATH_NOT_FOUND)
         {
-            return std::wstring();
+            errorMessage = "No permissions to shadow copy directory";
+        }
+
+        error.generalErrorType = format("ASP.NET Core app failed to start - %s", errorMessage.c_str());
+        error.errorReason = format("Ensure the application pool process model has write permissions to the shadow copy directory %ls",
+                                   shadowCopyPath.c_str());
+        if (options.QueryShowDetailedErrors())
+        {
+            error.detailedErrorContent = ex.what();
         }
+        return std::wstring();
     }
 
+    LOG_INFOF(L"Finished copying %d files to shadow copy directory %ls.", copiedFileCount, shadowCopyBaseDirectory.path().c_str());
     return shadowCopyPath;
 }

src/Servers/IIS/AspNetCoreModuleV2/AspNetCore/applicationinfo.h

@@ -80,7 +80,7 @@ class APPLICATION_INFO: NonCopyable
     TryCreateApplication(IHttpContext& pHttpContext, const ShimOptions& options, ErrorContext& error);
 
     std::filesystem::path
-    HandleShadowCopy(const ShimOptions& options, IHttpContext& pHttpContext);
+    HandleShadowCopy(const ShimOptions& options, IHttpContext& pHttpContext, ErrorContext& error);
 
     IHttpServer            &m_pServer;
     HandlerResolver        &m_handlerResolver;

src/Servers/IIS/AspNetCoreModuleV2/CommonLib/Environment.cpp

@@ -168,7 +168,23 @@ void Environment::CopyToDirectoryInner(const std::filesystem::path& source, cons
     auto destinationDirEntry = std::filesystem::directory_entry(destination);
     if (!destinationDirEntry.exists())
     {
-        CreateDirectory(destination.wstring().c_str(), nullptr);
+        auto ret = CreateDirectory(destination.wstring().c_str(), nullptr);
+        if (!ret)
+        {
+            // TODO: macro this or not?
+            std::string msg = format("Failed to create destination directory: %s (source: %s)",
+                                      destination.string().c_str(),
+                                      source.string().c_str());
+            auto ex = std::system_error(GetLastError(), std::system_category(), msg);
+            try {
+                throw ex;
+            }
+            catch (...)
+            {
+                OBSERVE_CAUGHT_EXCEPTION();
+                throw;
+            }
+        }
     }
 
     for (auto& path : std::filesystem::directory_iterator(source))
@@ -187,13 +203,29 @@ void Environment::CopyToDirectoryInner(const std::filesystem::path& source, cons
                     continue;
                 }
             }
-
+            auto sourcePathString = path.path().wstring();
+            auto destinationPathString = destinationPath.wstring();
+            auto ret = CopyFile(sourcePathString.c_str(), destinationPathString.c_str(), FALSE);
+            if (!ret)
+            {
+                std::string msg = format("Failed to copy file %s to %s",
+                                         sourcePathString.c_str(),
+                                         destinationPathString.c_str());
+                auto ex = std::system_error(GetLastError(), std::system_category(), msg);
+                try {
+                    throw ex;
+                }
+                catch (...)
+                {
+                    OBSERVE_CAUGHT_EXCEPTION();
+                    throw;
+                }
+            }
             copiedFileCount++;
-            CopyFile(path.path().wstring().c_str(), destinationPath.wstring().c_str(), FALSE);
         }
         else if (path.is_directory())
         {
-            auto sourceInnerDirectory = path.path();
+            auto& sourceInnerDirectory = path.path();
 
             if (sourceInnerDirectory.wstring().rfind(directoryToIgnore, 0) != 0)
             {

src/Servers/IIS/AspNetCoreModuleV2/CommonLib/exceptions.h

@@ -9,6 +9,7 @@
 #include "debugutil.h"
 #include "StringHelpers.h"
 #include "InvalidOperationException.h"
+#include "ConfigurationLoadException.h"
 #include "ntassert.h"
 #include "NonCopyable.h"
 #include "EventTracing.h"
@@ -197,6 +198,11 @@ __declspec(noinline) inline HRESULT CaughtExceptionHResult(LOCATION_ARGUMENTS_ON
         ReportException(LOCATION_CALL exception);
         return exception.GetResult();
     }
+    catch (const ConfigurationLoadException& exception)
+    {
+        ReportException(LOCATION_CALL exception);
+        return HRESULT_FROM_WIN32(ERROR_UNHANDLED_EXCEPTION);
+    }
     catch (const InvalidOperationException& exception)
     {
         ReportException(LOCATION_CALL exception);
@@ -224,6 +230,10 @@ __declspec(noinline) inline std::wstring CaughtExceptionToString()
     {
         return exception.as_wstring();
     }
+    catch (const ConfigurationLoadException& exception)
+    {
+        return exception.get_message();
+    }
     catch (const std::system_error& exception)
     {
         return to_wide_string(exception.what(), CP_ACP);