From c6830afa55f1da9021679a2a36179399a5d21caa Mon Sep 17 00:00:00 2001 From: Pavel Krymets Date: Mon, 6 Aug 2018 17:20:44 -0700 Subject: [PATCH] Add default debug log file name and dll information to debug log (#1149) --- build/launchSettings.json | 4 +- .../Properties/launchSettings.json | 4 +- .../AspNetCore/AspNetCore.vcxproj | 8 +- .../AspNetCore/applicationinfo.cpp | 2 +- src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp | 4 +- .../CommonLib/Environment.cpp | 2 + .../CommonLib/debugutil.cpp | 246 +++++++++++------- src/AspNetCoreModuleV2/CommonLib/debugutil.h | 21 +- .../CommonLib/hostfxr_utility.cpp | 46 ++-- src/AspNetCoreModuleV2/CommonLib/utility.cpp | 2 +- src/AspNetCoreModuleV2/IISLib/dbgutil.h | 2 +- .../InProcessRequestHandler.vcxproj | 8 +- .../InProcessRequestHandler/dllmain.cpp | 10 +- .../OutOfProcessRequestHandler.vcxproj | 8 +- .../OutOfProcessRequestHandler/dllmain.cpp | 5 +- .../RequestHandlerLib/FileOutputManager.cpp | 2 +- .../IISDeployer.cs | 10 +- .../Inprocess/LoggingTests.cs | 69 +++-- .../Utilities/FunctionalTestsBase.cs | 2 +- test/CommonLibTests/CommonLibTests.vcxproj | 8 +- test/CommonLibTests/utility_tests.cpp | 19 ++ .../Properties/launchSettings.json | 4 +- .../Properties/launchSettings.json | 4 +- .../Properties/launchSettings.json | 4 +- .../Properties/launchSettings.json | 4 +- .../Properties/launchSettings.json | 4 +- 26 files changed, 300 insertions(+), 202 deletions(-) diff --git a/build/launchSettings.json b/build/launchSettings.json index 8cd1df05e6..38ae6c9d32 100644 --- a/build/launchSettings.json +++ b/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" } } } diff --git a/samples/NativeIISSample/Properties/launchSettings.json b/samples/NativeIISSample/Properties/launchSettings.json index 8cd1df05e6..38ae6c9d32 100644 --- a/samples/NativeIISSample/Properties/launchSettings.json +++ b/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" } } } diff --git a/src/AspNetCoreModuleV2/AspNetCore/AspNetCore.vcxproj b/src/AspNetCoreModuleV2/AspNetCore/AspNetCore.vcxproj index 4895850cbc..3c64a0dee2 100644 --- a/src/AspNetCoreModuleV2/AspNetCore/AspNetCore.vcxproj +++ b/src/AspNetCoreModuleV2/AspNetCore/AspNetCore.vcxproj @@ -102,7 +102,7 @@ Windows true - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib Source.def UseLinkTimeCodeGeneration @@ -138,7 +138,7 @@ Windows true - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib Source.def UseLinkTimeCodeGeneration @@ -178,7 +178,7 @@ true true Source.def - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib UseLinkTimeCodeGeneration @@ -217,7 +217,7 @@ true true Source.def - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib UseLinkTimeCodeGeneration diff --git a/src/AspNetCoreModuleV2/AspNetCore/applicationinfo.cpp b/src/AspNetCoreModuleV2/AspNetCore/applicationinfo.cpp index 8f94f23b08..3ac7246ca9 100644 --- a/src/AspNetCoreModuleV2/AspNetCore/applicationinfo.cpp +++ b/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()); diff --git a/src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp b/src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp index 5369fbc527..0526d1ccab 100644 --- a/src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp +++ b/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 diff --git a/src/AspNetCoreModuleV2/CommonLib/Environment.cpp b/src/AspNetCoreModuleV2/CommonLib/Environment.cpp index 316319207c..5e71216ce5 100644 --- a/src/AspNetCoreModuleV2/CommonLib/Environment.cpp +++ b/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; } diff --git a/src/AspNetCoreModuleV2/CommonLib/debugutil.cpp b/src/AspNetCoreModuleV2/CommonLib/debugutil.cpp index 9d7ec40ebb..4e9e73a936 100644 --- a/src/AspNetCoreModuleV2/CommonLib/debugutil.cpp +++ b/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 -DebugInitialize() +HRESULT +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 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(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 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() ); - } -} diff --git a/src/AspNetCoreModuleV2/CommonLib/debugutil.h b/src/AspNetCoreModuleV2/CommonLib/debugutil.h index b5f4075de2..b070794d0a 100644 --- a/src/AspNetCoreModuleV2/CommonLib/debugutil.h +++ b/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 +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, - ... - ); diff --git a/src/AspNetCoreModuleV2/CommonLib/hostfxr_utility.cpp b/src/AspNetCoreModuleV2/CommonLib/hostfxr_utility.cpp index ab827460bf..d0cb70dbb2 100644 --- a/src/AspNetCoreModuleV2/CommonLib/hostfxr_utility.cpp +++ b/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 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)) { diff --git a/src/AspNetCoreModuleV2/CommonLib/utility.cpp b/src/AspNetCoreModuleV2/CommonLib/utility.cpp index a82a7d18b3..2f8c25378c 100644 --- a/src/AspNetCoreModuleV2/CommonLib/utility.cpp +++ b/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 diff --git a/src/AspNetCoreModuleV2/IISLib/dbgutil.h b/src/AspNetCoreModuleV2/IISLib/dbgutil.h index bf745bfcd9..60365faad2 100644 --- a/src/AspNetCoreModuleV2/IISLib/dbgutil.h +++ b/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_; \ diff --git a/src/AspNetCoreModuleV2/InProcessRequestHandler/InProcessRequestHandler.vcxproj b/src/AspNetCoreModuleV2/InProcessRequestHandler/InProcessRequestHandler.vcxproj index addfb56214..0365f219d9 100644 --- a/src/AspNetCoreModuleV2/InProcessRequestHandler/InProcessRequestHandler.vcxproj +++ b/src/AspNetCoreModuleV2/InProcessRequestHandler/InProcessRequestHandler.vcxproj @@ -110,7 +110,7 @@ Windows true - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib Source.def UseLinkTimeCodeGeneration @@ -144,7 +144,7 @@ Windows true - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib Source.def UseLinkTimeCodeGeneration @@ -181,7 +181,7 @@ true true Source.def - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib UseLinkTimeCodeGeneration @@ -217,7 +217,7 @@ true true Source.def - 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) + kernel32.lib;user32.lib;advapi32.lib;shell32.lib;ole32.lib;oleaut32.lib;uuid.lib;ahadmin.lib;ws2_32.lib;iphlpapi.lib;version.lib UseLinkTimeCodeGeneration diff --git a/src/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp b/src/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp index e0ed004a67..ca40d04e36 100644 --- a/src/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp +++ b/src/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp @@ -40,7 +40,7 @@ InitializeGlobalConfiguration( g_pHttpServer = pServer; RETURN_IF_FAILED(ALLOC_CACHE_HANDLER::StaticInitialize()); RETURN_IF_FAILED(IN_PROCESS_HANDLER::StaticInitialize()); - + if (pServer->IsCommandLineLaunch()) { g_hEventLog = RegisterEventSource(NULL, ASPNETCORE_IISEXPRESS_EVENT_PROVIDER); @@ -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; @@ -107,18 +107,18 @@ CreateApplication( REQUESTHANDLER_CONFIG *pConfig = nullptr; RETURN_IF_FAILED(REQUESTHANDLER_CONFIG::CreateRequestHandlerConfig(pServer, pHttpApplication, &pConfig)); std::unique_ptr pRequestHandlerConfig(pConfig); - + BOOL disableStartupPage = pConfig->QueryDisableStartUpErrorPage(); auto pApplication = std::make_unique(*pServer, *pHttpApplication, std::move(pRequestHandlerConfig), pParameters, nParameters); - + // never create two inprocess applications in one process g_fInProcessApplicationCreated = true; if (FAILED_LOG(pApplication->LoadManagedApplication())) { // Set the currently running application to a fake application that returns startup exceptions. auto pErrorApplication = std::make_unique(*pServer, *pHttpApplication, disableStartupPage); - + RETURN_IF_FAILED(pErrorApplication->StartMonitoringAppOffline()); *ppApplication = pErrorApplication.release(); } diff --git a/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/OutOfProcessRequestHandler.vcxproj b/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/OutOfProcessRequestHandler.vcxproj index c34aa8d3a3..4fc4809b7f 100644 --- a/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/OutOfProcessRequestHandler.vcxproj +++ b/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/OutOfProcessRequestHandler.vcxproj @@ -110,7 +110,7 @@ Windows true - 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) + 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 Source.def UseLinkTimeCodeGeneration @@ -144,7 +144,7 @@ Windows true - 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) + 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 Source.def UseLinkTimeCodeGeneration @@ -181,7 +181,7 @@ true true Source.def - 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) + 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 UseLinkTimeCodeGeneration @@ -217,7 +217,7 @@ true true Source.def - 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) + 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 UseLinkTimeCodeGeneration diff --git a/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/dllmain.cpp b/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/dllmain.cpp index 710be75262..7df01e1ab1 100644 --- a/src/AspNetCoreModuleV2/OutOfProcessRequestHandler/dllmain.cpp +++ b/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; @@ -279,7 +278,7 @@ CreateApplication( { UNREFERENCED_PARAMETER(pParameters); UNREFERENCED_PARAMETER(nParameters); - + InitializeGlobalConfiguration(pServer); REQUESTHANDLER_CONFIG *pConfig = nullptr; diff --git a/src/AspNetCoreModuleV2/RequestHandlerLib/FileOutputManager.cpp b/src/AspNetCoreModuleV2/RequestHandlerLib/FileOutputManager.cpp index c5734eeb46..65e70757ab 100644 --- a/src/AspNetCoreModuleV2/RequestHandlerLib/FileOutputManager.cpp +++ b/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; diff --git a/src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeployer.cs b/src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeployer.cs index 4e6c71c1c4..acc4ae4cfb 100644 --- a/src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeployer.cs +++ b/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())); diff --git a/test/Common.FunctionalTests/Inprocess/LoggingTests.cs b/test/Common.FunctionalTests/Inprocess/LoggingTests.cs index 0ff23a392f..6710fb7f47 100644 --- a/test/Common.FunctionalTests/Inprocess/LoggingTests.cs +++ b/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(); - try - { - var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true); - deploymentParameters.EnvironmentVariables["ASPNETCORE_MODULE_DEBUG_FILE"] = tempFile; - deploymentParameters.AddDebugLogToWebConfig(tempFile); + var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true); + deploymentParameters.HandlerSettings["debugLevel"] = "file"; + deploymentParameters.HandlerSettings["debugFile"] = "debug.txt"; - 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); - Assert.Contains("[aspnetcorev2.dll]", logContents); - Assert.Contains("[aspnetcorev2_inprocess.dll]", logContents); - } - finally - { - File.Delete(tempFile); - } + [ConditionalFact] + public async Task StartupMessagesAreLoggedIntoDefaultDebugLogFile() + { + var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true); + deploymentParameters.HandlerSettings["debugLevel"] = "file"; + + 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); - Assert.Contains("[aspnetcorev2.dll]", logContents); - Assert.Contains("[aspnetcorev2_inprocess.dll]", logContents); + AssertLogs(secondTempFile); } 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); + } + } } } diff --git a/test/Common.FunctionalTests/Utilities/FunctionalTestsBase.cs b/test/Common.FunctionalTests/Utilities/FunctionalTestsBase.cs index 108e8ca84d..14b78a0d6e 100644 --- a/test/Common.FunctionalTests/Utilities/FunctionalTestsBase.cs +++ b/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) diff --git a/test/CommonLibTests/CommonLibTests.vcxproj b/test/CommonLibTests/CommonLibTests.vcxproj index c3947b45b3..d549a5679d 100644 --- a/test/CommonLibTests/CommonLibTests.vcxproj +++ b/test/CommonLibTests/CommonLibTests.vcxproj @@ -101,7 +101,7 @@ true Console ..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\$(Configuration)\; - 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) + 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) UseLinkTimeCodeGeneration @@ -128,7 +128,7 @@ true Console ..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\x64\$(Configuration)\; - 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) + 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) UseLinkTimeCodeGeneration @@ -155,7 +155,7 @@ true true ..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\$(Configuration)\; - 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) + 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) UseLinkTimeCodeGeneration @@ -182,7 +182,7 @@ true true ..\..\src\AspNetCoreModuleV2\InProcessRequestHandler\x64\$(Configuration)\; - 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) + 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) UseLinkTimeCodeGeneration diff --git a/test/CommonLibTests/utility_tests.cpp b/test/CommonLibTests/utility_tests.cpp index 0632543999..567e47762b 100644 --- a/test/CommonLibTests/utility_tests.cpp +++ b/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()); +} diff --git a/test/WebSites/InProcessWebSite/Properties/launchSettings.json b/test/WebSites/InProcessWebSite/Properties/launchSettings.json index 8cd1df05e6..38ae6c9d32 100644 --- a/test/WebSites/InProcessWebSite/Properties/launchSettings.json +++ b/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" } } } diff --git a/test/WebSites/OutOfProcessWebSite/Properties/launchSettings.json b/test/WebSites/OutOfProcessWebSite/Properties/launchSettings.json index 8cd1df05e6..38ae6c9d32 100644 --- a/test/WebSites/OutOfProcessWebSite/Properties/launchSettings.json +++ b/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" } } } diff --git a/test/WebSites/OverriddenServerWebSite/Properties/launchSettings.json b/test/WebSites/OverriddenServerWebSite/Properties/launchSettings.json index 8cd1df05e6..38ae6c9d32 100644 --- a/test/WebSites/OverriddenServerWebSite/Properties/launchSettings.json +++ b/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" } } } diff --git a/test/WebSites/StartupExceptionWebSite/Properties/launchSettings.json b/test/WebSites/StartupExceptionWebSite/Properties/launchSettings.json index 8cd1df05e6..38ae6c9d32 100644 --- a/test/WebSites/StartupExceptionWebSite/Properties/launchSettings.json +++ b/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" } } } diff --git a/test/WebSites/StressTestWebSite/Properties/launchSettings.json b/test/WebSites/StressTestWebSite/Properties/launchSettings.json index 8cd1df05e6..38ae6c9d32 100644 --- a/test/WebSites/StressTestWebSite/Properties/launchSettings.json +++ b/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" } } }