Add default debug log file name and dll information to debug log (#1149)

build/launchSettings.json

@@ -20,7 +20,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     },
     "ANCM IIS": {
@@ -34,7 +34,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     }
   }

samples/NativeIISSample/Properties/launchSettings.json

@@ -20,7 +20,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     },
     "ANCM IIS": {
@@ -34,7 +34,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     }
   }

src/AspNetCoreModuleV2/AspNetCore/AspNetCore.vcxproj

@@ -102,7 +102,7 @@
     <Link>
       <SubSystem>Windows</SubSystem>
       <GenerateDebugInformation>true</GenerateDebugInformation>
-      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
@@ -138,7 +138,7 @@
     <Link>
       <SubSystem>Windows</SubSystem>
       <GenerateDebugInformation>true</GenerateDebugInformation>
-      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
@@ -178,7 +178,7 @@
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <OptimizeReferences>true</OptimizeReferences>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;winhttp.lib;odbc32.lib;ws2_32.lib;odbccp32.lib;wbemuuid.lib;iphlpapi.lib;pdh.lib;rpcrt4.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
     <ResourceCompile>
@@ -217,7 +217,7 @@
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <OptimizeReferences>true</OptimizeReferences>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
     <ResourceCompile>

src/AspNetCoreModuleV2/AspNetCore/applicationinfo.cpp

@@ -206,7 +206,7 @@ APPLICATION_INFO::FindRequestHandlerAssembly(STRU& location)
                 }
             }
 
-            WLOG_INFOF(L"Loading request handler: %s", struFileName.QueryStr());
+            LOG_INFOF("Loading request handler: %S", struFileName.QueryStr());
 
             s_hAspnetCoreRH = LoadLibraryW(struFileName.QueryStr());
 

src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp

@@ -15,7 +15,6 @@ DECLARE_DEBUG_PRINT_OBJECT("aspnetcorev2.dll");
 
 HANDLE              g_hEventLog = NULL;
 BOOL                g_fRecycleProcessCalled = FALSE;
-HINSTANCE           g_hModule;
 BOOL                g_fInShutdown = FALSE;
 
 VOID
@@ -41,9 +40,8 @@ BOOL WINAPI DllMain(HMODULE hModule,
     switch (ul_reason_for_call)
     {
     case DLL_PROCESS_ATTACH:
-        g_hModule = hModule;
         DisableThreadLibraryCalls(hModule);
-        DebugInitialize();
+        DebugInitialize(hModule);
         break;
     case DLL_PROCESS_DETACH:
         // IIS can cause dll detach to occur before we receive global notifications

src/AspNetCoreModuleV2/CommonLib/Environment.cpp

@@ -56,5 +56,7 @@ Environment::GetEnvironmentVariableValue(const std::wstring & str)
         }
     } while (expandedStr.size() != requestedSize + 1);
 
+    expandedStr.resize(requestedSize);
+
     return expandedStr;
 }

src/AspNetCoreModuleV2/CommonLib/debugutil.cpp

@@ -16,11 +16,138 @@
 
 inline HANDLE g_hStandardOutput = INVALID_HANDLE_VALUE;
 inline HANDLE g_logFile = INVALID_HANDLE_VALUE;
+inline HMODULE g_hModule;
 inline SRWLOCK g_logFileLock;
 
-VOID
+HRESULT
-DebugInitialize()
+PrintDebugHeader()
 {
+    DWORD  verHandle = 0;
+    UINT   size      = 0;
+    LPVOID lpBuffer  = NULL;
+
+    WCHAR path[MAX_PATH];
+    RETURN_LAST_ERROR_IF(!GetModuleFileName(g_hModule, path, sizeof(path)));
+
+    DWORD verSize = GetFileVersionInfoSize(path, &verHandle);
+    RETURN_LAST_ERROR_IF(verSize == 0);
+
+    // Allocate memory to hold data structure returned by GetFileVersionInfo
+    std::vector<BYTE> verData(verSize);
+
+    RETURN_LAST_ERROR_IF(!GetFileVersionInfo(path, verHandle, verSize, verData.data()));
+    RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), L"\\", &lpBuffer, &size));
+
+    auto verInfo = reinterpret_cast<VS_FIXEDFILEINFO *>(lpBuffer);
+    // Check result signature
+    if (verInfo->dwSignature == VS_FFI_SIGNATURE)
+    {
+        LPVOID pvProductName = NULL;
+        unsigned int iProductNameLen = 0;
+        RETURN_LAST_ERROR_IF(!VerQueryValue(verData.data(), _T("\\StringFileInfo\\040904b0\\FileDescription"), &pvProductName, &iProductNameLen));
+
+        // Major, minor are stored in dwFileVersionMS field and patch, build in dwFileVersionLS field as pair of 32 bit numbers
+        DebugPrintf(ASPNETCORE_DEBUG_FLAG_INFO, "Initializing logs for %S. File Version: %d.%d.%d.%d. Description: %S",
+            path,
+            ( verInfo->dwFileVersionMS >> 16 ) & 0xffff,
+            ( verInfo->dwFileVersionMS >>  0 ) & 0xffff,
+            ( verInfo->dwFileVersionLS >> 16 ) & 0xffff,
+            ( verInfo->dwFileVersionLS >>  0 ) & 0xffff,
+            pvProductName
+        );
+    }
+
+    return S_OK;
+}
+
+void SetDebugFlags(const std::wstring &debugValue)
+{
+    try
+    {
+        if (!debugValue.empty())
+        {
+            const auto value = std::stoi(debugValue);
+
+            if (value >= 1) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_ERROR;
+            if (value >= 2) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_WARNING;
+            if (value >= 3) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_INFO;
+            if (value >= 4) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_CONSOLE;
+            if (value >= 5) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_FILE;
+
+            return;
+        }
+    }
+    catch (...)
+    {
+        // ignore
+    }
+
+    try
+    {
+        std::wstringstream stringStream(debugValue);
+        std::wstring flag;
+
+        while (std::getline(stringStream, flag, L','))
+        {
+            if (_wcsnicmp(flag.c_str(), L"error", wcslen(L"error")) == 0) DEBUG_FLAGS_VAR |= DEBUG_FLAGS_ERROR;
+            if (_wcsnicmp(flag.c_str(), L"warning", wcslen(L"warning")) == 0) DEBUG_FLAGS_VAR |= DEBUG_FLAGS_WARN;
+            if (_wcsnicmp(flag.c_str(), L"info", wcslen(L"info")) == 0) DEBUG_FLAGS_VAR |= DEBUG_FLAGS_INFO;
+            if (_wcsnicmp(flag.c_str(), L"console", wcslen(L"console")) == 0) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_CONSOLE;
+            if (_wcsnicmp(flag.c_str(), L"file", wcslen(L"file")) == 0) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_FILE;
+        }
+
+        // If file or console is enabled but level is not set, enable all levels
+        if (DEBUG_FLAGS_VAR != 0 && (DEBUG_FLAGS_VAR & DEBUG_FLAGS_ANY) == 0)
+        {
+            DEBUG_FLAGS_VAR |= DEBUG_FLAGS_ANY;
+        }
+    }
+    catch (...)
+    {
+        // ignore
+    }
+}
+
+bool CreateDebugLogFile(const std::wstring &debugOutputFile)
+{
+    try
+    {
+        if (!debugOutputFile.empty())
+        {
+            if (g_logFile != INVALID_HANDLE_VALUE)
+            {
+                LOG_INFOF("Switching debug log files to %S", debugOutputFile.c_str());
+            }
+
+            SRWExclusiveLock lock(g_logFileLock);
+            if (g_logFile != INVALID_HANDLE_VALUE)
+            {
+                CloseHandle(g_logFile);
+                g_logFile = INVALID_HANDLE_VALUE;
+            }
+            g_logFile = CreateFileW(debugOutputFile.c_str(),
+                (GENERIC_READ | GENERIC_WRITE),
+                (FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE),
+                nullptr,
+                OPEN_ALWAYS,
+                FILE_ATTRIBUTE_NORMAL,
+                nullptr
+            );
+            return true;
+        }
+    }
+    catch (...)
+    {
+        // ignore
+    }
+
+    return false;
+}
+
+VOID
+DebugInitialize(HMODULE hModule)
+{
+    g_hModule = hModule;
     g_hStandardOutput = GetStdHandle(STD_OUTPUT_HANDLE);
 
     HKEY hKey;
@@ -75,11 +202,15 @@ DebugInitialize()
     {
         DEBUG_FLAGS_VAR |= DEBUG_FLAGS_INFO;
     }
+
+    PrintDebugHeader();
 }
 
 HRESULT
 DebugInitializeFromConfig(IHttpServer& pHttpServer, IHttpApplication& pHttpApplication)
 {
+    auto oldFlags = DEBUG_FLAGS_VAR;
+
     CComPtr<IAppHostElement>        pAspNetCoreElement;
 
     const CComBSTR bstrAspNetCoreSection = L"system.webServer/aspNetCore";
@@ -97,68 +228,32 @@ DebugInitializeFromConfig(IHttpServer& pHttpServer, IHttpApplication& pHttpAppli
 
     SetDebugFlags(debugValue.QueryStr());
 
-    CreateDebugLogFile(debugFile.QueryStr());
+    if (debugFile.QueryCCH() == 0 && IsEnabled(ASPNETCORE_DEBUG_FLAG_FILE))
+    {
+        debugFile.Append(L".\\aspnetcore-debug.log");
+    }
+
+    std::filesystem::path filePath = std::filesystem::path(debugFile.QueryStr());
+    if (!filePath.empty() && filePath.is_relative())
+    {
+        filePath = std::filesystem::path(pHttpApplication.GetApplicationPhysicalPath()) / filePath;
+    }
+
+    const auto reopenedFile = CreateDebugLogFile(filePath);
+
+    // Print header if flags changed
+    if (oldFlags != DEBUG_FLAGS_VAR || reopenedFile)
+    {
+        PrintDebugHeader();
+    }
 
     return S_OK;
 }
 
-void SetDebugFlags(const std::wstring &debugValue)
-{
-    try
-    {
-        if (!debugValue.empty())
-        {
-            const auto value = std::stoi(debugValue.c_str());
-
-            if (value >= 1) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_ERROR;
-            if (value >= 2) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_WARNING;
-            if (value >= 3) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_INFO;
-            if (value >= 4) DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_CONSOLE;
-        }
-    }
-    catch (...)
-    {
-        // ignore
-    }
-}
-
-void CreateDebugLogFile(const std::wstring &debugOutputFile)
-{
-    try
-    {
-        if (!debugOutputFile.empty())
-        {
-            if (g_logFile != INVALID_HANDLE_VALUE)
-            {
-                WLOG_INFOF(L"Switching debug log files to %s", debugOutputFile.c_str());
-                CloseHandle(g_logFile);
-                DEBUG_FLAGS_VAR &= ~ASPNETCORE_DEBUG_FLAG_FILE;
-
-            }
-            g_logFile = CreateFileW(debugOutputFile.c_str(),
-                (GENERIC_READ | GENERIC_WRITE),
-                (FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE),
-                nullptr,
-                OPEN_ALWAYS,
-                FILE_ATTRIBUTE_NORMAL,
-                nullptr
-            );
-            if (g_logFile != INVALID_HANDLE_VALUE)
-            {
-                DEBUG_FLAGS_VAR |= ASPNETCORE_DEBUG_FLAG_FILE;
-            }
-        }
-    }
-    catch (...)
-    {
-        // ignore
-    }
-}
-
 VOID
 DebugStop()
 {
-    if (IsEnabled(ASPNETCORE_DEBUG_FLAG_FILE))
+    if (g_logFile != INVALID_HANDLE_VALUE)
     {
         CloseHandle(g_logFile);
     }
@@ -200,7 +295,7 @@ DebugPrint(
             WriteFile(g_hStandardOutput, strOutput.QueryStr(), strOutput.QueryCB(), &nBytesWritten, nullptr);
         }
 
-        if (IsEnabled(ASPNETCORE_DEBUG_FLAG_FILE))
+        if (g_logFile != INVALID_HANDLE_VALUE)
         {
             SRWExclusiveLock lock(g_logFileLock);
 
@@ -239,38 +334,3 @@ DebugPrintf(
         DebugPrint( dwFlag, strCooked.QueryStr() );
     }
 }
-
-VOID
-WDebugPrintf(
-    DWORD   dwFlag,
-    LPCWSTR   szFormat,
-    ...
-    )
-{
-    va_list  args;
-    HRESULT hr = S_OK;
-
-    if ( IsEnabled( dwFlag ) )
-    {
-        STACK_STRU (formatted,256);
-
-        va_start( args, szFormat );
-
-        hr = formatted.SafeVsnwprintf(szFormat, args );
-
-        va_end( args );
-
-        if (FAILED (hr))
-        {
-            return;
-        }
-
-        STACK_STRA (converted, 256);
-        if (FAILED ( converted.CopyW(formatted.QueryStr(), formatted.QueryCCH()) ))
-        {
-            return;
-        }
-
-        DebugPrint( dwFlag, converted.QueryStr() );
-    }
-}

src/AspNetCoreModuleV2/CommonLib/debugutil.h

@@ -12,31 +12,23 @@
 #define ASPNETCORE_DEBUG_FLAG_WARNING       DEBUG_FLAG_WARN
 #define ASPNETCORE_DEBUG_FLAG_ERROR         DEBUG_FLAG_ERROR
 #define ASPNETCORE_DEBUG_FLAG_CONSOLE       0x00000008
-#define ASPNETCORE_DEBUG_FLAG_FILE          0x00000008
+#define ASPNETCORE_DEBUG_FLAG_FILE          0x00000010
 
 #define LOG_INFO(...) DebugPrint(ASPNETCORE_DEBUG_FLAG_INFO, __VA_ARGS__)
 #define LOG_INFOF(...) DebugPrintf(ASPNETCORE_DEBUG_FLAG_INFO, __VA_ARGS__)
-#define WLOG_INFOF(...) WDebugPrintf(ASPNETCORE_DEBUG_FLAG_INFO, __VA_ARGS__)
 
 #define LOG_WARN(...) DebugPrint(ASPNETCORE_DEBUG_FLAG_WARNING, __VA_ARGS__)
 #define LOG_WARNF(...) DebugPrintf(ASPNETCORE_DEBUG_FLAG_WARNING, __VA_ARGS__)
-#define WLOG_WARNF(...) WDebugPrintf(ASPNETCORE_DEBUG_FLAG_WARNING, __VA_ARGS__)
 
 #define LOG_ERROR(...) DebugPrint(ASPNETCORE_DEBUG_FLAG_ERROR, __VA_ARGS__)
 #define LOG_ERRORF(...) DebugPrintf(ASPNETCORE_DEBUG_FLAG_ERROR, __VA_ARGS__)
-#define WLOG_ERRORF(...) WDebugPrintf(ASPNETCORE_DEBUG_FLAG_ERROR, __VA_ARGS__)
 
 VOID
-DebugInitialize();
+DebugInitialize(HMODULE hModule);
-
-VOID
-CreateDebugLogFile(const std::wstring &debugOutputFile);
 
 HRESULT
 DebugInitializeFromConfig(IHttpServer& pHttpServer, IHttpApplication& pHttpApplication);
 
-void SetDebugFlags(const std::wstring &value);
-
 VOID
 DebugStop();
 
@@ -57,10 +49,3 @@ DebugPrintf(
     LPCSTR  szFormat,
     ...
     );
-
-VOID
-WDebugPrintf(
-    DWORD   dwFlag,
-    LPCWSTR  szFormat,
-    ...
-    );

src/AspNetCoreModuleV2/CommonLib/hostfxr_utility.cpp

@@ -38,7 +38,7 @@ HOSTFXR_UTILITY::GetStandaloneHostfxrParameters(
         _Out_ BSTR**		ppwzArgv
 )
 {
-    WLOG_INFOF(L"Resolving standalone hostfxr parameters for application: %s arguments: %s path: %s",
+    LOG_INFOF("Resolving standalone hostfxr parameters for application: %S arguments: %S path: %S",
         pwzExeAbsolutePath,
         pcwzArguments,
         pwzExeAbsolutePath);
@@ -47,7 +47,7 @@ HOSTFXR_UTILITY::GetStandaloneHostfxrParameters(
 
     if (!exePath.has_extension())
     {
-        WLOG_INFOF(L"Exe path has not extension, returning");
+        LOG_INFOF("Exe path has not extension, returning");
 
         return false;
     }
@@ -55,14 +55,14 @@ HOSTFXR_UTILITY::GetStandaloneHostfxrParameters(
     const fs::path physicalPath(pcwzApplicationPhysicalPath);
     const fs::path hostFxrLocation = physicalPath / "hostfxr.dll";
 
-    WLOG_INFOF(L"Checking hostfxr.dll at %s", hostFxrLocation.c_str());
+    LOG_INFOF("Checking hostfxr.dll at %S", hostFxrLocation.c_str());
 
     if (!is_regular_file(hostFxrLocation))
     {
         fs::path runtimeConfigLocation = exePath;
         runtimeConfigLocation.replace_extension(L".runtimeconfig.json");
 
-        WLOG_INFOF(L"Checking runtimeconfig.json at %s", runtimeConfigLocation.c_str());
+        LOG_INFOF("Checking runtimeconfig.json at %S", runtimeConfigLocation.c_str());
         if (!is_regular_file(runtimeConfigLocation))
         {
             EVENTLOG(hEventLog, INPROCESS_FULL_FRAMEWORK_APP, pcwzApplicationPhysicalPath, 0);
@@ -78,7 +78,7 @@ HOSTFXR_UTILITY::GetStandaloneHostfxrParameters(
 
     if (!is_regular_file(dllPath))
     {
-        WLOG_INFOF(L"Application dll at %s was not found", dllPath.c_str());
+        LOG_INFOF("Application dll at %S was not found", dllPath.c_str());
         return E_FAIL;
     }
 
@@ -119,7 +119,7 @@ HOSTFXR_UTILITY::GetHostFxrParameters(
 {
     HRESULT                     hr = S_OK;
 
-    WLOG_INFOF(L"Resolving hostfxr parameters for application: %s arguments: %s path: %s",
+    LOG_INFOF("Resolving hostfxr parameters for application: %S arguments: %S path: %S",
         pcwzProcessPath,
         pcwzArguments,
         pcwzApplicationPhysicalPath);
@@ -131,7 +131,7 @@ HOSTFXR_UTILITY::GetHostFxrParameters(
     // Check if the absolute path is to dotnet or not.
     if (IsDotnetExecutable(processPath))
     {
-        WLOG_INFOF(L"Process path %s is dotnet, treating application as portable", processPath.c_str());
+        LOG_INFOF("Process path %S is dotnet, treating application as portable", processPath.c_str());
         //
         // The processPath ends with dotnet.exe or dotnet
         // like: C:\Program Files\dotnet\dotnet.exe, C:\Program Files\dotnet\dotnet, dotnet.exe, or dotnet.
@@ -168,7 +168,7 @@ HOSTFXR_UTILITY::GetHostFxrParameters(
     }
     else
     {
-        WLOG_INFOF(L"Process path %s is not dotnet, treating application as standalone", processPath.c_str());
+        LOG_INFOF("Process path %S is not dotnet, treating application as standalone", processPath.c_str());
 
         if (processPath.is_relative())
         {
@@ -239,7 +239,7 @@ HOSTFXR_UTILITY::ParseHostfxrArguments(
     STRU        struTempPath;
     INT         intArgsProcessed = 0;
 
-    WLOG_INFOF(L"Resolving hostfxr_main arguments application: %s arguments: %s path: %s",
+    LOG_INFOF("Resolving hostfxr_main arguments application: %S arguments: %S path: %S",
         pwzExePath,
         pwzArgumentsFromConfig,
         pcwzApplicationPhysicalPath);
@@ -300,7 +300,7 @@ HOSTFXR_UTILITY::ParseHostfxrArguments(
             }
         }
 
-        WLOG_INFOF(L"Argument[%d] = %s",
+        LOG_INFOF("Argument[%d] = %S",
             intArgsProcessed + 1,
             argv[intArgsProcessed + 1]);
     }
@@ -337,7 +337,7 @@ HOSTFXR_UTILITY::GetAbsolutePathToDotnet(
      const fs::path & requestedPath
 )
 {
-    WLOG_INFOF(L"Resolving absolute path to dotnet.exe from %s", requestedPath.c_str());
+    LOG_INFOF("Resolving absolute path to dotnet.exe from %S", requestedPath.c_str());
 
     auto processPath = requestedPath;
     if (processPath.is_relative())
@@ -350,7 +350,7 @@ HOSTFXR_UTILITY::GetAbsolutePathToDotnet(
     //
     if (is_regular_file(requestedPath))
     {
-        WLOG_INFOF(L"Found dotnet.exe at %s", requestedPath.c_str());
+        LOG_INFOF("Found dotnet.exe at %S", requestedPath.c_str());
 
         return std::make_optional(requestedPath);
     }
@@ -360,7 +360,7 @@ HOSTFXR_UTILITY::GetAbsolutePathToDotnet(
 
     if (is_regular_file(pathWithExe))
     {
-        WLOG_INFOF(L"Found dotnet.exe at %s", pathWithExe.c_str());
+        LOG_INFOF("Found dotnet.exe at %S", pathWithExe.c_str());
 
         return std::make_optional(pathWithExe);
     }
@@ -371,7 +371,7 @@ HOSTFXR_UTILITY::GetAbsolutePathToDotnet(
     // Only do it if no path is specified
     if (requestedPath.has_parent_path())
     {
-        WLOG_INFOF(L"Absolute path to dotnet.exe was not found at %s", requestedPath.c_str());
+        LOG_INFOF("Absolute path to dotnet.exe was not found at %S", requestedPath.c_str());
 
         return std::nullopt;
     }
@@ -379,7 +379,7 @@ HOSTFXR_UTILITY::GetAbsolutePathToDotnet(
     const auto dotnetViaWhere = InvokeWhereToFindDotnet();
     if (dotnetViaWhere.has_value())
     {
-        WLOG_INFOF(L"Found dotnet.exe via where.exe invocation at %s", dotnetViaWhere.value().c_str());
+        LOG_INFOF("Found dotnet.exe via where.exe invocation at %S", dotnetViaWhere.value().c_str());
 
         return dotnetViaWhere;
     }
@@ -387,12 +387,12 @@ HOSTFXR_UTILITY::GetAbsolutePathToDotnet(
     const auto programFilesLocation = GetAbsolutePathToDotnetFromProgramFiles();
     if (programFilesLocation.has_value())
     {
-        WLOG_INFOF(L"Found dotnet.exe in Program Files at %s", programFilesLocation.value().c_str());
+        LOG_INFOF("Found dotnet.exe in Program Files at %S", programFilesLocation.value().c_str());
 
         return programFilesLocation;
     }
 
-    WLOG_INFOF(L"dotnet.exe not found");
+    LOG_INFOF("dotnet.exe not found");
     return std::nullopt;
 }
 
@@ -405,7 +405,7 @@ HOSTFXR_UTILITY::GetAbsolutePathToHostFxr(
     std::vector<std::wstring> versionFolders;
     const auto hostFxrBase = dotnetPath.parent_path() / "host" / "fxr";
 
-    WLOG_INFOF(L"Resolving absolute path to hostfxr.dll from %s", dotnetPath.c_str());
+    LOG_INFOF("Resolving absolute path to hostfxr.dll from %S", dotnetPath.c_str());
 
     if (!is_directory(hostFxrBase))
     {
@@ -434,7 +434,7 @@ HOSTFXR_UTILITY::GetAbsolutePathToHostFxr(
         return std::nullopt;
     }
 
-    WLOG_INFOF(L"hostfxr.dll located at %s", hostFxrPath.c_str());
+    LOG_INFOF("hostfxr.dll located at %S", hostFxrPath.c_str());
     return std::make_optional(hostFxrPath);
 }
 
@@ -551,7 +551,7 @@ HOSTFXR_UTILITY::InvokeWhereToFindDotnet()
 
     FINISHED_IF_FAILED(struDotnetLocationsString.CopyA(pzFileContents, dwNumBytesRead));
 
-    WLOG_INFOF(L"where.exe invocation returned: %s", struDotnetLocationsString.QueryStr());
+    LOG_INFOF("where.exe invocation returned: %S", struDotnetLocationsString.QueryStr());
 
     // Check the bitness of the currently running process
     // matches the dotnet.exe found.
@@ -570,7 +570,7 @@ HOSTFXR_UTILITY::InvokeWhereToFindDotnet()
         fIsCurrentProcess64Bit = systemInfo.wProcessorArchitecture == PROCESSOR_ARCHITECTURE_AMD64;
     }
 
-    WLOG_INFOF(L"Current process bitness type detected as isX64=%d", fIsCurrentProcess64Bit);
+    LOG_INFOF("Current process bitness type detected as isX64=%d", fIsCurrentProcess64Bit);
 
     while (TRUE)
     {
@@ -584,14 +584,14 @@ HOSTFXR_UTILITY::InvokeWhereToFindDotnet()
         // \r\n is two wchars, so add 2 here.
         prevIndex = index + 2;
 
-        WLOG_INFOF(L"Processing entry %s", struDotnetSubstring.QueryStr());
+        LOG_INFOF("Processing entry %S", struDotnetSubstring.QueryStr());
 
         if (LOG_LAST_ERROR_IF(!GetBinaryTypeW(struDotnetSubstring.QueryStr(), &dwBinaryType)))
         {
             continue;
         }
 
-        WLOG_INFOF(L"Binary type %d", dwBinaryType);
+        LOG_INFOF("Binary type %d", dwBinaryType);
 
         if (fIsCurrentProcess64Bit == (dwBinaryType == SCS_64BIT_BINARY))
         {

src/AspNetCoreModuleV2/CommonLib/utility.cpp

@@ -572,7 +572,7 @@ UTILITY::LogEvent(
         );
     }
 
-    WDebugPrintf(dwEventInfoType == EVENTLOG_ERROR_TYPE ? ASPNETCORE_DEBUG_FLAG_ERROR : ASPNETCORE_DEBUG_FLAG_INFO, L"Event Log: %s", pstrMsg);
+    DebugPrintf(dwEventInfoType == EVENTLOG_ERROR_TYPE ? ASPNETCORE_DEBUG_FLAG_ERROR : ASPNETCORE_DEBUG_FLAG_INFO, "Event Log: %S", pstrMsg);
 }
 
 VOID

src/AspNetCoreModuleV2/IISLib/dbgutil.h

@@ -56,7 +56,7 @@ extern DWORD DEBUG_FLAGS_VAR;
 
 #define DECLARE_DEBUG_PRINT_OBJECT( _pszLabel_ )                \
     PCSTR DEBUG_LABEL_VAR = _pszLabel_;                 \
-    DWORD DEBUG_FLAGS_VAR = DEBUG_FLAGS_WARN;            \
+    DWORD DEBUG_FLAGS_VAR = 0;            \
 
 #define DECLARE_DEBUG_PRINT_OBJECT2( _pszLabel_, _dwLevel_ )    \
     PCSTR DEBUG_LABEL_VAR = _pszLabel_;                 \

src/AspNetCoreModuleV2/InProcessRequestHandler/InProcessRequestHandler.vcxproj

@@ -110,7 +110,7 @@
     <Link>
       <SubSystem>Windows</SubSystem>
       <GenerateDebugInformation>true</GenerateDebugInformation>
-      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
@@ -144,7 +144,7 @@
     <Link>
       <SubSystem>Windows</SubSystem>
       <GenerateDebugInformation>true</GenerateDebugInformation>
-      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
@@ -181,7 +181,7 @@
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <OptimizeReferences>true</OptimizeReferences>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;winhttp.lib;odbc32.lib;ws2_32.lib;odbccp32.lib;wbemuuid.lib;iphlpapi.lib;pdh.lib;rpcrt4.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
   </ItemDefinitionGroup>
@@ -217,7 +217,7 @@
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <OptimizeReferences>true</OptimizeReferences>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
   </ItemDefinitionGroup>

src/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp

@@ -50,7 +50,6 @@ InitializeGlobalConfiguration(
                 g_hEventLog = RegisterEventSource(NULL, ASPNETCORE_EVENT_PROVIDER);
             }
 
-            DebugInitialize();
             DebugInitializeFromConfig(*pServer, *pHttpApplication);
 
             g_fGlobalInitialize = TRUE;
@@ -72,6 +71,7 @@ BOOL APIENTRY DllMain(HMODULE hModule,
     case DLL_PROCESS_ATTACH:
         DisableThreadLibraryCalls(hModule);
         InitializeSRWLock(&g_srwLockRH);
+        DebugInitialize(hModule);
         break;
     case DLL_PROCESS_DETACH:
         g_fProcessDetach = TRUE;

src/AspNetCoreModuleV2/OutOfProcessRequestHandler/OutOfProcessRequestHandler.vcxproj

@@ -110,7 +110,7 @@
     <Link>
       <SubSystem>Windows</SubSystem>
       <GenerateDebugInformation>true</GenerateDebugInformation>
-      <AdditionalDependencies>kernel32.lib;user32.lib;nothrownew.obj;advapi32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib;Rpcrt4.lib;winhttp.lib</AdditionalDependencies>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
@@ -144,7 +144,7 @@
     <Link>
       <SubSystem>Windows</SubSystem>
       <GenerateDebugInformation>true</GenerateDebugInformation>
-      <AdditionalDependencies>kernel32.lib;user32.lib;nothrownew.obj;advapi32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib;Rpcrt4.lib;winhttp.lib</AdditionalDependencies>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
@@ -181,7 +181,7 @@
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <OptimizeReferences>true</OptimizeReferences>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
-      <AdditionalDependencies>kernel32.lib;user32.lib;nothrownew.obj;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;winhttp.lib;odbc32.lib;ws2_32.lib;odbccp32.lib;wbemuuid.lib;iphlpapi.lib;pdh.lib;rpcrt4.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib;Rpcrt4.lib;winhttp.lib</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
   </ItemDefinitionGroup>
@@ -217,7 +217,7 @@
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <OptimizeReferences>true</OptimizeReferences>
       <ModuleDefinitionFile>Source.def</ModuleDefinitionFile>
-      <AdditionalDependencies>kernel32.lib;user32.lib;nothrownew.obj;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;rpcrt4.lib;winhttp.lib;pdh.lib;ws2_32.lib;wbemuuid.lib;iphlpapi.lib;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib;Rpcrt4.lib;winhttp.lib</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
   </ItemDefinitionGroup>

src/AspNetCoreModuleV2/OutOfProcessRequestHandler/dllmain.cpp

@@ -88,8 +88,6 @@ InitializeGlobalConfiguration(
             }
         }
 
-        DebugInitialize();
-
         dwResult = GetExtendedTcpTable(NULL,
             &dwSize,
             FALSE,
@@ -257,6 +255,7 @@ BOOL APIENTRY DllMain(HMODULE hModule,
     case DLL_PROCESS_ATTACH:
         DisableThreadLibraryCalls(hModule);
         InitializeSRWLock(&g_srwLockRH);
+        DebugInitialize(hModule);
         break;
     case DLL_PROCESS_DETACH:
         g_fProcessDetach = TRUE;

src/AspNetCoreModuleV2/RequestHandlerLib/FileOutputManager.cpp

@@ -139,7 +139,7 @@ FileOutputManager::Start()
     // Periodically flush the log content to file
     m_Timer.InitializeTimer(STTIMER::TimerCallback, &m_struLogFilePath, 3000, 3000);
 
-    WLOG_INFOF(L"Created log file for inprocess application: %s",
+    LOG_INFOF("Created log file for inprocess application: %S",
         m_struLogFilePath.QueryStr());
 
     return S_OK;

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeployer.cs

@@ -73,7 +73,15 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                 {
                     DotnetPublish();
                     contentRoot = DeploymentParameters.PublishedApplicationRootPath;
-                    IISDeploymentParameters.AddDebugLogToWebConfig(Path.Combine(contentRoot, $"{_application.WebSiteName}.txt"));
+                    // Do not override settings set on parameters
+                    if (!IISDeploymentParameters.HandlerSettings.ContainsKey("debugLevel") &&
+                        !IISDeploymentParameters.HandlerSettings.ContainsKey("debugFile"))
+                    {
+                        var logFile = Path.Combine(contentRoot, $"{_application.WebSiteName}.txt");
+                        IISDeploymentParameters.HandlerSettings["debugLevel"] = "4";
+                        IISDeploymentParameters.HandlerSettings["debugFile"] = logFile;
+                    }
+
                     DefaultWebConfigActions.Add(WebConfigHelpers.AddOrModifyHandlerSection(
                         key: "modules",
                         value: DeploymentParameters.AncmVersion.ToString()));

test/Common.FunctionalTests/Inprocess/LoggingTests.cs

@@ -2,6 +2,7 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 using System;
+using System.Collections.Generic;
 using System.IO;
 using System.Linq;
 using System.Threading.Tasks;
@@ -84,30 +85,45 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         }
 
         [ConditionalFact]
-        [RequiresIIS(IISCapability.PoolEnvironmentVariables)]
         public async Task StartupMessagesAreLoggedIntoDebugLogFile()
         {
-            var tempFile = Path.GetTempFileName();
+            var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
-            try
+            deploymentParameters.HandlerSettings["debugLevel"] = "file";
-            {
+            deploymentParameters.HandlerSettings["debugFile"] = "debug.txt";
-                var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
-                deploymentParameters.EnvironmentVariables["ASPNETCORE_MODULE_DEBUG_FILE"] = tempFile;
-                deploymentParameters.AddDebugLogToWebConfig(tempFile);
 
-                var deploymentResult = await DeployAsync(deploymentParameters);
+            var deploymentResult = await DeployAsync(deploymentParameters);
 
-                var response = await deploymentResult.RetryingHttpClient.GetAsync("/");
+            await deploymentResult.RetryingHttpClient.GetAsync("/");
 
-                StopServer();
+            AssertLogs(Path.Combine(deploymentResult.ContentRoot, "debug.txt"));
+        }
 
-                var logContents = File.ReadAllText(tempFile);
+        [ConditionalFact]
-                Assert.Contains("[aspnetcorev2.dll]", logContents);
+        public async Task StartupMessagesAreLoggedIntoDefaultDebugLogFile()
-                Assert.Contains("[aspnetcorev2_inprocess.dll]", logContents);
+        {
-            }
+            var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
-            finally
+            deploymentParameters.HandlerSettings["debugLevel"] = "file";
-            {
+
-                File.Delete(tempFile);
+            var deploymentResult = await DeployAsync(deploymentParameters);
-            }
+
+            await deploymentResult.RetryingHttpClient.GetAsync("/");
+
+            AssertLogs(Path.Combine(deploymentResult.ContentRoot, "aspnetcore-debug.log"));
+        }
+
+        [ConditionalFact]
+        [RequiresIIS(IISCapability.PoolEnvironmentVariables)]
+        public async Task StartupMessagesAreLoggedIntoDefaultDebugLogFileWhenEnabledWithEnvVar()
+        {
+            var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
+            deploymentParameters.EnvironmentVariables["ASPNETCORE_MODULE_DEBUG"] = "file";
+            // Add empty debugFile handler setting to prevent IIS deployer from overriding debug settings
+            deploymentParameters.HandlerSettings["debugFile"] = "";
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            await deploymentResult.RetryingHttpClient.GetAsync("/");
+
+            AssertLogs(Path.Combine(deploymentResult.ContentRoot, "aspnetcore-debug.log"));
         }
 
         [ConditionalTheory]
@@ -176,9 +192,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
                 var logContents = File.ReadAllText(firstTempFile);
                 Assert.Contains("Switching debug log files to", logContents);
 
-                var secondLogContents = File.ReadAllText(secondTempFile);
+                AssertLogs(secondTempFile);
-                Assert.Contains("[aspnetcorev2.dll]", logContents);
-                Assert.Contains("[aspnetcorev2_inprocess.dll]", logContents);
             }
             finally
             {
@@ -186,5 +200,18 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
                 File.Delete(secondTempFile);
             }
         }
+
+        private static void AssertLogs(string logPath)
+        {
+            using (var stream = File.Open(logPath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite))
+            using (var streamReader = new StreamReader(stream))
+            {
+                var logContents = streamReader.ReadToEnd();
+                Assert.Contains("[aspnetcorev2.dll]", logContents);
+                Assert.Contains("[aspnetcorev2_inprocess.dll]", logContents);
+                Assert.Contains("Description: IIS AspNetCore Module V2. Commit:", logContents);
+                Assert.Contains("Description: IIS ASP.NET Core Module Request Handler. Commit:", logContents);
+            }
+        }
     }
 }

test/Common.FunctionalTests/Utilities/FunctionalTestsBase.cs

@@ -24,7 +24,7 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting
         {
             if (!parameters.EnvironmentVariables.ContainsKey(DebugEnvironmentVariable))
             {
-                parameters.EnvironmentVariables[DebugEnvironmentVariable] = "4";
+                parameters.EnvironmentVariables[DebugEnvironmentVariable] = "console";
             }
 
             if (parameters.ServerType == ServerType.IISExpress)

test/CommonLibTests/CommonLibTests.vcxproj

@@ -101,7 +101,7 @@
       <GenerateDebugInformation>true</GenerateDebugInformation>
       <SubSystem>Console</SubSystem>
       <AdditionalLibraryDirectories>..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\$(Configuration)\;</AdditionalLibraryDirectories>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;version.lib;%(AdditionalDependencies)</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
     <Lib>
@@ -128,7 +128,7 @@
       <GenerateDebugInformation>true</GenerateDebugInformation>
       <SubSystem>Console</SubSystem>
       <AdditionalLibraryDirectories>..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\x64\$(Configuration)\;</AdditionalLibraryDirectories>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;version.lib;%(AdditionalDependencies)</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
     <Lib>
@@ -155,7 +155,7 @@
       <OptimizeReferences>true</OptimizeReferences>
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <AdditionalLibraryDirectories>..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\$(Configuration)\;</AdditionalLibraryDirectories>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;version.lib;%(AdditionalDependencies)</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
     <Lib>
@@ -182,7 +182,7 @@
       <OptimizeReferences>true</OptimizeReferences>
       <EnableCOMDATFolding>true</EnableCOMDATFolding>
       <AdditionalLibraryDirectories>..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\x64\$(Configuration)\;</AdditionalLibraryDirectories>
-      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;%(AdditionalDependencies)</AdditionalDependencies>
+      <AdditionalDependencies>kernel32.lib;user32.lib;gdi32.lib;winspool.lib;comdlg32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;odbc32.lib;odbccp32.lib;inprocessapplication.obj;inprocesshandler.obj;ahadmin.lib;Rpcrt4.lib;inprocessapplicationbase.obj;stdafx.obj;version.lib;%(AdditionalDependencies)</AdditionalDependencies>
       <LinkTimeCodeGeneration>UseLinkTimeCodeGeneration</LinkTimeCodeGeneration>
     </Link>
     <Lib>

test/CommonLibTests/utility_tests.cpp

@@ -2,6 +2,7 @@
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
 #include "stdafx.h"
+#include "Environment.h"
 
 TEST(PassUnexpandedEnvString, ExpandsResult)
 {
@@ -39,3 +40,21 @@ TEST(PassUnexpandedEnvString, LongStringExpandsResults)
     //EXPECT_EQ(struStringValue.QueryStr(), struExpandedString.QueryStr());
     EXPECT_STREQ(struStringValue.QueryStr(), struExpandedString.QueryStr());
 }
+
+
+TEST(GetEnvironmentVariableValue, ReturnsCorrectLenght)
+{
+    SetEnvironmentVariable(L"RANDOM_ENV_VAR_1", L"test");
+
+    auto result = Environment::GetEnvironmentVariableValue(L"RANDOM_ENV_VAR_1");
+    EXPECT_TRUE(result.has_value());
+    EXPECT_EQ(result.value().length(), 4);
+    EXPECT_STREQ(result.value().c_str(), L"test");
+}
+
+
+TEST(GetEnvironmentVariableValue, ReturnsNulloptWhenNotFound)
+{
+    auto result = Environment::GetEnvironmentVariableValue(L"RANDOM_ENV_VAR_2");
+    EXPECT_FALSE(result.has_value());
+}

test/WebSites/InProcessWebSite/Properties/launchSettings.json

@@ -20,7 +20,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     },
     "ANCM IIS": {
@@ -34,7 +34,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     }
   }

test/WebSites/OutOfProcessWebSite/Properties/launchSettings.json

@@ -20,7 +20,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     },
     "ANCM IIS": {
@@ -34,7 +34,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     }
   }

test/WebSites/OverriddenServerWebSite/Properties/launchSettings.json

@@ -20,7 +20,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     },
     "ANCM IIS": {
@@ -34,7 +34,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     }
   }

test/WebSites/StartupExceptionWebSite/Properties/launchSettings.json

@@ -20,7 +20,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     },
     "ANCM IIS": {
@@ -34,7 +34,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     }
   }

test/WebSites/StressTestWebSite/Properties/launchSettings.json

@@ -20,7 +20,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     },
     "ANCM IIS": {
@@ -34,7 +34,7 @@
         "LAUNCHER_ARGS": "$(TargetPath)",
         "ASPNETCORE_ENVIRONMENT": "Development",
         "LAUNCHER_PATH": "$(DotNetPath)",
-        "ASPNETCORE_MODULE_DEBUG": "4"
+        "ASPNETCORE_MODULE_DEBUG": "console"
       }
     }
   }