From 2cc108b2e1e81b999461f7b52e1ce96d80cb0939 Mon Sep 17 00:00:00 2001 From: Justin Kotalik Date: Thu, 6 Sep 2018 11:57:00 -0700 Subject: [PATCH] Write wide strings to stdout; cleanup logging providers; test utf8 (#1332) --- .../AspNetCore/HandlerResolver.cpp | 20 +-- src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp | 2 +- .../CommonLib/BaseOutputManager.h | 68 ++++++++++ .../CommonLib/CommonLib.vcxproj | 1 + .../CommonLib/FileOutputManager.cpp | 126 ++++++++---------- .../CommonLib/FileOutputManager.h | 31 ++--- .../CommonLib/IOutputManager.h | 8 +- .../CommonLib/LoggingHelpers.cpp | 9 +- .../CommonLib/LoggingHelpers.h | 4 +- .../CommonLib/NullOutputManager.h | 12 +- .../CommonLib/PipeOutputManager.cpp | 68 ++++------ .../CommonLib/PipeOutputManager.h | 20 +-- .../CommonLib/StdWrapper.cpp | 6 +- src/AspNetCoreModuleV2/CommonLib/StdWrapper.h | 2 +- .../CommonLib/StringHelpers.cpp | 23 ++++ .../CommonLib/StringHelpers.h | 3 + src/AspNetCoreModuleV2/CommonLib/exceptions.h | 1 + src/AspNetCoreModuleV2/CommonLib/resources.h | 4 +- .../inprocessapplication.cpp | 20 ++- .../inprocessapplication.h | 4 +- .../Inprocess/LoggingTests.cs | 47 +++++++ .../Inprocess/StartupExceptionTests.cs | 2 +- .../Utilities/EventLogHelpers.cs | 6 +- .../CommonLibTests/FileOutputManagerTests.cpp | 56 ++++---- .../CommonLibTests/PipeOutputManagerTests.cpp | 60 +++++---- .../StartupExceptionWebSite/Program.cs | 10 +- 26 files changed, 348 insertions(+), 265 deletions(-) create mode 100644 src/AspNetCoreModuleV2/CommonLib/BaseOutputManager.h diff --git a/src/AspNetCoreModuleV2/AspNetCore/HandlerResolver.cpp b/src/AspNetCoreModuleV2/AspNetCore/HandlerResolver.cpp index 4c98e60f11..7414f51161 100644 --- a/src/AspNetCoreModuleV2/AspNetCore/HandlerResolver.cpp +++ b/src/AspNetCoreModuleV2/AspNetCore/HandlerResolver.cpp @@ -15,6 +15,7 @@ #include "ConfigurationLoadException.h" #include "WebConfigConfigurationSource.h" #include "ModuleHelpers.h" +#include "BaseOutputManager.h" const PCWSTR HandlerResolver::s_pwzAspnetcoreInProcessRequestHandlerName = L"aspnetcorev2_inprocess.dll"; const PCWSTR HandlerResolver::s_pwzAspnetcoreOutOfProcessRequestHandlerName = L"aspnetcorev2_outofprocess.dll"; @@ -54,7 +55,7 @@ HandlerResolver::LoadRequestHandlerAssembly(const IHttpApplication &pApplication if (pConfiguration.QueryHostingModel() == APP_HOSTING_MODEL::HOSTING_IN_PROCESS) { std::unique_ptr options; - std::unique_ptr outputManager; + std::unique_ptr outputManager; RETURN_IF_FAILED(HOSTFXR_OPTIONS::Create( L"", @@ -72,28 +73,21 @@ HandlerResolver::LoadRequestHandlerAssembly(const IHttpApplication &pApplication pApplication.GetApplicationPhysicalPath(), outputManager)); - outputManager->Start(); + outputManager->TryStartRedirection(); hr = FindNativeAssemblyFromHostfxr(*options.get(), pstrHandlerDllName, handlerDllPath); - outputManager->Stop(); + + outputManager->TryStopRedirection(); if (FAILED(hr) && m_hHostFxrDll != nullptr) { - STRA content; - STRU struStdMsg; - - outputManager->GetStdOutContent(&content); - if (content.QueryCCH() > 0) - { - struStdMsg.CopyA(content.QueryStr()); - } + auto output = outputManager->GetStdOutContent(); EventLog::Error( ASPNETCORE_EVENT_GENERAL_ERROR, ASPNETCORE_EVENT_INPROCESS_RH_ERROR_MSG, handlerDllPath.empty()? s_pwzAspnetcoreInProcessRequestHandlerName : handlerDllPath.c_str(), - struStdMsg.QueryStr()); - + output.c_str()); } } else diff --git a/src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp b/src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp index 1f34270aee..4ec0d774dd 100644 --- a/src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp +++ b/src/AspNetCoreModuleV2/AspNetCore/dllmain.cpp @@ -101,7 +101,7 @@ HRESULT { g_hEventLog = RegisterEventSource(nullptr, ASPNETCORE_EVENT_PROVIDER); } - + // check whether the feature is disabled due to security reason if (RegOpenKeyEx(HKEY_LOCAL_MACHINE, L"SOFTWARE\\Microsoft\\IIS Extensions\\IIS AspNetCore Module V2\\Parameters", diff --git a/src/AspNetCoreModuleV2/CommonLib/BaseOutputManager.h b/src/AspNetCoreModuleV2/CommonLib/BaseOutputManager.h new file mode 100644 index 0000000000..32706b0192 --- /dev/null +++ b/src/AspNetCoreModuleV2/CommonLib/BaseOutputManager.h @@ -0,0 +1,68 @@ +// Copyright (c) .NET Foundation. All rights reserved. +// Licensed under the MIT License. See License.txt in the project root for license information. + +#pragma once +#include "IOutputManager.h" +#include "StdWrapper.h" +#include "EventLog.h" +#include "exceptions.h" +#include "StringHelpers.h" +#include "debugutil.h" + +class BaseOutputManager : + public IOutputManager +{ +public: + BaseOutputManager() : BaseOutputManager(/* fEnableNativeLogging */ true) {} + BaseOutputManager(bool enableNativeLogging) : + m_disposed(false), + stdoutWrapper(nullptr), + stderrWrapper(nullptr), + m_enableNativeRedirection(enableNativeLogging) + { + InitializeSRWLock(&m_srwLock); + } + ~BaseOutputManager() {} + + void + TryStartRedirection() + { + const auto startLambda = [&]() { this->Start(); }; + TryOperation(startLambda, L"Could not start stdout redirection in %s. Exception message: %s."); + } + + void + TryStopRedirection() + { + const auto stopLambda = [&]() { this->Stop(); }; + TryOperation(stopLambda, L"Could not stop stdout redirection in %s. Exception message: %s."); + } + +protected: + std::wstring m_stdOutContent; + bool m_disposed; + bool m_enableNativeRedirection; + SRWLOCK m_srwLock{}; + std::unique_ptr stdoutWrapper; + std::unique_ptr stderrWrapper; + + template + void + TryOperation(Functor func, + std::wstring exceptionMessage) + { + try + { + func(); + } + catch (std::runtime_error& exception) + { + EventLog::Warn(ASPNETCORE_EVENT_GENERAL_WARNING, exceptionMessage.c_str(), GetModuleName().c_str(), to_wide_string(exception.what(), GetConsoleOutputCP()).c_str()); + } + catch (...) + { + OBSERVE_CAUGHT_EXCEPTION(); + } + } +}; + diff --git a/src/AspNetCoreModuleV2/CommonLib/CommonLib.vcxproj b/src/AspNetCoreModuleV2/CommonLib/CommonLib.vcxproj index 5e430905e1..8628cc6529 100644 --- a/src/AspNetCoreModuleV2/CommonLib/CommonLib.vcxproj +++ b/src/AspNetCoreModuleV2/CommonLib/CommonLib.vcxproj @@ -199,6 +199,7 @@ + diff --git a/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.cpp b/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.cpp index fb95017af8..b0442e1a81 100644 --- a/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.cpp +++ b/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.cpp @@ -9,18 +9,18 @@ #include "SRWExclusiveLock.h" #include "file_utility.h" #include "StdWrapper.h" +#include "StringHelpers.h" extern HINSTANCE g_hModule; -FileOutputManager::FileOutputManager() : - FileOutputManager(/* fEnableNativeLogging */ true) { } +FileOutputManager::FileOutputManager(std::wstring pwzStdOutLogFileName, std::wstring pwzApplicationPath) : + FileOutputManager(pwzStdOutLogFileName, pwzApplicationPath, /* fEnableNativeLogging */ true) { } -FileOutputManager::FileOutputManager(bool fEnableNativeLogging) : +FileOutputManager::FileOutputManager(std::wstring pwzStdOutLogFileName, std::wstring pwzApplicationPath, bool fEnableNativeLogging) : + BaseOutputManager(fEnableNativeLogging), m_hLogFileHandle(INVALID_HANDLE_VALUE), - m_disposed(false), - stdoutWrapper(nullptr), - stderrWrapper(nullptr), - m_fEnableNativeRedirection(fEnableNativeLogging) + m_applicationPath(pwzApplicationPath), + m_stdOutLogFileName(pwzStdOutLogFileName) { InitializeSRWLock(&m_srwLock); } @@ -30,23 +30,13 @@ FileOutputManager::~FileOutputManager() FileOutputManager::Stop(); } -HRESULT -FileOutputManager::Initialize(PCWSTR pwzStdOutLogFileName, PCWSTR pwzApplicationPath) -{ - RETURN_IF_FAILED(m_wsApplicationPath.Copy(pwzApplicationPath)); - RETURN_IF_FAILED(m_wsStdOutLogFileName.Copy(pwzStdOutLogFileName)); - - return S_OK; -} - // Start redirecting stdout and stderr into the file handle. // Uses sttimer to continuously flush output into the file. -HRESULT +void FileOutputManager::Start() { SYSTEMTIME systemTime; SECURITY_ATTRIBUTES saAttr = { 0 }; - STRU struPath; FILETIME processCreationTime; FILETIME dummyFileTime; @@ -54,48 +44,38 @@ FileOutputManager::Start() // in the current process. if (!AllocConsole()) { - // ERROR_ACCESS_DENIED means there is a console already present. - if (GetLastError() != ERROR_ACCESS_DENIED) - { - RETURN_LAST_ERROR(); - } + THROW_LAST_ERROR_IF(GetLastError() != ERROR_ACCESS_DENIED); } // Concatenate the log file name and application path - RETURN_IF_FAILED(FILE_UTILITY::ConvertPathToFullPath( - m_wsStdOutLogFileName.QueryStr(), - m_wsApplicationPath.QueryStr(), - &struPath)); + auto logPath = m_applicationPath / m_stdOutLogFileName; + create_directories(logPath.parent_path()); - RETURN_IF_FAILED(FILE_UTILITY::EnsureDirectoryPathExist(struPath.QueryStr())); - - - // TODO fix string as it is incorrect - RETURN_LAST_ERROR_IF(!GetProcessTimes( + THROW_LAST_ERROR_IF(!GetProcessTimes( GetCurrentProcess(), &processCreationTime, &dummyFileTime, &dummyFileTime, &dummyFileTime)); - RETURN_LAST_ERROR_IF(!FileTimeToSystemTime(&processCreationTime, &systemTime)); - RETURN_IF_FAILED( - m_struLogFilePath.SafeSnwprintf(L"%s_%d%02d%02d%02d%02d%02d_%d.log", - struPath.QueryStr(), - systemTime.wYear, - systemTime.wMonth, - systemTime.wDay, - systemTime.wHour, - systemTime.wMinute, - systemTime.wSecond, - GetCurrentProcessId())); + THROW_LAST_ERROR_IF(!FileTimeToSystemTime(&processCreationTime, &systemTime)); + + m_logFilePath = format(L"%s_%d%02d%02d%02d%02d%02d_%d.log", + logPath.c_str(), + systemTime.wYear, + systemTime.wMonth, + systemTime.wDay, + systemTime.wHour, + systemTime.wMinute, + systemTime.wSecond, + GetCurrentProcessId()); saAttr.nLength = sizeof(SECURITY_ATTRIBUTES); saAttr.bInheritHandle = TRUE; saAttr.lpSecurityDescriptor = NULL; // Create the file with both READ and WRITE. - m_hLogFileHandle = CreateFileW(m_struLogFilePath.QueryStr(), + m_hLogFileHandle = CreateFileW(m_logFilePath.c_str(), FILE_READ_DATA | FILE_WRITE_DATA, FILE_SHARE_READ, &saAttr, @@ -103,22 +83,18 @@ FileOutputManager::Start() FILE_ATTRIBUTE_NORMAL, nullptr); - RETURN_LAST_ERROR_IF(m_hLogFileHandle == INVALID_HANDLE_VALUE); + THROW_LAST_ERROR_IF(m_hLogFileHandle == INVALID_HANDLE_VALUE); - stdoutWrapper = std::make_unique(stdout, STD_OUTPUT_HANDLE, m_hLogFileHandle, m_fEnableNativeRedirection); - stderrWrapper = std::make_unique(stderr, STD_ERROR_HANDLE, m_hLogFileHandle, m_fEnableNativeRedirection); + stdoutWrapper = std::make_unique(stdout, STD_OUTPUT_HANDLE, m_hLogFileHandle, m_enableNativeRedirection); + stderrWrapper = std::make_unique(stderr, STD_ERROR_HANDLE, m_hLogFileHandle, m_enableNativeRedirection); stdoutWrapper->StartRedirection(); stderrWrapper->StartRedirection(); - - return S_OK; } - -HRESULT +void FileOutputManager::Stop() { - STRA straStdOutput; CHAR pzFileContents[MAX_FILE_READ_SIZE] = { 0 }; DWORD dwNumBytesRead; LARGE_INTEGER li = { 0 }; @@ -128,75 +104,77 @@ FileOutputManager::Stop() if (m_disposed) { - return S_OK; + return; } SRWExclusiveLock lock(m_srwLock); if (m_disposed) { - return S_OK; + return; } m_disposed = true; if (m_hLogFileHandle == INVALID_HANDLE_VALUE) { - return HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND); + THROW_HR(HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND)); } FlushFileBuffers(m_hLogFileHandle); if (stdoutWrapper != nullptr) { - RETURN_IF_FAILED(stdoutWrapper->StopRedirection()); + THROW_IF_FAILED(stdoutWrapper->StopRedirection()); } if (stderrWrapper != nullptr) { - RETURN_IF_FAILED(stderrWrapper->StopRedirection()); + THROW_IF_FAILED(stderrWrapper->StopRedirection()); } // delete empty log file - handle = FindFirstFile(m_struLogFilePath.QueryStr(), &fileData); + handle = FindFirstFile(m_logFilePath.c_str(), &fileData); if (handle != INVALID_HANDLE_VALUE && handle != NULL && fileData.nFileSizeHigh == 0 && fileData.nFileSizeLow == 0) // skip check of nFileSizeHigh { FindClose(handle); - LOG_LAST_ERROR_IF(!DeleteFile(m_struLogFilePath.QueryStr())); + LOG_LAST_ERROR_IF(!DeleteFile(m_logFilePath.c_str())); + return; } // Read the first 30Kb from the file and store it in a buffer. // By doing this, we can close the handle to the file and be done with it. - RETURN_LAST_ERROR_IF(!GetFileSizeEx(m_hLogFileHandle, &li)); + THROW_LAST_ERROR_IF(!GetFileSizeEx(m_hLogFileHandle, &li)); - if (li.LowPart == 0 || li.HighPart > 0) + if (li.HighPart > 0) { - RETURN_HR(HRESULT_FROM_WIN32(ERROR_FILE_INVALID)); + THROW_HR(HRESULT_FROM_WIN32(ERROR_FILE_INVALID)); } dwFilePointer = SetFilePointer(m_hLogFileHandle, 0, NULL, FILE_BEGIN); - RETURN_LAST_ERROR_IF(dwFilePointer == INVALID_SET_FILE_POINTER); + THROW_LAST_ERROR_IF(dwFilePointer == INVALID_SET_FILE_POINTER); - RETURN_LAST_ERROR_IF(!ReadFile(m_hLogFileHandle, pzFileContents, MAX_FILE_READ_SIZE, &dwNumBytesRead, NULL)); + THROW_LAST_ERROR_IF(!ReadFile(m_hLogFileHandle, pzFileContents, MAX_FILE_READ_SIZE, &dwNumBytesRead, NULL)); - m_straFileContent.Copy(pzFileContents, dwNumBytesRead); + m_stdOutContent = to_wide_string(std::string(pzFileContents, dwNumBytesRead), GetConsoleOutputCP()); - // printf will fail in in full IIS - if (printf(m_straFileContent.QueryStr()) != -1) + auto content = GetStdOutContent(); + if (!content.empty()) { - // Need to flush contents for the new stdout and stderr - _flushall(); + // printf will fail in in full IIS + if (wprintf(content.c_str()) != -1) + { + // Need to flush contents for the new stdout and stderr + _flushall(); + } } - - return S_OK; } -bool FileOutputManager::GetStdOutContent(STRA* struStdOutput) +std::wstring FileOutputManager::GetStdOutContent() { - struStdOutput->Copy(m_straFileContent); - return m_straFileContent.QueryCCH() > 0; + return m_stdOutContent; } diff --git a/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.h b/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.h index 94f6e19176..435e07d4ff 100644 --- a/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.h +++ b/src/AspNetCoreModuleV2/CommonLib/FileOutputManager.h @@ -4,38 +4,27 @@ #pragma once #include "sttimer.h" -#include "IOutputManager.h" #include "HandleWrapper.h" #include "StdWrapper.h" #include "stringa.h" #include "stringu.h" +#include "BaseOutputManager.h" -class FileOutputManager : public IOutputManager +class FileOutputManager : public BaseOutputManager { - #define FILE_FLUSH_TIMEOUT 3000 #define MAX_FILE_READ_SIZE 30000 public: - FileOutputManager(); - FileOutputManager(bool fEnableNativeLogging); + FileOutputManager(std::wstring pwzApplicationPath, std::wstring pwzStdOutLogFileName); + FileOutputManager(std::wstring pwzApplicationPath, std::wstring pwzStdOutLogFileName, bool fEnableNativeLogging); ~FileOutputManager(); - HRESULT - Initialize(PCWSTR pwzStdOutLogFileName, PCWSTR pwzApplciationpath); - - virtual bool GetStdOutContent(STRA* struStdOutput) override; - virtual HRESULT Start() override; - virtual HRESULT Stop() override; + virtual std::wstring GetStdOutContent() override; + void Start() override; + void Stop() override; private: HandleWrapper m_hLogFileHandle; - STTIMER m_Timer; - STRU m_wsStdOutLogFileName; - STRU m_wsApplicationPath; - STRU m_struLogFilePath; - STRA m_straFileContent; - BOOL m_disposed; - BOOL m_fEnableNativeRedirection; - SRWLOCK m_srwLock{}; - std::unique_ptr stdoutWrapper; - std::unique_ptr stderrWrapper; + std::wstring m_stdOutLogFileName; + std::filesystem::path m_applicationPath; + std::filesystem::path m_logFilePath; }; diff --git a/src/AspNetCoreModuleV2/CommonLib/IOutputManager.h b/src/AspNetCoreModuleV2/CommonLib/IOutputManager.h index fec85cea96..4f19ad983d 100644 --- a/src/AspNetCoreModuleV2/CommonLib/IOutputManager.h +++ b/src/AspNetCoreModuleV2/CommonLib/IOutputManager.h @@ -10,18 +10,18 @@ class IOutputManager { public: virtual - HRESULT + void Start() = 0; virtual ~IOutputManager() = default; virtual - bool - GetStdOutContent(STRA* struStdOutput) = 0; + std::wstring + GetStdOutContent() = 0; virtual - HRESULT + void Stop() = 0; }; diff --git a/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.cpp b/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.cpp index 3d1aacf46d..0a33c4c145 100644 --- a/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.cpp +++ b/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.cpp @@ -3,7 +3,6 @@ #include "stdafx.h" #include "LoggingHelpers.h" -#include "IOutputManager.h" #include "FileOutputManager.h" #include "PipeOutputManager.h" #include "NullOutputManager.h" @@ -11,6 +10,9 @@ #include #include #include "ntassert.h" +#include "exceptions.h" +#include "EventLog.h" +#include "BaseOutputManager.h" HRESULT LoggingHelpers::CreateLoggingProvider( @@ -18,7 +20,7 @@ LoggingHelpers::CreateLoggingProvider( bool fEnableNativeLogging, PCWSTR pwzStdOutFileName, PCWSTR pwzApplicationPath, - std::unique_ptr& outputManager + std::unique_ptr& outputManager ) { HRESULT hr = S_OK; @@ -34,8 +36,7 @@ LoggingHelpers::CreateLoggingProvider( if (fIsLoggingEnabled) { - auto manager = std::make_unique(fEnableNativeLogging); - hr = manager->Initialize(pwzStdOutFileName, pwzApplicationPath); + auto manager = std::make_unique(pwzStdOutFileName, pwzApplicationPath, fEnableNativeLogging); outputManager = std::move(manager); } else if (!GetConsoleScreenBufferInfo(GetStdHandle(STD_OUTPUT_HANDLE), &dummy)) diff --git a/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.h b/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.h index 0c06f759cf..eff25b47d1 100644 --- a/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.h +++ b/src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.h @@ -3,7 +3,7 @@ #pragma once -#include "IOutputManager.h" +#include "BaseOutputManager.h" class LoggingHelpers { @@ -16,7 +16,7 @@ public: bool fEnableNativeLogging, PCWSTR pwzStdOutFileName, PCWSTR pwzApplicationPath, - std::unique_ptr& outputManager + std::unique_ptr& outputManager ); }; diff --git a/src/AspNetCoreModuleV2/CommonLib/NullOutputManager.h b/src/AspNetCoreModuleV2/CommonLib/NullOutputManager.h index 389f967b69..d9c63b682d 100644 --- a/src/AspNetCoreModuleV2/CommonLib/NullOutputManager.h +++ b/src/AspNetCoreModuleV2/CommonLib/NullOutputManager.h @@ -5,7 +5,7 @@ #include "stdafx.h" -class NullOutputManager : public IOutputManager +class NullOutputManager : public BaseOutputManager { public: @@ -13,19 +13,17 @@ public: ~NullOutputManager() = default; - HRESULT Start() + void Start() { - return S_OK; } - HRESULT Stop() + void Stop() { - return S_OK; } - bool GetStdOutContent(STRA*) + std::wstring GetStdOutContent() { - return false; + return L""; } }; diff --git a/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.cpp b/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.cpp index 60c2723fcb..8a9fe0612e 100644 --- a/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.cpp +++ b/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.cpp @@ -1,12 +1,14 @@ // Copyright (c) .NET Foundation. All rights reserved. // Licensed under the MIT License. See License.txt in the project root for license information. -#include "stdafx.h" #include "PipeOutputManager.h" -#include "exceptions.h" + +#include "stdafx.h" +#include "Exceptions.h" #include "SRWExclusiveLock.h" #include "StdWrapper.h" #include "ntassert.h" +#include "StringHelpers.h" #define LOG_IF_DUPFAIL(err) do { if (err == -1) { LOG_IF_FAILED(HRESULT_FROM_WIN32(_doserrno)); } } while (0, 0); #define LOG_IF_ERRNO(err) do { if (err != 0) { LOG_IF_FAILED(HRESULT_FROM_WIN32(_doserrno)); } } while (0, 0); @@ -17,16 +19,12 @@ PipeOutputManager::PipeOutputManager() } PipeOutputManager::PipeOutputManager(bool fEnableNativeLogging) : + BaseOutputManager(fEnableNativeLogging), m_hErrReadPipe(INVALID_HANDLE_VALUE), m_hErrWritePipe(INVALID_HANDLE_VALUE), m_hErrThread(nullptr), - m_dwStdErrReadTotal(0), - m_disposed(FALSE), - m_fEnableNativeRedirection(fEnableNativeLogging), - stdoutWrapper(nullptr), - stderrWrapper(nullptr) + m_numBytesReadTotal(0) { - InitializeSRWLock(&m_srwLock); } PipeOutputManager::~PipeOutputManager() @@ -37,7 +35,7 @@ PipeOutputManager::~PipeOutputManager() // Start redirecting stdout and stderr into a pipe // Continuously read the pipe on a background thread // until Stop is called. -HRESULT PipeOutputManager::Start() +void PipeOutputManager::Start() { SECURITY_ATTRIBUTES saAttr = { 0 }; HANDLE hStdErrReadPipe; @@ -50,17 +48,17 @@ HRESULT PipeOutputManager::Start() // ERROR_ACCESS_DENIED means there is a console already present. if (GetLastError() != ERROR_ACCESS_DENIED) { - RETURN_LAST_ERROR(); + THROW_LAST_ERROR(); } } - RETURN_LAST_ERROR_IF(!CreatePipe(&hStdErrReadPipe, &hStdErrWritePipe, &saAttr, 0 /*nSize*/)); + THROW_LAST_ERROR_IF(!CreatePipe(&hStdErrReadPipe, &hStdErrWritePipe, &saAttr, 0 /*nSize*/)); m_hErrReadPipe = hStdErrReadPipe; m_hErrWritePipe = hStdErrWritePipe; - stdoutWrapper = std::make_unique(stdout, STD_OUTPUT_HANDLE, hStdErrWritePipe, m_fEnableNativeRedirection); - stderrWrapper = std::make_unique(stderr, STD_ERROR_HANDLE, hStdErrWritePipe, m_fEnableNativeRedirection); + stdoutWrapper = std::make_unique(stdout, STD_OUTPUT_HANDLE, hStdErrWritePipe, m_enableNativeRedirection); + stderrWrapper = std::make_unique(stderr, STD_ERROR_HANDLE, hStdErrWritePipe, m_enableNativeRedirection); LOG_IF_FAILED(stdoutWrapper->StartRedirection()); LOG_IF_FAILED(stderrWrapper->StartRedirection()); @@ -74,9 +72,7 @@ HRESULT PipeOutputManager::Start() 0, // default creation flags nullptr); // receive thread identifier - RETURN_LAST_ERROR_IF_NULL(m_hErrThread); - - return S_OK; + THROW_LAST_ERROR_IF_NULL(m_hErrThread); } // Stop redirecting stdout and stderr into a pipe @@ -84,21 +80,20 @@ HRESULT PipeOutputManager::Start() // and prints any output that was captured in the pipe. // If more than 30Kb was written to the pipe, that output will // be thrown away. -HRESULT PipeOutputManager::Stop() +void PipeOutputManager::Stop() { DWORD dwThreadStatus = 0; - STRA straStdOutput; if (m_disposed) { - return S_OK; + return; } SRWExclusiveLock lock(m_srwLock); if (m_disposed) { - return S_OK; + return; } m_disposed = true; @@ -108,7 +103,7 @@ HRESULT PipeOutputManager::Stop() if (m_hErrWritePipe != INVALID_HANDLE_VALUE) { // Flush the pipe writer before closing to capture all output - RETURN_LAST_ERROR_IF(!FlushFileBuffers(m_hErrWritePipe)); + THROW_LAST_ERROR_IF(!FlushFileBuffers(m_hErrWritePipe)); CloseHandle(m_hErrWritePipe); m_hErrWritePipe = INVALID_HANDLE_VALUE; } @@ -163,33 +158,22 @@ HRESULT PipeOutputManager::Stop() // If we captured any output, relog it to the original stdout // Useful for the IIS Express scenario as it is running with stdout and stderr - if (GetStdOutContent(&straStdOutput)) + m_stdOutContent = to_wide_string(std::string(m_pipeContents, m_numBytesReadTotal), GetConsoleOutputCP()); + + if (!m_stdOutContent.empty()) { // printf will fail in in full IIS - if (printf(straStdOutput.QueryStr()) != -1) + if (wprintf(m_stdOutContent.c_str()) != -1) { // Need to flush contents for the new stdout and stderr _flushall(); } } - - return S_OK; } -bool PipeOutputManager::GetStdOutContent(STRA* straStdOutput) +std::wstring PipeOutputManager::GetStdOutContent() { - bool fLogged = false; - - // TODO consider returning the file contents rather than copying. - if (m_dwStdErrReadTotal > 0) - { - if (SUCCEEDED(straStdOutput->Copy(m_pzFileContents, m_dwStdErrReadTotal))) - { - fLogged = TRUE; - } - } - - return fLogged; + return m_stdOutContent; } void @@ -211,13 +195,13 @@ PipeOutputManager::ReadStdErrHandleInternal() { // Fill a maximum of MAX_PIPE_READ_SIZE into a buffer. if (ReadFile(m_hErrReadPipe, - &m_pzFileContents[m_dwStdErrReadTotal], - MAX_PIPE_READ_SIZE - m_dwStdErrReadTotal, + &m_pipeContents[m_numBytesReadTotal], + MAX_PIPE_READ_SIZE - m_numBytesReadTotal, &dwNumBytesRead, nullptr)) { - m_dwStdErrReadTotal += dwNumBytesRead; - if (m_dwStdErrReadTotal >= MAX_PIPE_READ_SIZE) + m_numBytesReadTotal += dwNumBytesRead; + if (m_numBytesReadTotal >= MAX_PIPE_READ_SIZE) { break; } diff --git a/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.h b/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.h index 0b51ff4038..3a1a74cd43 100644 --- a/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.h +++ b/src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.h @@ -3,11 +3,11 @@ #pragma once -#include "IOutputManager.h" #include "StdWrapper.h" #include "stringu.h" +#include "BaseOutputManager.h" -class PipeOutputManager : public IOutputManager +class PipeOutputManager : public BaseOutputManager { // Timeout to be used if a thread never exits #define PIPE_OUTPUT_THREAD_TIMEOUT 2000 @@ -19,9 +19,9 @@ public: PipeOutputManager(bool fEnableNativeLogging); ~PipeOutputManager(); - HRESULT Start() override; - HRESULT Stop() override; - bool GetStdOutContent(STRA* straStdOutput) override; + void Start() override; + void Stop() override; + std::wstring GetStdOutContent() override; // Thread functions void ReadStdErrHandleInternal(); @@ -32,13 +32,7 @@ private: HANDLE m_hErrReadPipe; HANDLE m_hErrWritePipe; - STRU m_struLogFilePath; HANDLE m_hErrThread; - CHAR m_pzFileContents[MAX_PIPE_READ_SIZE] = { 0 }; - DWORD m_dwStdErrReadTotal; - SRWLOCK m_srwLock {}; - BOOL m_disposed; - BOOL m_fEnableNativeRedirection; - std::unique_ptr stdoutWrapper; - std::unique_ptr stderrWrapper; + CHAR m_pipeContents[MAX_PIPE_READ_SIZE] = { 0 }; + DWORD m_numBytesReadTotal; }; diff --git a/src/AspNetCoreModuleV2/CommonLib/StdWrapper.cpp b/src/AspNetCoreModuleV2/CommonLib/StdWrapper.cpp index 432e48a163..809864f06a 100644 --- a/src/AspNetCoreModuleV2/CommonLib/StdWrapper.cpp +++ b/src/AspNetCoreModuleV2/CommonLib/StdWrapper.cpp @@ -12,7 +12,7 @@ StdWrapper::StdWrapper(FILE* stdStream, DWORD stdHandleNumber, HANDLE handleToRe : m_previousFileDescriptor(0), m_stdStream(stdStream), m_stdHandleNumber(stdHandleNumber), - m_fEnableNativeRedirection(fEnableNativeRedirection), + m_enableNativeRedirection(fEnableNativeRedirection), m_handleToRedirectTo(handleToRedirectTo), m_redirectedFile(nullptr) { @@ -48,7 +48,7 @@ StdWrapper::StartRedirection() m_previousFileDescriptor = _dup(_fileno(m_stdStream)); } - if (!m_fEnableNativeRedirection) + if (!m_enableNativeRedirection) { RETURN_LAST_ERROR_IF(!SetStdHandle(m_stdHandleNumber, m_handleToRedirectTo)); @@ -122,7 +122,7 @@ StdWrapper::StopRedirection() const RETURN_LAST_ERROR_IF(!SetStdHandle(m_stdHandleNumber, reinterpret_cast(_get_osfhandle(m_previousFileDescriptor)))); - if (!m_fEnableNativeRedirection) + if (!m_enableNativeRedirection) { return S_OK; } diff --git a/src/AspNetCoreModuleV2/CommonLib/StdWrapper.h b/src/AspNetCoreModuleV2/CommonLib/StdWrapper.h index f03b2ff060..17373f093e 100644 --- a/src/AspNetCoreModuleV2/CommonLib/StdWrapper.h +++ b/src/AspNetCoreModuleV2/CommonLib/StdWrapper.h @@ -18,7 +18,7 @@ private: int m_previousFileDescriptor; FILE* m_stdStream; DWORD m_stdHandleNumber; - BOOL m_fEnableNativeRedirection; + BOOL m_enableNativeRedirection; HANDLE m_handleToRedirectTo; FILE* m_redirectedFile; }; diff --git a/src/AspNetCoreModuleV2/CommonLib/StringHelpers.cpp b/src/AspNetCoreModuleV2/CommonLib/StringHelpers.cpp index 5e251f69ed..736597b9a5 100644 --- a/src/AspNetCoreModuleV2/CommonLib/StringHelpers.cpp +++ b/src/AspNetCoreModuleV2/CommonLib/StringHelpers.cpp @@ -2,6 +2,7 @@ // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. #include "StringHelpers.h" +#include "exceptions.h" bool ends_with(const std::wstring &source, const std::wstring &suffix, bool ignoreCase) { @@ -18,3 +19,25 @@ bool equals_ignore_case(const std::wstring& s1, const std::wstring& s2) { return CSTR_EQUAL == CompareStringOrdinal(s1.c_str(), static_cast(s1.length()), s2.c_str(), static_cast(s2.length()), true); } + +std::wstring to_wide_string(const std::string &source, const unsigned int codePage) +{ + // MultiByteToWideChar returns 0 on failure, which is also the same return value + // for empty strings. Preemptive return. + if (source.length() == 0) + { + return L""; + } + + std::wstring destination; + + int nChars = MultiByteToWideChar(codePage, 0, source.data(), static_cast(source.length()), NULL, 0); + THROW_LAST_ERROR_IF(nChars == 0); + + destination.resize(nChars); + + nChars = MultiByteToWideChar(codePage, 0, source.data(), static_cast(source.length()), destination.data(), nChars); + THROW_LAST_ERROR_IF(nChars == 0); + + return destination; +} diff --git a/src/AspNetCoreModuleV2/CommonLib/StringHelpers.h b/src/AspNetCoreModuleV2/CommonLib/StringHelpers.h index e6cda03ff7..40b3b821c7 100644 --- a/src/AspNetCoreModuleV2/CommonLib/StringHelpers.h +++ b/src/AspNetCoreModuleV2/CommonLib/StringHelpers.h @@ -11,6 +11,9 @@ bool ends_with(const std::wstring &source, const std::wstring &suffix, bool igno [[nodiscard]] bool equals_ignore_case(const std::wstring& s1, const std::wstring& s2); +[[nodiscard]] +std::wstring to_wide_string(const std::string &source, const unsigned int codePage); + template [[nodiscard]] std::wstring format(const std::wstring& format, Args ... args) diff --git a/src/AspNetCoreModuleV2/CommonLib/exceptions.h b/src/AspNetCoreModuleV2/CommonLib/exceptions.h index 109f76ce87..f79b9e99e5 100644 --- a/src/AspNetCoreModuleV2/CommonLib/exceptions.h +++ b/src/AspNetCoreModuleV2/CommonLib/exceptions.h @@ -59,6 +59,7 @@ #define FINISHED_LAST_ERROR_IF(condition) do { if (condition) { hr = LogLastError(LOCATION_INFO); _GOTO_FINISHED(); }} while (0, 0) #define FINISHED_LAST_ERROR_IF_NULL(ptr) do { if ((ptr) == nullptr) { hr = LogLastError(LOCATION_INFO); _GOTO_FINISHED(); }} while (0, 0) +#define THROW_HR(hr) do { _HR_RET(hr); ThrowResultException(LOCATION_INFO, LogHResultFailed(LOCATION_INFO, __hrRet)); } while (0, 0) #define THROW_LAST_ERROR() do { ThrowResultException(LOCATION_INFO, LogLastError(LOCATION_INFO)); } while (0, 0) #define THROW_IF_FAILED(hr) do { _HR_RET(hr); if (FAILED(__hrRet)) { ThrowResultException(LOCATION_INFO, __hrRet); }} while (0, 0) #define THROW_LAST_ERROR_IF(condition) do { if (condition) { ThrowResultException(LOCATION_INFO, LogLastError(LOCATION_INFO)); }} while (0, 0) diff --git a/src/AspNetCoreModuleV2/CommonLib/resources.h b/src/AspNetCoreModuleV2/CommonLib/resources.h index 790e849516..d44c6a25f8 100644 --- a/src/AspNetCoreModuleV2/CommonLib/resources.h +++ b/src/AspNetCoreModuleV2/CommonLib/resources.h @@ -39,8 +39,8 @@ #define ASPNETCORE_EVENT_RECYCLE_FAILURE_CONFIGURATION_MSG L"Failed to recycle application due to a configuration change at '%s'. Recycling worker process." #define ASPNETCORE_EVENT_MODULE_DISABLED_MSG L"AspNetCore Module is disabled" #define ASPNETCORE_EVENT_HOSTFXR_DLL_INVALID_VERSION_MSG L"Hostfxr version used does not support 'hostfxr_get_native_search_directories', update the version of hostfxr to a higher version. Path to hostfxr: '%s'." -#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_MSG L"Application '%s' with physical root '%s' hit unexpected managed exception, exception code = '0x%x. Please check the stderr logs for more information." -#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_STDOUT_MSG L"Application '%s' with physical root '%s' hit unexpected managed exception, exception code = '0x%x. Last 4KB characters of captured stdout and stderr logs:\r\n%s" +#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_MSG L"Application '%s' with physical root '%s' hit unexpected managed exception, exception code = '0x%x'. Please check the stderr logs for more information." +#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_STDOUT_MSG L"Application '%s' with physical root '%s' hit unexpected managed exception, exception code = '0x%x'. Last 4KB characters of captured stdout and stderr logs:\r\n%s" #define ASPNETCORE_EVENT_INPROCESS_RH_ERROR_MSG L"Could not find the assembly '%s' for in-process application. Please confirm the Microsoft.AspNetCore.Server.IIS package is referenced in your application. Captured output: %s" #define ASPNETCORE_EVENT_OUT_OF_PROCESS_RH_MISSING_MSG L"Could not find the assembly '%s' for out-of-process application. Please confirm the assembly is installed correctly for IIS or IISExpress." #define ASPNETCORE_EVENT_INPROCESS_START_SUCCESS_MSG L"Application '%s' started the coreclr in-process successfully." diff --git a/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp b/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp index 942bfe44b0..6f37a1a3b9 100644 --- a/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp +++ b/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp @@ -207,7 +207,7 @@ IN_PROCESS_APPLICATION::ExecuteApplication() QueryApplicationPhysicalPath().c_str(), m_pLoggerProvider)); - LOG_IF_FAILED(m_pLoggerProvider->Start()); + m_pLoggerProvider->TryStartRedirection(); } // There can only ever be a single instance of .NET Core @@ -246,7 +246,7 @@ IN_PROCESS_APPLICATION::ExecuteApplication() // At this point CLR thread either finished or timed out, abandon it. m_clrThread.detach(); - LOG_IF_FAILED(m_pLoggerProvider->Stop()); + m_pLoggerProvider->TryStopRedirection(); if (m_fStopCalled) { @@ -391,8 +391,6 @@ IN_PROCESS_APPLICATION::ExecuteClr(const std::shared_ptr& con VOID IN_PROCESS_APPLICATION::ClrThreadEntryPoint(const std::shared_ptr &context) { - LOG_INFO(L"Starting CLR thread"); - // Keep aspnetcorev2_inprocess.dll loaded while this thread is running // this is required because thread might be abandoned HandleWrapper moduleHandle; @@ -441,14 +439,11 @@ IN_PROCESS_APPLICATION::SetEnvironmentVariablesOnWorkerProcess() VOID IN_PROCESS_APPLICATION::UnexpectedThreadExit(const ExecuteClrContext& context) const { - STRA straStdErrOutput; - STRU struStdMsg; - auto hasStdOut = m_pLoggerProvider->GetStdOutContent(&straStdErrOutput) && - SUCCEEDED(struStdMsg.CopyA(straStdErrOutput.QueryStr())); + auto content = m_pLoggerProvider->GetStdOutContent(); if (context.m_exceptionCode != 0) { - if (hasStdOut) + if (!content.empty()) { EventLog::Error( ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION, @@ -456,7 +451,7 @@ IN_PROCESS_APPLICATION::UnexpectedThreadExit(const ExecuteClrContext& context) c QueryApplicationId().c_str(), QueryApplicationPhysicalPath().c_str(), context.m_exceptionCode, - struStdMsg.QueryStr()); + content.c_str()); } else { @@ -476,7 +471,8 @@ IN_PROCESS_APPLICATION::UnexpectedThreadExit(const ExecuteClrContext& context) c // This will be a common place for errors as it means the hostfxr_main returned // or there was an exception. // - if (hasStdOut) + + if (!content.empty()) { EventLog::Error( ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_STDOUT, @@ -484,7 +480,7 @@ IN_PROCESS_APPLICATION::UnexpectedThreadExit(const ExecuteClrContext& context) c QueryApplicationId().c_str(), QueryApplicationPhysicalPath().c_str(), context.m_exitCode, - struStdMsg.QueryStr()); + content.c_str()); } else { diff --git a/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h b/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h index cab7a49e9b..e2488d71e7 100644 --- a/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h +++ b/src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h @@ -5,8 +5,8 @@ #include #include "InProcessApplicationBase.h" -#include "IOutputManager.h" #include "InProcessOptions.h" +#include "BaseOutputManager.h" class IN_PROCESS_HANDLER; typedef REQUEST_NOTIFICATION_STATUS(WINAPI * PFN_REQUEST_HANDLER) (IN_PROCESS_HANDLER* pInProcessHandler, void* pvRequestHandlerContext); @@ -155,7 +155,7 @@ private: static IN_PROCESS_APPLICATION* s_Application; - std::unique_ptr m_pLoggerProvider; + std::unique_ptr m_pLoggerProvider; inline static const LPCSTR s_exeLocationParameterName = "InProcessExeLocation"; diff --git a/test/Common.FunctionalTests/Inprocess/LoggingTests.cs b/test/Common.FunctionalTests/Inprocess/LoggingTests.cs index e574d4f96f..d26088b018 100644 --- a/test/Common.FunctionalTests/Inprocess/LoggingTests.cs +++ b/test/Common.FunctionalTests/Inprocess/LoggingTests.cs @@ -4,6 +4,7 @@ using System; using System.IO; using System.Linq; +using System.Net; using System.Threading.Tasks; using Microsoft.AspNetCore.Server.IIS.FunctionalTests.Utilities; using Microsoft.AspNetCore.Server.IntegrationTesting; @@ -68,6 +69,10 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests var deploymentResult = await DeployAsync(deploymentParameters); await Helpers.AssertStarts(deploymentResult, "HelloWorld"); + + StopServer(); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Could not start stdout redirection in (.*)aspnetcorev2.dll. Exception message: HRESULT 0x80070003"); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, "Could not stop stdout redirection in (.*)aspnetcorev2.dll. Exception message: HRESULT 0x80070002"); } [ConditionalFact] @@ -222,6 +227,48 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests Assert.Contains("FORWARDING_HANDLER::", logContents); } + [ConditionalFact] + public async Task CheckUnicodePipe() + { + var path = "CheckConsoleFunctions"; + var deploymentParameters = _fixture.GetBaseDeploymentParameters(_fixture.StartupExceptionWebsite, publish: true); + deploymentParameters.TransformArguments((a, _) => $"{a} {path}"); + + var deploymentResult = await DeployAsync(deploymentParameters); + + var response = await deploymentResult.HttpClient.GetAsync(path); + + Assert.Equal(HttpStatusCode.InternalServerError, response.StatusCode); + + StopServer(); + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", "(.*)彡⾔(.*)")); + } + + [ConditionalFact] + public async Task CheckUTF8File() + { + var path = "CheckConsoleFunctions"; + + var deploymentParameters = _fixture.GetBaseDeploymentParameters(_fixture.StartupExceptionWebsite, publish: true); + deploymentParameters.TransformArguments((a, _) => $"{a} {path}"); + + deploymentParameters.EnableLogging(_logFolderPath); + + var deploymentResult = await DeployAsync(deploymentParameters); + + var response = await deploymentResult.HttpClient.GetAsync(path); + + Assert.Equal(HttpStatusCode.InternalServerError, response.StatusCode); + + StopServer(); + + var contents = File.ReadAllText(Helpers.GetExpectedLogName(deploymentResult, _logFolderPath)); + + Assert.Contains("彡⾔", contents); + + EventLogHelpers.VerifyEventLogEvent(deploymentResult, EventLogHelpers.InProcessThreadExitStdOut(deploymentResult, "12", "(.*)彡⾔(.*)")); + } + private static string ReadLogs(string logPath) { using (var stream = File.Open(logPath, FileMode.Open, FileAccess.Read, FileShare.ReadWrite)) diff --git a/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs b/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs index dbbf09f1ac..ef5b6a3a2c 100644 --- a/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs +++ b/test/Common.FunctionalTests/Inprocess/StartupExceptionTests.cs @@ -48,7 +48,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests await AssertFailsToStart(deploymentParameters); - Assert.Contains(TestSink.Writes, context => context.Message.Contains(new string('a', 4096))); + Assert.Contains(TestSink.Writes, context => context.Message.Contains(new string('a', 30000))); } [ConditionalFact] diff --git a/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs b/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs index 4fb129feaf..e385f281d8 100644 --- a/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs +++ b/test/Common.FunctionalTests/Utilities/EventLogHelpers.cs @@ -121,7 +121,11 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests { return $"Application '/LM/W3SVC/1/ROOT' with physical root '{EscapedContentRoot(deploymentResult)}' hit unexpected managed background thread exit, exit code = '{code}'."; } - + public static string InProcessThreadExitStdOut(IISDeploymentResult deploymentResult, string code, string output) + { + return $"Application '/LM/W3SVC/1/ROOT' with physical root '{EscapedContentRoot(deploymentResult)}' hit unexpected managed background thread exit, exit code = '{code}'. Last 4KB characters of captured stdout and stderr logs:\r\n{output}"; + } + public static string FailedToStartApplication(IISDeploymentResult deploymentResult, string code) { return $"Failed to start application '/LM/W3SVC/1/ROOT', ErrorCode '{code}'."; diff --git a/test/CommonLibTests/FileOutputManagerTests.cpp b/test/CommonLibTests/FileOutputManagerTests.cpp index bba9e22704..66a9ff7f0b 100644 --- a/test/CommonLibTests/FileOutputManagerTests.cpp +++ b/test/CommonLibTests/FileOutputManagerTests.cpp @@ -33,9 +33,8 @@ namespace FileOutManagerStartupTests PCWSTR expected = L"test"; auto tempDirectory = TempDirectory(); - FileOutputManager* pManager = new FileOutputManager; + FileOutputManager* pManager = new FileOutputManager(fileNamePrefix, tempDirectory.path()); - pManager->Initialize(fileNamePrefix.c_str(), tempDirectory.path().c_str()); { FileManagerWrapper wrapper(pManager); @@ -69,89 +68,84 @@ namespace FileOutManagerOutputTests { TEST(FileOutManagerOutputTest, StdOut) { - PCSTR expected = "test"; + PCWSTR expected = L"test"; auto tempDirectory = TempDirectory(); - FileOutputManager* pManager = new FileOutputManager; - pManager->Initialize(L"", tempDirectory.path().c_str()); + FileOutputManager* pManager = new FileOutputManager(L"", tempDirectory.path()); { FileManagerWrapper wrapper(pManager); - fprintf(stdout, expected); + fwprintf(stdout, expected); pManager->Stop(); - STRA straContent; - ASSERT_TRUE(pManager->GetStdOutContent(&straContent)); + auto output = pManager->GetStdOutContent(); + ASSERT_FALSE(output.empty()); - ASSERT_STREQ(straContent.QueryStr(), expected); + ASSERT_STREQ(output.c_str(), expected); } } TEST(FileOutManagerOutputTest, StdErr) { - PCSTR expected = "test"; + PCWSTR expected = L"test"; auto tempDirectory = TempDirectory(); - FileOutputManager* pManager = new FileOutputManager; - pManager->Initialize(L"", tempDirectory.path().c_str()); + FileOutputManager* pManager = new FileOutputManager(L"", tempDirectory.path().c_str()); { FileManagerWrapper wrapper(pManager); - fprintf(stderr, expected); + fwprintf(stderr, expected); pManager->Stop(); - STRA straContent; - ASSERT_TRUE(pManager->GetStdOutContent(&straContent)); + auto output = pManager->GetStdOutContent(); + ASSERT_FALSE(output.empty()); - ASSERT_STREQ(straContent.QueryStr(), expected); + ASSERT_STREQ(output.c_str(), expected); } } TEST(FileOutManagerOutputTest, CapAt30KB) { - PCSTR expected = "hello world"; + PCWSTR expected = L"hello world"; auto tempDirectory = TempDirectory(); - FileOutputManager* pManager = new FileOutputManager; - pManager->Initialize(L"", tempDirectory.path().c_str()); + FileOutputManager* pManager = new FileOutputManager(L"", tempDirectory.path()); { FileManagerWrapper wrapper(pManager); for (int i = 0; i < 3000; i++) { - printf(expected); + wprintf(expected); } pManager->Stop(); - STRA straContent; - ASSERT_TRUE(pManager->GetStdOutContent(&straContent)); + auto output = pManager->GetStdOutContent(); + ASSERT_FALSE(output.empty()); - ASSERT_EQ(straContent.QueryCCH(), 30000); + ASSERT_EQ(output.size(), 30000); } } - TEST(FileOutManagerOutputTest, StartStopRestoresCorrectly) { - PCSTR expected = "test"; + PCWSTR expected = L"test"; auto tempDirectory = TempDirectory(); for (int i = 0; i < 10; i++) { - FileOutputManager* pManager = new FileOutputManager; - pManager->Initialize(L"", tempDirectory.path().c_str()); + FileOutputManager* pManager = new FileOutputManager(L"", tempDirectory.path()); { FileManagerWrapper wrapper(pManager); - printf(expected); + wprintf(expected); pManager->Stop(); - STRA straContent; - ASSERT_TRUE(pManager->GetStdOutContent(&straContent)); + auto output = pManager->GetStdOutContent(); + ASSERT_FALSE(output.empty()); - ASSERT_STREQ(straContent.QueryStr(), expected); + ASSERT_STREQ(output.c_str(), expected); } } } diff --git a/test/CommonLibTests/PipeOutputManagerTests.cpp b/test/CommonLibTests/PipeOutputManagerTests.cpp index 20609adf72..385d6df9e0 100644 --- a/test/CommonLibTests/PipeOutputManagerTests.cpp +++ b/test/CommonLibTests/PipeOutputManagerTests.cpp @@ -26,40 +26,49 @@ namespace PipeOutputManagerTests TEST(PipeManagerOutputTest, StdOut) { PCWSTR expected = L"test"; - STRA output; PipeOutputManager* pManager = new PipeOutputManager(true); - ASSERT_EQ(S_OK, pManager->Start()); + pManager->Start(); fwprintf(stdout, expected); + pManager->Stop(); - ASSERT_EQ(S_OK, pManager->Stop()); + auto output = pManager->GetStdOutContent(); + ASSERT_STREQ(output.c_str(), expected); + delete pManager; + } - pManager->GetStdOutContent(&output); - ASSERT_STREQ(output.QueryStr(), "test"); + TEST(PipeManagerOutputTest, StdOutMultiToWide) + { + PipeOutputManager* pManager = new PipeOutputManager(true); + + pManager->Start(); + fprintf(stdout, "test"); + pManager->Stop(); + + auto output = pManager->GetStdOutContent(); + ASSERT_STREQ(output.c_str(), L"test"); delete pManager; } TEST(PipeManagerOutputTest, StdErr) { PCWSTR expected = L"test"; - STRA output; PipeOutputManager* pManager = new PipeOutputManager(); - ASSERT_EQ(S_OK, pManager->Start()); + pManager->Start(); fwprintf(stderr, expected); - ASSERT_EQ(S_OK, pManager->Stop()); + pManager->Stop(); - pManager->GetStdOutContent(&output); - ASSERT_STREQ(output.QueryStr(), "test"); + auto output = pManager->GetStdOutContent(); + ASSERT_STREQ(output.c_str(), expected); delete pManager; } TEST(PipeManagerOutputTest, CheckMaxPipeSize) { std::wstring test; - STRA output; for (int i = 0; i < 3000; i++) { test.append(L"hello world"); @@ -67,14 +76,15 @@ namespace PipeOutputManagerTests PipeOutputManager* pManager = new PipeOutputManager(); - ASSERT_EQ(S_OK, pManager->Start()); + pManager->Start(); wprintf(test.c_str()); - ASSERT_EQ(S_OK, pManager->Stop()); + pManager->Stop(); - pManager->GetStdOutContent(&output); - ASSERT_EQ(output.QueryCCH(), (DWORD)30000); + auto output = pManager->GetStdOutContent(); + ASSERT_EQ(output.size(), (DWORD)30000); delete pManager; } + TEST(PipeManagerOutputTest, SetInvalidHandlesForErrAndOut) { auto m_fdPreviousStdOut = _dup(_fileno(stdout)); @@ -86,7 +96,7 @@ namespace PipeOutputManagerTests PCWSTR expected = L"test"; PipeOutputManager* pManager = new PipeOutputManager(); - ASSERT_EQ(S_OK, pManager->Start()); + pManager->Start(); _dup2(m_fdPreviousStdOut, _fileno(stdout)); _dup2(m_fdPreviousStdErr, _fileno(stderr)); @@ -104,17 +114,16 @@ namespace PipeOutputManagerTests auto stdoutBefore = _fileno(stdout); auto stderrBefore = _fileno(stderr); PCWSTR expected = L"test"; - STRA output; PipeOutputManager* pManager = new PipeOutputManager(); - ASSERT_EQ(S_OK, pManager->Start()); + pManager->Start(); fwprintf(stdout, expected); - ASSERT_EQ(S_OK, pManager->Stop()); + pManager->Stop(); - pManager->GetStdOutContent(&output); - ASSERT_STREQ(output.QueryStr(), "test"); + auto output = pManager->GetStdOutContent(); + ASSERT_STREQ(output.c_str(), expected); ASSERT_EQ(stdoutBefore, _fileno(stdout)); ASSERT_EQ(stderrBefore, _fileno(stderr)); delete pManager; @@ -131,16 +140,15 @@ namespace PipeOutputManagerTests auto stdoutHandle = GetStdHandle(STD_OUTPUT_HANDLE); auto stderrHandle = GetStdHandle(STD_ERROR_HANDLE); PCWSTR expected = L"test"; - STRA output; PipeOutputManager* pManager = new PipeOutputManager(); - ASSERT_EQ(S_OK, pManager->Start()); + pManager->Start(); fwprintf(stderr, expected); - ASSERT_EQ(S_OK, pManager->Stop()); + pManager->Stop(); - pManager->GetStdOutContent(&output); - ASSERT_STREQ(output.QueryStr(), "test"); + auto output = pManager->GetStdOutContent(); + ASSERT_STREQ(output.c_str(), expected); ASSERT_EQ(stdoutBefore, _fileno(stdout)); ASSERT_EQ(stderrBefore, _fileno(stderr)); diff --git a/test/WebSites/StartupExceptionWebSite/Program.cs b/test/WebSites/StartupExceptionWebSite/Program.cs index 750f247481..70c0ac0108 100644 --- a/test/WebSites/StartupExceptionWebSite/Program.cs +++ b/test/WebSites/StartupExceptionWebSite/Program.cs @@ -21,10 +21,10 @@ namespace IISTestSite { // Semicolons are appended to env variables; removing them. case "CheckLargeStdOutWrites": - Console.WriteLine(new string('a', 4096)); + Console.WriteLine(new string('a', 30000)); break; case "CheckLargeStdErrWrites": - Console.Error.WriteLine(new string('a', 4096)); + Console.Error.WriteLine(new string('a', 30000)); Console.Error.Flush(); break; case "CheckLogFile": @@ -35,17 +35,16 @@ namespace IISTestSite Console.Error.Flush(); break; case "CheckOversizedStdErrWrites": - Console.WriteLine(new string('a', 5000)); + Console.WriteLine(new string('a', 31000)); break; case "CheckOversizedStdOutWrites": - Console.Error.WriteLine(new string('a', 4096)); + Console.Error.WriteLine(new string('a', 31000)); Console.Error.Flush(); break; case "Hang": Thread.Sleep(Timeout.Infinite); break; case "HangOnStop": - var host = new WebHostBuilder() .UseIIS() .UseStartup() @@ -60,6 +59,7 @@ namespace IISTestSite Console.Title = "Test"; Console.WriteLine($"Is Console redirection: {Console.IsOutputRedirected}"); Console.BackgroundColor = ConsoleColor.Blue; + Console.WriteLine("彡⾔"); break; }