Redirect native logs into stdout and pipe (#1154)

src/AspNetCoreModuleV2/AspNetCore/HandlerResolver.cpp

@@ -10,6 +10,8 @@
 #include "GlobalVersionUtility.h"
 #include "HandleWrapper.h"
 #include "file_utility.h"
+#include "LoggingHelpers.h"
+#include "resources.h"
 
 const PCWSTR HandlerResolver::s_pwzAspnetcoreInProcessRequestHandlerName = L"aspnetcorev2_inprocess.dll";
 const PCWSTR HandlerResolver::s_pwzAspnetcoreOutOfProcessRequestHandlerName = L"aspnetcorev2_outofprocess.dll";
@@ -46,6 +48,7 @@ HandlerResolver::LoadRequestHandlerAssembly(IHttpApplication &pApplication, STRU
         if (pConfiguration->QueryHostingModel() == APP_HOSTING_MODEL::HOSTING_IN_PROCESS)
         {
             std::unique_ptr<HOSTFXR_OPTIONS> options;
+            std::unique_ptr<IOutputManager> outputManager;
 
             RETURN_IF_FAILED(HOSTFXR_OPTIONS::Create(
                 NULL,
@@ -56,14 +59,35 @@ HandlerResolver::LoadRequestHandlerAssembly(IHttpApplication &pApplication, STRU
 
             RETURN_IF_FAILED(location.Copy(options->GetExeLocation()));
 
-            if (FAILED_LOG(hr = FindNativeAssemblyFromHostfxr(options.get(), pstrHandlerDllName, &struFileName)))
+            RETURN_IF_FAILED(LoggingHelpers::CreateLoggingProvider(
-            {
+                pConfiguration->QueryStdoutLogEnabled(),
-                EventLog::Error(
+                !m_pServer.IsCommandLineLaunch(),
-                    ASPNETCORE_EVENT_INPROCESS_RH_MISSING,
+                pConfiguration->QueryStdoutLogFile()->QueryStr(),
-                    ASPNETCORE_EVENT_INPROCESS_RH_MISSING_MSG,
+                pApplication.GetApplicationPhysicalPath(),
-                    struFileName.IsEmpty() ? s_pwzAspnetcoreInProcessRequestHandlerName : struFileName.QueryStr());
+                outputManager));
+
+            outputManager->Start();
+
+            hr = FindNativeAssemblyFromHostfxr(options.get(), pstrHandlerDllName, &struFileName);
+            outputManager->Stop();
+
+            if (FAILED(hr) && m_hHostFxrDll != NULL)
+            {
+                STRA content;
+                STRU struStdMsg;
+
+                outputManager->GetStdOutContent(&content);
+                if (content.QueryCCH() > 0)
+                {
+                    struStdMsg.CopyA(content.QueryStr());
+                }
+
+                EventLog::Error(
+                    ASPNETCORE_EVENT_GENERAL_ERROR,
+                    ASPNETCORE_EVENT_INPROCESS_RH_ERROR_MSG,
+                    struFileName.IsEmpty() ? s_pwzAspnetcoreInProcessRequestHandlerName : struFileName.QueryStr(),
+                    struStdMsg.QueryStr());
 
-                return hr;
             }
         }
         else
@@ -188,12 +212,23 @@ HandlerResolver::FindNativeAssemblyFromHostfxr(
     BOOL        fFound = FALSE;
     DWORD       dwBufferSize = 1024 * 10;
     DWORD       dwRequiredBufferSize = 0;
+    STRA        output;
+
 
     DBG_ASSERT(struFilename != NULL);
 
     RETURN_LAST_ERROR_IF_NULL(m_hHostFxrDll = LoadLibraryW(hostfxrOptions->GetHostFxrLocation()));
 
     auto pFnHostFxrSearchDirectories = reinterpret_cast<hostfxr_get_native_search_directories_fn>(GetProcAddress(m_hHostFxrDll, "hostfxr_get_native_search_directories"));
+    if (pFnHostFxrSearchDirectories == nullptr)
+    {
+        EventLog::Error(
+            ASPNETCORE_EVENT_GENERAL_ERROR,
+            ASPNETCORE_EVENT_HOSTFXR_DLL_INVALID_VERSION_MSG,
+            hostfxrOptions->GetHostFxrLocation()
+            );
+        RETURN_IF_FAILED(E_FAIL);
+    }
 
     RETURN_LAST_ERROR_IF_NULL(pFnHostFxrSearchDirectories);
     RETURN_IF_FAILED(struNativeSearchPaths.Resize(dwBufferSize));

src/AspNetCoreModuleV2/AspNetCore/aspnetcore_shim_config.cpp

@@ -29,7 +29,7 @@ ASPNETCORE_SHIM_CONFIG::Populate(
         CS_ASPNETCORE_PROCESS_EXE_PATH,
         &m_struProcessPath));
 
-    // Swallow this error for backward compatability
+    // Swallow this error for backward compatibility
     // Use default behavior for empty string
     GetElementStringProperty(pAspNetCoreElement,
         CS_ASPNETCORE_HOSTING_MODEL,
@@ -62,5 +62,13 @@ ASPNETCORE_SHIM_CONFIG::Populate(
         RETURN_IF_FAILED(ConfigUtility::FindHandlerVersion(pAspNetCoreElement, m_struHandlerVersion));
     }
 
+
+    RETURN_IF_FAILED(GetElementBoolProperty(pAspNetCoreElement,
+        CS_ASPNETCORE_STDOUT_LOG_ENABLED,
+        &m_fStdoutLogEnabled));
+    RETURN_IF_FAILED(GetElementStringProperty(pAspNetCoreElement,
+        CS_ASPNETCORE_STDOUT_LOG_FILE,
+        &m_struStdoutLogFile));
+
     return S_OK;
 }

src/AspNetCoreModuleV2/AspNetCore/aspnetcore_shim_config.h

@@ -12,6 +12,8 @@
 #define CS_ASPNETCORE_PROCESS_EXE_PATH                   L"processPath"
 #define CS_ASPNETCORE_PROCESS_ARGUMENTS                  L"arguments"
 #define CS_ASPNETCORE_HOSTING_MODEL                      L"hostingModel"
+#define CS_ASPNETCORE_STDOUT_LOG_ENABLED                 L"stdoutLogEnabled"
+#define CS_ASPNETCORE_STDOUT_LOG_FILE                    L"stdoutLogFile"
 
 enum APP_HOSTING_MODEL
 {
@@ -56,6 +58,18 @@ public:
         return &m_struHandlerVersion;
     }
 
+    BOOL
+    QueryStdoutLogEnabled()
+    {
+        return m_fStdoutLogEnabled;
+    }
+
+    STRU*
+    QueryStdoutLogFile()
+    {
+        return &m_struStdoutLogFile;
+    }
+
     ASPNETCORE_SHIM_CONFIG() :
         m_hostingModel(HOSTING_UNKNOWN)
     {
@@ -67,5 +81,6 @@ private:
     STRU                   m_struProcessPath;
     APP_HOSTING_MODEL      m_hostingModel;
     STRU                   m_struHandlerVersion;
+    BOOL                   m_fStdoutLogEnabled;
+    STRU                   m_struStdoutLogFile;
 };
-

src/AspNetCoreModuleV2/CommonLib/CommonLib.vcxproj

@@ -200,6 +200,7 @@
     <ClInclude Include="EventLog.h" />
     <ClInclude Include="exceptions.h" />
     <ClInclude Include="file_utility.h" />
+    <ClInclude Include="FileOutputManager.h" />
     <ClInclude Include="GlobalVersionUtility.h" />
     <ClInclude Include="fx_ver.h" />
     <ClInclude Include="HandleWrapper.h" />
@@ -207,7 +208,12 @@
     <ClInclude Include="hostfxr_utility.h" />
     <ClInclude Include="iapplication.h" />
     <ClInclude Include="debugutil.h" />
+    <ClInclude Include="IOutputManager.h" />
     <ClInclude Include="irequesthandler.h" />
+    <ClInclude Include="LoggingHelpers.h" />
+    <ClInclude Include="NullOutputManager.h" />
+    <ClInclude Include="PipeOutputManager.h" />
+    <ClInclude Include="StdWrapper.h" />
     <ClInclude Include="requesthandler.h" />
     <ClInclude Include="resources.h" />
     <ClInclude Include="SRWExclusiveLock.h" />
@@ -220,11 +226,15 @@
     <ClCompile Include="Environment.cpp" />
     <ClCompile Include="EventLog.cpp" />
     <ClCompile Include="file_utility.cpp" />
+    <ClCompile Include="FileOutputManager.cpp" />
     <ClCompile Include="fx_ver.cpp" />
     <ClCompile Include="GlobalVersionUtility.cpp" />
     <ClCompile Include="HandleWrapper.cpp" />
     <ClCompile Include="hostfxr_utility.cpp" />
     <ClCompile Include="hostfxroptions.cpp" />
+    <ClCompile Include="LoggingHelpers.cpp" />
+    <ClCompile Include="PipeOutputManager.cpp" />
+    <ClCompile Include="StdWrapper.cpp" />
     <ClCompile Include="SRWExclusiveLock.cpp" />
     <ClCompile Include="SRWSharedLock.cpp" />
     <ClCompile Include="stdafx.cpp">

src/AspNetCoreModuleV2/CommonLib/EventLog.cpp

@@ -27,7 +27,7 @@ EventLog::LogEvent(
         );
     }
 
-    DebugPrintf(dwEventInfoType == EVENTLOG_ERROR_TYPE ? ASPNETCORE_DEBUG_FLAG_ERROR : ASPNETCORE_DEBUG_FLAG_INFO, "Event Log: %S", pstrMsg);
+    DebugPrintf(dwEventInfoType == EVENTLOG_ERROR_TYPE ? ASPNETCORE_DEBUG_FLAG_ERROR : ASPNETCORE_DEBUG_FLAG_INFO, "Event Log: %S \r\nEnd Event Log Message.", pstrMsg);
 }
 
 VOID

src/AspNetCoreModuleV2/CommonLib/FileOutputManager.cpp

@@ -0,0 +1,190 @@
+// 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 "FileOutputManager.h"
+#include "sttimer.h"
+#include "exceptions.h"
+#include "debugutil.h"
+#include "SRWExclusiveLock.h"
+#include "file_utility.h"
+#include "StdWrapper.h"
+
+extern HINSTANCE    g_hModule;
+
+FileOutputManager::FileOutputManager() :
+    FileOutputManager(/* fEnableNativeLogging */ true) { }
+
+FileOutputManager::FileOutputManager(bool fEnableNativeLogging) :
+    m_hLogFileHandle(INVALID_HANDLE_VALUE),
+    m_disposed(false),
+    stdoutWrapper(nullptr),
+    stderrWrapper(nullptr),
+    m_fEnableNativeRedirection(fEnableNativeLogging)
+{
+    InitializeSRWLock(&m_srwLock);
+}
+
+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
+FileOutputManager::Start()
+{
+    SYSTEMTIME systemTime;
+    SECURITY_ATTRIBUTES saAttr = { 0 };
+    STRU struPath;
+
+    // Concatenate the log file name and application path
+    RETURN_IF_FAILED(FILE_UTILITY::ConvertPathToFullPath(
+        m_wsStdOutLogFileName.QueryStr(),
+        m_wsApplicationPath.QueryStr(),
+        &struPath));
+
+    RETURN_IF_FAILED(FILE_UTILITY::EnsureDirectoryPathExist(struPath.QueryStr()));
+
+    // Get the module name and add it to the log file name
+    // as two log files will be created, one from the shim
+    // and one from the request handler.
+    WCHAR path[MAX_PATH];
+    RETURN_LAST_ERROR_IF(!GetModuleFileName(g_hModule, path, sizeof(path)));
+    std::filesystem::path fsPath(path);
+
+    // TODO fix string as it is incorrect
+    GetSystemTime(&systemTime);
+
+    RETURN_IF_FAILED(
+        m_struLogFilePath.SafeSnwprintf(L"%s_%d%02d%02d%02d%02d%02d_%d_%s.log",
+            struPath.QueryStr(),
+            systemTime.wYear,
+            systemTime.wMonth,
+            systemTime.wDay,
+            systemTime.wHour,
+            systemTime.wMinute,
+            systemTime.wSecond,
+            GetCurrentProcessId(),
+            fsPath.filename().stem().c_str()));
+
+    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(),
+        FILE_READ_DATA | FILE_WRITE_DATA,
+        FILE_SHARE_READ,
+        &saAttr,
+        CREATE_ALWAYS,
+        FILE_ATTRIBUTE_NORMAL,
+        nullptr);
+
+    RETURN_LAST_ERROR_IF(m_hLogFileHandle == INVALID_HANDLE_VALUE);
+
+    stdoutWrapper = std::make_unique<StdWrapper>(stdout, STD_OUTPUT_HANDLE, m_hLogFileHandle, m_fEnableNativeRedirection);
+    stderrWrapper = std::make_unique<StdWrapper>(stderr, STD_ERROR_HANDLE, m_hLogFileHandle, m_fEnableNativeRedirection);
+
+    stdoutWrapper->StartRedirection();
+    stderrWrapper->StartRedirection();
+
+    return S_OK;
+}
+
+
+HRESULT
+FileOutputManager::Stop()
+{
+    STRA     straStdOutput;
+    CHAR            pzFileContents[MAX_FILE_READ_SIZE] = { 0 };
+    DWORD           dwNumBytesRead;
+    LARGE_INTEGER   li = { 0 };
+    DWORD           dwFilePointer = 0;
+    HANDLE   handle = NULL;
+    WIN32_FIND_DATA fileData;
+
+    if (m_disposed)
+    {
+        return S_OK;
+    }
+
+    SRWExclusiveLock lock(m_srwLock);
+
+    if (m_disposed)
+    {
+        return S_OK;
+    }
+
+    m_disposed = true;
+
+    if (m_hLogFileHandle == INVALID_HANDLE_VALUE)
+    {
+        return HRESULT_FROM_WIN32(ERROR_FILE_NOT_FOUND);
+    }
+
+    FlushFileBuffers(m_hLogFileHandle);
+
+    if (stdoutWrapper != nullptr)
+    {
+        RETURN_IF_FAILED(stdoutWrapper->StopRedirection());
+    }
+
+    if (stderrWrapper != nullptr)
+    {
+        RETURN_IF_FAILED(stderrWrapper->StopRedirection());
+    }
+
+    // delete empty log file
+    handle = FindFirstFile(m_struLogFilePath.QueryStr(), &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()));
+    }
+
+    // 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));
+
+    if (li.LowPart == 0 || li.HighPart > 0)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    dwFilePointer = SetFilePointer(m_hLogFileHandle, 0, NULL, FILE_BEGIN);
+
+    RETURN_LAST_ERROR_IF(dwFilePointer == INVALID_SET_FILE_POINTER);
+
+    RETURN_LAST_ERROR_IF(!ReadFile(m_hLogFileHandle, pzFileContents, MAX_FILE_READ_SIZE, &dwNumBytesRead, NULL));
+
+    m_straFileContent.Copy(pzFileContents, dwNumBytesRead);
+
+    // printf will fail in in full IIS
+    if (printf(m_straFileContent.QueryStr()) != -1)
+    {
+        // Need to flush contents for the new stdout and stderr
+        _flushall();
+    }
+
+    return S_OK;
+}
+
+bool FileOutputManager::GetStdOutContent(STRA* struStdOutput)
+{
+    struStdOutput->Copy(m_straFileContent);
+    return m_straFileContent.QueryCCH() > 0;
+}

src/AspNetCoreModuleV2/CommonLib/FileOutputManager.h

@@ -6,12 +6,17 @@
 #include "sttimer.h"
 #include "IOutputManager.h"
 #include "HandleWrapper.h"
+#include "StdWrapper.h"
+#include "stringa.h"
+#include "stringu.h"
 
 class FileOutputManager : public IOutputManager
 {
     #define FILE_FLUSH_TIMEOUT 3000
+    #define MAX_FILE_READ_SIZE 30000
 public:
     FileOutputManager();
+    FileOutputManager(bool fEnableNativeLogging);
     ~FileOutputManager();
 
     HRESULT
@@ -27,9 +32,10 @@ private:
     STRU m_wsStdOutLogFileName;
     STRU m_wsApplicationPath;
     STRU m_struLogFilePath;
-    int m_fdPreviousStdOut;
+    STRA m_straFileContent;
-    int m_fdPreviousStdErr;
     BOOL m_disposed;
-    SRWLOCK m_srwLock;
+    BOOL m_fEnableNativeRedirection;
+    SRWLOCK m_srwLock{};
+    std::unique_ptr<StdWrapper>    stdoutWrapper;
+    std::unique_ptr<StdWrapper>    stderrWrapper;
 };
-

src/AspNetCoreModuleV2/CommonLib/HandleWrapper.h

@@ -4,6 +4,7 @@
 #pragma once
 
 #include <Windows.h>
+#include <ntassert.h>
 
 struct InvalidHandleTraits
 {

src/AspNetCoreModuleV2/CommonLib/IOutputManager.h

@@ -1,9 +1,11 @@
 // 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"
-
 #pragma once
+
+#include "stdafx.h"
+#include "stringa.h"
+
 class IOutputManager
 {
 public:

src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.cpp

@@ -7,14 +7,18 @@
 #include "FileOutputManager.h"
 #include "PipeOutputManager.h"
 #include "NullOutputManager.h"
+#include "debugutil.h"
+#include <Windows.h>
+#include <io.h>
+#include "ntassert.h"
 
 HRESULT
 LoggingHelpers::CreateLoggingProvider(
     bool fIsLoggingEnabled,
-    bool fEnablePipe,
+    bool fEnableNativeLogging,
     PCWSTR pwzStdOutFileName,
     PCWSTR pwzApplicationPath,
-    _Out_ IOutputManager** outputManager
+    std::unique_ptr<IOutputManager>& outputManager
 )
 {
     HRESULT hr = S_OK;
@@ -25,17 +29,17 @@ LoggingHelpers::CreateLoggingProvider(
     {
         if (fIsLoggingEnabled)
         {
-            FileOutputManager* manager = new FileOutputManager;
+            auto manager = std::make_unique<FileOutputManager>(fEnableNativeLogging);
             hr = manager->Initialize(pwzStdOutFileName, pwzApplicationPath);
-            *outputManager = manager;
+            outputManager = std::move(manager);
         }
-        else if (fEnablePipe)
+        else if (!GetConsoleWindow())
         {
-            *outputManager = new PipeOutputManager;
+            outputManager = std::make_unique<PipeOutputManager>(fEnableNativeLogging);
         }
         else
         {
-            *outputManager = new NullOutputManager;
+            outputManager = std::make_unique<NullOutputManager>();
         }
     }
     catch (std::bad_alloc&)

src/AspNetCoreModuleV2/CommonLib/LoggingHelpers.h

@@ -13,10 +13,10 @@ public:
     HRESULT
     CreateLoggingProvider(
         bool fLoggingEnabled,
-        bool fEnablePipe,
+        bool fEnableNativeLogging,
         PCWSTR pwzStdOutFileName,
         PCWSTR pwzApplicationPath,
-        _Out_ IOutputManager** outputManager
+        std::unique_ptr<IOutputManager>& outputManager
     );
 };
 

src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.cpp

@@ -5,63 +5,74 @@
 #include "PipeOutputManager.h"
 #include "exceptions.h"
 #include "SRWExclusiveLock.h"
+#include "StdWrapper.h"
+#include "ntassert.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);
 
-PipeOutputManager::PipeOutputManager() :
+PipeOutputManager::PipeOutputManager()
-    m_dwStdErrReadTotal(0),
+    : PipeOutputManager( /* fEnableNativeLogging */ true)
+{
+}
+
+PipeOutputManager::PipeOutputManager(bool fEnableNativeLogging) :
     m_hErrReadPipe(INVALID_HANDLE_VALUE),
     m_hErrWritePipe(INVALID_HANDLE_VALUE),
-    m_hErrThread(NULL),
+    m_hErrThread(nullptr),
+    m_dwStdErrReadTotal(0),
     m_disposed(FALSE),
-    m_fdPreviousStdOut(-1),
+    m_fEnableNativeRedirection(fEnableNativeLogging),
-    m_fdPreviousStdErr(-1)
+    stdoutWrapper(nullptr),
+    stderrWrapper(nullptr)
 {
     InitializeSRWLock(&m_srwLock);
 }
 
 PipeOutputManager::~PipeOutputManager()
 {
-    Stop();
+    PipeOutputManager::Stop();
 }
 
+// Start redirecting stdout and stderr into a pipe
+// Continuously read the pipe on a background thread
+// until Stop is called.
 HRESULT PipeOutputManager::Start()
 {
     SECURITY_ATTRIBUTES     saAttr = { 0 };
     HANDLE                  hStdErrReadPipe;
     HANDLE                  hStdErrWritePipe;
 
-    m_fdPreviousStdOut = _dup(_fileno(stdout));
-    LOG_IF_DUPFAIL(m_fdPreviousStdOut);
-
-    m_fdPreviousStdErr = _dup(_fileno(stderr));
-    LOG_IF_DUPFAIL(m_fdPreviousStdErr);
-
     RETURN_LAST_ERROR_IF(!CreatePipe(&hStdErrReadPipe, &hStdErrWritePipe, &saAttr, 0 /*nSize*/));
 
-    // TODO this still doesn't redirect calls in native, like wprintf
-    RETURN_LAST_ERROR_IF(!SetStdHandle(STD_ERROR_HANDLE, hStdErrWritePipe));
-
-    RETURN_LAST_ERROR_IF(!SetStdHandle(STD_OUTPUT_HANDLE, hStdErrWritePipe));
-
     m_hErrReadPipe = hStdErrReadPipe;
     m_hErrWritePipe = hStdErrWritePipe;
 
-    // Read the stderr handle on a separate thread until we get 4096 bytes.
+    stdoutWrapper = std::make_unique<StdWrapper>(stdout, STD_OUTPUT_HANDLE, hStdErrWritePipe, m_fEnableNativeRedirection);
+    stderrWrapper = std::make_unique<StdWrapper>(stderr, STD_ERROR_HANDLE, hStdErrWritePipe, m_fEnableNativeRedirection);
+
+    LOG_IF_FAILED(stdoutWrapper->StartRedirection());
+    LOG_IF_FAILED(stderrWrapper->StartRedirection());
+
+    // Read the stderr handle on a separate thread until we get 30Kb.
     m_hErrThread = CreateThread(
-        NULL,       // default security attributes
+        nullptr,       // default security attributes
         0,          // default stack size
-        (LPTHREAD_START_ROUTINE)ReadStdErrHandle,
+        reinterpret_cast<LPTHREAD_START_ROUTINE>(ReadStdErrHandle),
         this,       // thread function arguments
         0,          // default creation flags
-        NULL);      // receive thread identifier
+        nullptr);      // receive thread identifier
 
     RETURN_LAST_ERROR_IF_NULL(m_hErrThread);
 
     return S_OK;
 }
 
+// Stop redirecting stdout and stderr into a pipe
+// This closes the background thread reading from the pipe
+// 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()
 {
     DWORD    dwThreadStatus = 0;
@@ -71,57 +82,53 @@ HRESULT PipeOutputManager::Stop()
     {
         return S_OK;
     }
+
     SRWExclusiveLock lock(m_srwLock);
 
     if (m_disposed)
     {
         return S_OK;
     }
+
     m_disposed = true;
 
-    fflush(stdout);
+    // Both pipe wrappers duplicate the pipe writer handle
-    fflush(stderr);
+    // meaning we are fine to close the handle too.
-
-    // Restore the original stdout and stderr handles of the process,
-    // as the application has either finished startup or has exited.
-
-    // If stdout/stderr were not set, we need to set it to NUL:
-    // such that other calls to Console.WriteLine don't use an invalid handle
-    FILE *stream;
-
-    if (m_fdPreviousStdOut >= 0)
-    {
-        LOG_LAST_ERROR_IF(SetStdHandle(STD_OUTPUT_HANDLE, (HANDLE)_get_osfhandle(m_fdPreviousStdOut)));
-    }
-    else
-    {
-        LOG_IF_ERRNO(freopen_s(&stream, "NUL:", "w", stdout));
-    }
-
-    if (m_fdPreviousStdErr >= 0)
-    {
-        LOG_LAST_ERROR_IF(SetStdHandle(STD_ERROR_HANDLE, (HANDLE)_get_osfhandle(m_fdPreviousStdErr)));
-    }
-    else
-    {
-        LOG_IF_ERRNO(freopen_s(&stream, "NUL:", "w", stderr));
-    }
-
     if (m_hErrWritePipe != INVALID_HANDLE_VALUE)
     {
+        // Flush the pipe writer before closing to capture all output
+        RETURN_LAST_ERROR_IF(!FlushFileBuffers(m_hErrWritePipe));
         CloseHandle(m_hErrWritePipe);
         m_hErrWritePipe = INVALID_HANDLE_VALUE;
     }
 
+    // Tell each pipe wrapper to stop redirecting output and restore the original values
+    if (stdoutWrapper != nullptr)
+    {
+        LOG_IF_FAILED(stdoutWrapper->StopRedirection());
+    }
+
+    if (stderrWrapper != nullptr)
+    {
+        LOG_IF_FAILED(stderrWrapper->StopRedirection());
+    }
+
+    // Forces ReadFile to cancel, causing the read loop to complete.
+    // Don't check return value as IO may or may not be completed already.
+    if (m_hErrThread != nullptr)
+    {
+        CancelSynchronousIo(m_hErrThread);
+    }
+
     // GetExitCodeThread returns 0 on failure; thread status code is invalid.
-    if (m_hErrThread != NULL &&
+    if (m_hErrThread != nullptr &&
         !LOG_LAST_ERROR_IF(GetExitCodeThread(m_hErrThread, &dwThreadStatus) == 0) &&
         dwThreadStatus == STILL_ACTIVE)
     {
-        // wait for graceful shutdown, i.e., the exit of the background thread or timeout
+        // Wait for graceful shutdown, i.e., the exit of the background thread or timeout
         if (WaitForSingleObject(m_hErrThread, PIPE_OUTPUT_THREAD_TIMEOUT) != WAIT_OBJECT_0)
         {
-            // if the thread is still running, we need kill it first before exit to avoid AV
+            // If the thread is still running, we need kill it first before exit to avoid AV
             if (!LOG_LAST_ERROR_IF(GetExitCodeThread(m_hErrThread, &dwThreadStatus) == 0) &&
                 dwThreadStatus == STILL_ACTIVE)
             {
@@ -131,42 +138,38 @@ HRESULT PipeOutputManager::Stop()
         }
     }
 
-    if (m_hErrThread != NULL)
+    if (m_hErrThread != nullptr)
     {
         CloseHandle(m_hErrThread);
-        m_hErrThread = NULL;
+        m_hErrThread = nullptr;
     }
 
-
     if (m_hErrReadPipe != INVALID_HANDLE_VALUE)
     {
         CloseHandle(m_hErrReadPipe);
         m_hErrReadPipe = INVALID_HANDLE_VALUE;
     }
 
+    // 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))
     {
-        printf(straStdOutput.QueryStr());
+        // printf will fail in in full IIS
-        // Need to flush contents for the new stdout and stderr
+        if (printf(straStdOutput.QueryStr()) != -1)
-        _flushall();
+        {
+            // Need to flush contents for the new stdout and stderr
+            _flushall();
+        }
     }
 
     return S_OK;
 }
 
-VOID
-PipeOutputManager::ReadStdErrHandle(
-    LPVOID pContext
-)
-{
-    PipeOutputManager *pLoggingProvider = (PipeOutputManager*)pContext;
-    DBG_ASSERT(pLoggingProvider != NULL);
-    pLoggingProvider->ReadStdErrHandleInternal();
-}
-
 bool PipeOutputManager::GetStdOutContent(STRA* straStdOutput)
 {
     bool fLogged = false;
+
+    // TODO consider returning the file contents rather than copying.
     if (m_dwStdErrReadTotal > 0)
     {
         if (SUCCEEDED(straStdOutput->Copy(m_pzFileContents, m_dwStdErrReadTotal)))
@@ -178,15 +181,29 @@ bool PipeOutputManager::GetStdOutContent(STRA* straStdOutput)
     return fLogged;
 }
 
-VOID
+void
-PipeOutputManager::ReadStdErrHandleInternal(
+PipeOutputManager::ReadStdErrHandle(
-    VOID
+    LPVOID pContext
 )
 {
+    auto pLoggingProvider = static_cast<PipeOutputManager*>(pContext);
+    DBG_ASSERT(pLoggingProvider != NULL);
+    pLoggingProvider->ReadStdErrHandleInternal();
+}
+
+void
+PipeOutputManager::ReadStdErrHandleInternal()
+{
+    // If ReadFile ever returns false, exit the thread
     DWORD dwNumBytesRead = 0;
     while (true)
     {
-        if (ReadFile(m_hErrReadPipe, &m_pzFileContents[m_dwStdErrReadTotal], MAX_PIPE_READ_SIZE - m_dwStdErrReadTotal, &dwNumBytesRead, NULL))
+        // 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,
+            &dwNumBytesRead,
+            nullptr))
         {
             m_dwStdErrReadTotal += dwNumBytesRead;
             if (m_dwStdErrReadTotal >= MAX_PIPE_READ_SIZE)
@@ -194,19 +211,21 @@ PipeOutputManager::ReadStdErrHandleInternal(
                 break;
             }
         }
-        else if (GetLastError() == ERROR_BROKEN_PIPE)
+        else
         {
             return;
         }
     }
 
-    char tempBuffer[MAX_PIPE_READ_SIZE];
+    // Using std::string as a wrapper around new char[] so we don't need to call delete
+    // Also don't allocate on stack as stack size is 128KB by default.
+    std::string tempBuffer; 
+    tempBuffer.resize(MAX_PIPE_READ_SIZE);
+
+    // After reading the maximum amount of data, keep reading in a loop until Stop is called on the output manager.
     while (true)
     {
-        if (ReadFile(m_hErrReadPipe, tempBuffer, MAX_PIPE_READ_SIZE, &dwNumBytesRead, NULL))
+        if (!ReadFile(m_hErrReadPipe, tempBuffer.data(), MAX_PIPE_READ_SIZE, &dwNumBytesRead, nullptr))
-        {
-        }
-        else if (GetLastError() == ERROR_BROKEN_PIPE)
         {
             return;
         }

src/AspNetCoreModuleV2/CommonLib/PipeOutputManager.h

@@ -4,35 +4,41 @@
 #pragma once
 
 #include "IOutputManager.h"
+#include "StdWrapper.h"
+#include "stringu.h"
 
 class PipeOutputManager : public IOutputManager
 {
+    // Timeout to be used if a thread never exits
     #define PIPE_OUTPUT_THREAD_TIMEOUT 2000
-    #define MAX_PIPE_READ_SIZE 4096
+
+    // Max event log message is ~32KB, limit pipe size just below that.
+    #define MAX_PIPE_READ_SIZE 30000
 public:
     PipeOutputManager();
+    PipeOutputManager(bool fEnableNativeLogging);
     ~PipeOutputManager();
 
-    virtual HRESULT Start() override;
+    HRESULT Start() override;
-    virtual HRESULT Stop() override;
+    HRESULT Stop() override;
-    virtual bool GetStdOutContent(STRA* struStdOutput) override;
+    bool GetStdOutContent(STRA* straStdOutput) override;
 
     // Thread functions
-    VOID ReadStdErrHandleInternal(VOID);
+    void ReadStdErrHandleInternal();
 
-    static
+    static void ReadStdErrHandle(LPVOID pContext);
-    VOID ReadStdErrHandle(LPVOID pContext);
 
 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;
+    SRWLOCK                         m_srwLock {};
-    int                             m_fdPreviousStdOut;
-    int                             m_fdPreviousStdErr;
     BOOL                            m_disposed;
+    BOOL                            m_fEnableNativeRedirection;
+    std::unique_ptr<StdWrapper>     stdoutWrapper;
+    std::unique_ptr<StdWrapper>     stderrWrapper;
 };
-

src/AspNetCoreModuleV2/CommonLib/StdWrapper.cpp

@@ -0,0 +1,148 @@
+// 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 "StdWrapper.h"
+#include "exceptions.h"
+#include "LoggingHelpers.h"
+#include <corecrt_io.h>
+#include <fcntl.h>
+
+StdWrapper::StdWrapper(FILE* stdStream, DWORD stdHandleNumber, HANDLE handleToRedirectTo, BOOL fEnableNativeRedirection)
+    : m_previousFileDescriptor(0),
+    m_stdStream(stdStream),
+    m_stdHandleNumber(stdHandleNumber),
+    m_fEnableNativeRedirection(fEnableNativeRedirection),
+    m_handleToRedirectTo(handleToRedirectTo),
+    m_redirectedFile(nullptr)
+{
+}
+
+StdWrapper::~StdWrapper() = default;
+
+// Redirects stdout/stderr to the provided handle.
+// Example:
+// If the handleToRedirecTo = 0x24
+// Before:
+// _fileno(stdout) = 1
+// GetStdHandle(STD_OUTPUT_HANDLE) = 0x20
+// After:
+// _fileno(stdout) = 3
+// GetStdHandle(STD_OUTPUT_HANDLE) = 0x28 <- Duplicated from 0x24
+HRESULT
+StdWrapper::StartRedirection()
+{
+    HANDLE stdHandle;
+
+    // In IIS, stdout and stderr are set to null as w3wp is created with DETACHED_PROCESS,
+    // so fileno(m_stdStream) returns -2.
+    // Open a null file such that undoing the redirection succeeds and _dup2 works.
+    // m_previousFileDescriptor will be used for restoring stdout/stderr
+    if (_fileno(m_stdStream) == -2)
+    {
+        freopen_s((FILE**)&m_stdStream, "nul", "w", m_stdStream);
+        m_previousFileDescriptor = _dup(_fileno(m_stdStream));
+    }
+    else
+    {
+        m_previousFileDescriptor = _dup(_fileno(m_stdStream));
+    }
+
+    if (!m_fEnableNativeRedirection)
+    {
+        RETURN_LAST_ERROR_IF(!SetStdHandle(m_stdHandleNumber, m_handleToRedirectTo));
+
+        return S_OK;
+    }
+    // After setting the std handle, we need to set stdout/stderr to the current
+    // output/error handle.
+
+    // Duplicate the handle before opening the handle and associating a file pointer.
+    // If we don't by calling close on the file, the same handle value will be closed
+    // multiple times.
+    // Note, by calling duplicate handle, the new handle returned will have a different value
+    // than the original, but point to the same underlying file object.
+    RETURN_LAST_ERROR_IF(!DuplicateHandle(
+        /* hSourceProcessHandle*/ GetCurrentProcess(),
+        /* hSourceHandle */ m_handleToRedirectTo,
+        /* hTargetProcessHandle */ GetCurrentProcess(),
+        /* lpTargetHandle */&stdHandle,
+        /* dwDesiredAccess */ 0, // dwDesired is ignored if DUPLICATE_SAME_ACCESS is specified
+        /* bInheritHandle */ TRUE,
+        /* dwOptions  */ DUPLICATE_SAME_ACCESS));
+
+    RETURN_LAST_ERROR_IF(!SetStdHandle(m_stdHandleNumber, stdHandle));
+
+    // _open_osfhandle will associate a filedescriptor with the handle.
+    const auto fileDescriptor = _open_osfhandle(reinterpret_cast<intptr_t>(stdHandle), _O_WTEXT | _O_TEXT);
+
+    if (fileDescriptor == -1)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    m_redirectedFile = _fdopen(fileDescriptor, "w");
+
+    if (m_redirectedFile == nullptr)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    // Set stdout/stderr to the newly created file.
+    const auto dup2Result = _dup2(_fileno(m_redirectedFile), _fileno(m_stdStream));
+
+    if (dup2Result != 0)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    // Removes buffering from the output
+    if (setvbuf(m_stdStream, nullptr, _IONBF, 0) != 0)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    return S_OK;
+}
+
+// Redirects stdout/stderr back to the original stdout/stderr.
+// Note, this will not restore the original handle values returned by GetStdHandle,
+// rather a duplicated number. This is because the original handle value is invalid
+// due to dup2 closing the file originally in stdout/stderr
+HRESULT
+StdWrapper::StopRedirection() const
+{
+    // After setting the std handle, we need to set stdout/stderr to the current
+    // output/error handle.
+    FILE * file = _fdopen(m_previousFileDescriptor, "w");
+    if (file == nullptr)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    RETURN_LAST_ERROR_IF(!SetStdHandle(m_stdHandleNumber, reinterpret_cast<HANDLE>(_get_osfhandle(m_previousFileDescriptor))));
+
+    if (!m_fEnableNativeRedirection)
+    {
+        return S_OK;
+    }
+
+    // Set stdout/stderr to the newly created file output.
+    const auto dup2Result = _dup2(_fileno(file), _fileno(m_stdStream));
+    if (dup2Result != 0)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    if (setvbuf(m_stdStream, nullptr, _IONBF, 0) != 0)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    if (fclose(m_redirectedFile) != 0)
+    {
+        RETURN_IF_FAILED(HRESULT_FROM_WIN32(ERROR_FILE_INVALID));
+    }
+
+    return S_OK;
+}

src/AspNetCoreModuleV2/CommonLib/StdWrapper.h

@@ -0,0 +1,25 @@
+// 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 <cstdio>
+
+// Wraps stdout/stderr stream, modifying them to redirect to the given handle
+class StdWrapper
+{
+public:
+    StdWrapper(FILE* stdStream, DWORD stdHandleNumber, HANDLE handleToRedirectTo, BOOL fEnableNativeRedirection);
+    ~StdWrapper();
+    HRESULT StartRedirection();
+    HRESULT StopRedirection() const;
+
+private:
+    int m_previousFileDescriptor;
+    FILE* m_stdStream;
+    DWORD m_stdHandleNumber;
+    BOOL m_fEnableNativeRedirection;
+    HANDLE m_handleToRedirectTo;
+    FILE* m_redirectedFile;
+};
+

src/AspNetCoreModuleV2/CommonLib/aspnetcore_msg.mc

@@ -177,19 +177,19 @@ Language=English
 .
 
 Messageid=1025
-SymbolicName=ASPNETCORE_EVENT_GENERAL_INFO_MSG
+SymbolicName=ASPNETCORE_EVENT_GENERAL_INFO
 Language=English
 %1
 .
 
 Messageid=1026
-SymbolicName=ASPNETCORE_EVENT_GENERAL_WARNING_MSG
+SymbolicName=ASPNETCORE_EVENT_GENERAL_WARNING
 Language=English
 %1
 .
 
 Messageid=1027
-SymbolicName=ASPNETCORE_EVENT_GENERAL_ERROR_MSG
+SymbolicName=ASPNETCORE_EVENT_GENERAL_ERROR
 Language=English
 %1
 .

src/AspNetCoreModuleV2/CommonLib/resources.h

@@ -31,8 +31,8 @@
 #define ASPNETCORE_EVENT_MIXED_HOSTING_MODEL_ERROR_MSG       L"Mixed hosting model is not supported. Application '%s' configured with different hostingModel value '%d' other than the one of running application(s)."
 #define ASPNETCORE_EVENT_UNKNOWN_HOSTING_MODEL_ERROR_MSG     L"Unknown hosting model '%s'. Please specify either hostingModel=\"inprocess\" or hostingModel=\"outofprocess\" in the web.config file."
 #define ASPNETCORE_EVENT_ADD_APPLICATION_ERROR_MSG           L"Failed to start application '%s', ErrorCode '0x%x'."
-#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_STDOUT_MSG    L"Application '%s' with physical root '%s' hit unexpected managed background thread exit, ErrorCode = '0x%x. Last 4KB characters of captured stdout and stderr logs:\r\n%s"
+#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_STDOUT_MSG    L"Application '%s' with physical root '%s' hit unexpected managed background thread exit, ErrorCode = '0x%x'. Last 4KB characters of captured stdout and stderr logs:\r\n%s"
-#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_MSG           L"Application '%s' with physical root '%s' hit unexpected managed background thread exit, ErrorCode = '0x%x. Please check the stderr logs for more information."
+#define ASPNETCORE_EVENT_INPROCESS_THREAD_EXIT_MSG           L"Application '%s' with physical root '%s' hit unexpected managed background thread exit, ErrorCode = '0x%x'. Please check the stderr logs for more information."
 #define ASPNETCORE_EVENT_APP_IN_SHUTDOWN_MSG                 L"Application shutting down."
 #define ASPNETCORE_EVENT_RECYCLE_APPOFFLINE_MSG              L"Application '%s' was recycled after detecting the app_offline file."
 #define ASPNETCORE_EVENT_MONITOR_APPOFFLINE_ERROR_MSG        L"Monitoring app_offline.htm failed for application '%s', ErrorCode '0x%x'. "
@@ -43,9 +43,11 @@
 #define ASPNETCORE_EVENT_PORTABLE_APP_DOTNET_MISSING_MSG     L"Could not find dotnet.exe on the system PATH environment variable for portable application '%s'. Check that a valid path to dotnet is on the PATH and the bitness of dotnet matches the bitness of the IIS worker process. ErrorCode = '0x%x'."
 #define ASPNETCORE_EVENT_HOSTFXR_DIRECTORY_NOT_FOUND_MSG     L"Could not find the hostfxr directory '%s' in the dotnet directory. ErrorCode = '0x%x'."
 #define ASPNETCORE_EVENT_HOSTFXR_DLL_NOT_FOUND_MSG           L"Could not find hostfxr.dll in '%s'. ErrorCode = '0x%x'."
+#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_APPLICATION_EXE_NOT_FOUND_LEVEL     EVENTLOG_ERROR_TYPE
 #define ASPNETCORE_EVENT_APPLICATION_EXE_NOT_FOUND_MSG       L"Could not find application executable in '%s'. ErrorCode = '0x%x'."
 #define ASPNETCORE_EVENT_INPROCESS_THREAD_EXCEPTION_MSG      L"Application '%s' with physical root '%s' hit unexpected managed exception, ErrorCode = '0x%x. Please check the stderr logs for more information."
 #define ASPNETCORE_EVENT_INVALID_PROCESS_PATH_MSG            L"Invalid or unknown processPath provided in web.config: processPath = '%s', ErrorCode = '0x%x'."
-#define ASPNETCORE_EVENT_INPROCESS_RH_MISSING_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."
+#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."

src/AspNetCoreModuleV2/CommonLib/sttimer.h

@@ -6,6 +6,7 @@
 
 #ifndef _STTIMER_H
 #define _STTIMER_H
+#include "stringu.h"
 
 class STTIMER
 {

src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp

@@ -102,12 +102,6 @@ IN_PROCESS_APPLICATION::StopInternal(bool fServerInitiated)
         }
     }
 
-    if (m_pLoggerProvider != NULL)
-    {
-        delete m_pLoggerProvider;
-        m_pLoggerProvider = NULL;
-    }
-
 Finished:
 
     if (FAILED(hr))
@@ -256,24 +250,7 @@ IN_PROCESS_APPLICATION::LoadManagedApplication
     }
 
     {
-        // Set up stdout redirect
-
         SRWExclusiveLock lock(m_stateLock);
-        if (m_pLoggerProvider == NULL)
-        {
-            hr =  LoggingHelpers::CreateLoggingProvider(
-                m_pConfig->QueryStdoutLogEnabled(),
-                !GetConsoleWindow(),
-                m_pConfig->QueryStdoutLogFile()->QueryStr(),
-                m_pConfig->QueryApplicationPhysicalPath()->QueryStr(),
-                &m_pLoggerProvider);
-            if (FAILED(hr))
-            {
-                goto Finished;
-            }
-
-            LOG_IF_FAILED(m_pLoggerProvider->Start());
-        }
 
         if (m_status != MANAGED_APPLICATION_STATUS::STARTING)
         {
@@ -461,6 +438,20 @@ IN_PROCESS_APPLICATION::ExecuteApplication(
         FINISHED_IF_FAILED(SetEnvironementVariablesOnWorkerProcess());
     }
 
+    LOG_INFO("Starting managed application");
+
+    if (m_pLoggerProvider == NULL)
+    {
+        FINISHED_IF_FAILED(hr = LoggingHelpers::CreateLoggingProvider(
+            m_pConfig->QueryStdoutLogEnabled(),
+            !m_pHttpServer.IsCommandLineLaunch(),
+            m_pConfig->QueryStdoutLogFile()->QueryStr(),
+            m_pConfig->QueryApplicationPhysicalPath()->QueryStr(),
+            m_pLoggerProvider));
+
+        LOG_IF_FAILED(m_pLoggerProvider->Start());
+    }
+
     // There can only ever be a single instance of .NET Core
     // loaded in the process but we need to get config information to boot it up in the
     // first place. This is happening in an execute request handler and everyone waits
@@ -482,7 +473,7 @@ Finished:
     //
     m_status = MANAGED_APPLICATION_STATUS::SHUTDOWN;
     m_fShutdownCalledFromManaged = TRUE;
-    FreeLibrary(hModule);
+
     m_pLoggerProvider->Stop();
 
     if (!m_fShutdownCalledFromNative)
@@ -545,7 +536,6 @@ IN_PROCESS_APPLICATION::RunDotnetApplication(DWORD argc, CONST PCWSTR* argv, hos
 
     __try
     {
-        LOG_INFO("Starting managed application");
         m_ProcessExitCode = pProc(argc, argv);
         if (m_ProcessExitCode != 0)
         {

src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.h

@@ -150,7 +150,7 @@ private:
 
     static IN_PROCESS_APPLICATION*  s_Application;
 
-    IOutputManager*                 m_pLoggerProvider;
+    std::unique_ptr<IOutputManager> m_pLoggerProvider;
 
     static const LPCSTR             s_exeLocationParameterName;
 

src/AspNetCoreModuleV2/RequestHandlerLib/FileOutputManager.cpp

@@ -1,195 +0,0 @@
-// 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 "FileOutputManager.h"
-#include "sttimer.h"
-#include "exceptions.h"
-#include "debugutil.h"
-#include "SRWExclusiveLock.h"
-#include "file_utility.h"
-
-FileOutputManager::FileOutputManager() :
-    m_hLogFileHandle(INVALID_HANDLE_VALUE),
-    m_fdPreviousStdOut(-1),
-    m_fdPreviousStdErr(-1),
-    m_disposed(false)
-{
-    InitializeSRWLock(&m_srwLock);
-}
-
-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;
-}
-
-bool FileOutputManager::GetStdOutContent(STRA* struStdOutput)
-{
-    //
-    // Ungraceful shutdown, try to log an error message.
-    // This will be a common place for errors as it means the hostfxr_main returned
-    // or there was an exception.
-    //
-    CHAR            pzFileContents[4096] = { 0 };
-    DWORD           dwNumBytesRead;
-    LARGE_INTEGER   li = { 0 };
-    BOOL            fLogged = FALSE;
-    DWORD           dwFilePointer = 0;
-
-    if (m_hLogFileHandle != INVALID_HANDLE_VALUE)
-    {
-        if (GetFileSizeEx(m_hLogFileHandle, &li) && li.LowPart > 0 && li.HighPart == 0)
-        {
-            if (li.LowPart > 4096)
-            {
-                dwFilePointer = SetFilePointer(m_hLogFileHandle, -4096, NULL, FILE_END);
-            }
-            else
-            {
-                dwFilePointer = SetFilePointer(m_hLogFileHandle, 0, NULL, FILE_BEGIN);
-            }
-
-            if (dwFilePointer != INVALID_SET_FILE_POINTER)
-            {
-                // Read file fails.
-                if (ReadFile(m_hLogFileHandle, pzFileContents, 4096, &dwNumBytesRead, NULL))
-                {
-                    if (SUCCEEDED(struStdOutput->Copy(pzFileContents, dwNumBytesRead)))
-                    {
-                        fLogged = TRUE;
-                    }
-                }
-            }
-        }
-    }
-
-    return fLogged;
-}
-
-HRESULT
-FileOutputManager::Start()
-{
-    SYSTEMTIME systemTime;
-    SECURITY_ATTRIBUTES saAttr = { 0 };
-    STRU struPath;
-
-    RETURN_IF_FAILED(FILE_UTILITY::ConvertPathToFullPath(
-        m_wsStdOutLogFileName.QueryStr(),
-        m_wsApplicationPath.QueryStr(),
-        &struPath));
-
-    RETURN_IF_FAILED(FILE_UTILITY::EnsureDirectoryPathExist(struPath.QueryStr()));
-
-    GetSystemTime(&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()));
-
-    m_fdPreviousStdOut = _dup(_fileno(stdout));
-    m_fdPreviousStdErr = _dup(_fileno(stderr));
-
-    m_hLogFileHandle = CreateFileW(m_struLogFilePath.QueryStr(),
-        FILE_READ_DATA | FILE_WRITE_DATA,
-        FILE_SHARE_READ,
-        &saAttr,
-        CREATE_ALWAYS,
-        FILE_ATTRIBUTE_NORMAL,
-        NULL);
-
-    if (m_hLogFileHandle == INVALID_HANDLE_VALUE)
-    {
-        return LOG_IF_FAILED(HRESULT_FROM_WIN32(GetLastError()));
-    }
-
-    // There are a few options for redirecting stdout/stderr,
-    // but there are issues with most of them.
-    // AllocConsole()
-    // *stdout = *m_pStdFile;
-    // *stderr = *m_pStdFile;
-    // Calling _dup2 on stderr fails on IIS. IIS sets stderr to -2
-    // _dup2(_fileno(m_pStdFile), _fileno(stdout));
-    // _dup2(_fileno(m_pStdFile), _fileno(stderr));
-    // If we were okay setting stdout and stderr to separate files, we could use:
-    // _wfreopen_s(&m_pStdFile, struLogFileName.QueryStr(), L"w+", stdout);
-    // _wfreopen_s(&m_pStdFile, struLogFileName.QueryStr(), L"w+", stderr);
-    // Calling SetStdHandle works for redirecting managed logs, however you cannot
-    // capture native logs (including hostfxr failures).
-
-    RETURN_LAST_ERROR_IF(!SetStdHandle(STD_OUTPUT_HANDLE, m_hLogFileHandle));
-
-    RETURN_LAST_ERROR_IF(!SetStdHandle(STD_ERROR_HANDLE, m_hLogFileHandle));
-
-    // Periodically flush the log content to file
-    m_Timer.InitializeTimer(STTIMER::TimerCallback, &m_struLogFilePath, 3000, 3000);
-
-    LOG_INFOF("Created log file for inprocess application: %S",
-        m_struLogFilePath.QueryStr());
-
-    return S_OK;
-}
-
-
-HRESULT
-FileOutputManager::Stop()
-{
-    if (m_disposed)
-    {
-        return S_OK;
-    }
-    SRWExclusiveLock lock(m_srwLock);
-    if (m_disposed)
-    {
-        return S_OK;
-    }
-    m_disposed = true;
-
-    HANDLE   handle = NULL;
-    WIN32_FIND_DATA fileData;
-
-    if (m_hLogFileHandle != INVALID_HANDLE_VALUE)
-    {
-        m_Timer.CancelTimer();
-    }
-
-    // delete empty log file
-    handle = FindFirstFile(m_struLogFilePath.QueryStr(), &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()));
-    }
-
-    if (m_fdPreviousStdOut >= 0)
-    {
-        LOG_LAST_ERROR_IF(!SetStdHandle(STD_OUTPUT_HANDLE, (HANDLE)_get_osfhandle(m_fdPreviousStdOut)));
-        LOG_INFOF("Restoring original stdout: %d", m_fdPreviousStdOut);
-    }
-
-    if (m_fdPreviousStdErr >= 0)
-    {
-        LOG_LAST_ERROR_IF(!SetStdHandle(STD_ERROR_HANDLE, (HANDLE)_get_osfhandle(m_fdPreviousStdErr)));
-        LOG_INFOF("Restoring original stderr: %d", m_fdPreviousStdOut);
-    }
-
-    return S_OK;
-}

src/AspNetCoreModuleV2/RequestHandlerLib/RequestHandlerLib.vcxproj

@@ -193,22 +193,14 @@
     <ClInclude Include="AppOfflineTrackingApplication.h" />
     <ClInclude Include="environmentvariablehelpers.h" />
     <ClInclude Include="filewatcher.h" />
-    <ClInclude Include="NullOutputManager.h" />
-    <ClInclude Include="FileOutputManager.h" />
     <ClInclude Include="environmentvariablehash.h" />
-    <ClInclude Include="IOutputManager.h" />
-    <ClInclude Include="LoggingHelpers.h" />
-    <ClInclude Include="PipeOutputManager.h" />
     <ClInclude Include="requesthandler_config.h" />
     <ClInclude Include="stdafx.h" />
   </ItemGroup>
   <ItemGroup>
     <ClCompile Include="AppOfflineTrackingApplication.cpp" />
-    <ClCompile Include="FileOutputManager.cpp" />
     <ClCompile Include="filewatcher.cpp" />
     <ClCompile Include="requesthandler_config.cpp" />
-    <ClCompile Include="LoggingHelpers.cpp" />
-    <ClCompile Include="PipeOutputManager.cpp" />
   </ItemGroup>
   <ItemGroup>
     <ProjectReference Include="..\CommonLib\CommonLib.vcxproj">

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

@@ -44,6 +44,11 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
         }
 
         public override void Dispose()
+        {
+            Dispose(gracefulShutdown: false);
+        }
+
+        public override void Dispose(bool gracefulShutdown)
         {
             Stop();
 
@@ -128,6 +133,8 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
             }
         }
 
+
+
         private void GetLogsFromFile()
         {
             try

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

@@ -151,5 +151,7 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                 .GetOrAdd("add", "name", ancmVersion)
                 .SetAttributeValue("image", GetAncmLocation(DeploymentParameters.AncmVersion));
         }
+
+        public abstract void Dispose(bool gracefulShutdown);
     }
 }

src/Microsoft.AspNetCore.Server.IntegrationTesting.IIS/IISDeploymentParameterExtensions.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.IO;
 using System.Linq;
 using System.Xml.Linq;
 
@@ -50,5 +51,14 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                         .SetAttributeValue("enabled", "true");
                 });
         }
+
+        public static void EnableLogging(this IISDeploymentParameters deploymentParameters, string path)
+        {
+            deploymentParameters.WebConfigActionList.Add(
+                WebConfigHelpers.AddOrModifyAspNetCoreSection("stdoutLogEnabled", "true"));
+
+            deploymentParameters.WebConfigActionList.Add(
+                WebConfigHelpers.AddOrModifyAspNetCoreSection("stdoutLogFile", Path.Combine(path, "std")));
+        }
     }
 }

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

@@ -37,7 +37,6 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
                 ServerConfigActionList = tempParameters.ServerConfigActionList;
                 WebConfigBasedEnvironmentVariables = tempParameters.WebConfigBasedEnvironmentVariables;
                 HandlerSettings = tempParameters.HandlerSettings;
-                GracefulShutdown = tempParameters.GracefulShutdown;
             }
         }
 
@@ -49,7 +48,5 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
 
         public IDictionary<string, string> HandlerSettings { get; set; } = new Dictionary<string, string>();
 
-        public bool GracefulShutdown { get; set; }
-
     }
 }

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

@@ -28,7 +28,7 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
         private const string FailedToInitializeBindingsMessage = "Failed to initialize site bindings";
         private const string UnableToStartIISExpressMessage = "Unable to start iisexpress.";
         private const int MaximumAttempts = 5;
-        private readonly TimeSpan ShutdownTimeSpan = TimeSpan.FromSeconds(60);
+        private readonly TimeSpan ShutdownTimeSpan = Debugger.IsAttached ? TimeSpan.FromMinutes(60) : TimeSpan.FromMinutes(1);
         private static readonly Regex UrlDetectorRegex = new Regex(@"^\s*Successfully registered URL ""(?<url>[^""]+)"" for site.*$");
 
         private Process _hostProcess;
@@ -381,10 +381,15 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting.IIS
         }
 
         public override void Dispose()
+        {
+            Dispose(gracefulShutdown: false);
+        }
+
+        public override void Dispose(bool gracefulShutdown)
         {
             using (Logger.BeginScope("Dispose"))
             {
-                if (IISDeploymentParameters.GracefulShutdown)
+                if (gracefulShutdown)
                 {
                     GracefullyShutdownProcess(_hostProcess);
                 }

test/Common.FunctionalTests/Inprocess/EventLogTests.cs

@@ -23,8 +23,9 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         public async Task CheckStartupEventLogMessage()
         {
             var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
+            
             var deploymentResult = await DeployAsync(deploymentParameters);
-            await Helpers.AssertStarts(deploymentResult);
+            await deploymentResult.AssertStarts();
 
             StopServer();
 
@@ -35,9 +36,8 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         public async Task CheckShutdownEventLogMessage()
         {
             var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
-            deploymentParameters.GracefulShutdown = true;
             var deploymentResult = await DeployAsync(deploymentParameters);
-            await Helpers.AssertStarts(deploymentResult);
+            await deploymentResult.AssertStarts();
 
             StopServer();
 

test/Common.FunctionalTests/Inprocess/LoggingTests.cs

@@ -2,7 +2,6 @@
 // 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;
@@ -47,20 +46,14 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
 
                 StopServer();
 
-                var fileInDirectory = Directory.GetFiles(pathToLogs).Single();
+                var fileInDirectory = Directory.GetFiles(pathToLogs).Single(fileName => fileName.Contains("inprocess"));
-
                 var contents = File.ReadAllText(fileInDirectory);
 
                 Assert.NotNull(contents);
                 Assert.Contains("TEST MESSAGE", contents);
-                Assert.DoesNotContain(TestSink.Writes, context => context.Message.Contains("TEST MESSAGE"));
-                // TODO we should check that debug logs are restored during graceful shutdown.
-                // The IIS Express deployer doesn't support graceful shutdown.
-                //Assert.Contains(TestSink.Writes, context => context.Message.Contains("Restoring original stdout: "));
             }
             finally
             {
-
                 RetryHelper.RetryOperation(
                     () => Directory.Delete(pathToLogs, true),
                     e => Logger.LogWarning($"Failed to delete directory : {e.Message}"),
@@ -132,7 +125,6 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         public async Task CheckStdoutLoggingToPipe_DoesNotCrashProcess(string path)
         {
             var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
-            deploymentParameters.GracefulShutdown = true;
             var deploymentResult = await DeployAsync(deploymentParameters);
 
             await Helpers.AssertStarts(deploymentResult, path);
@@ -151,7 +143,6 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         public async Task CheckStdoutLoggingToPipeWithFirstWrite(string path)
         {
             var deploymentParameters = _fixture.GetBaseDeploymentParameters(publish: true);
-            deploymentParameters.GracefulShutdown = true;
 
             var firstWriteString = path + path;
 

test/Common.FunctionalTests/MultiApplicationTests.cs

@@ -44,6 +44,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         {
             var parameters = _fixture.GetBaseDeploymentParameters(HostingModel.InProcess, publish: true);
             parameters.ServerConfigActionList.Add(DuplicateApplication);
+
             var result = await DeployAsync(parameters);
             var result1 = await result.HttpClient.GetAsync("/app1/HelloWorld");
             var result2 = await result.HttpClient.GetAsync("/app2/HelloWorld");

test/Common.FunctionalTests/Utilities/EventLogHelpers.cs

@@ -1,6 +1,8 @@
 // Copyright (c) .NET Foundation. All rights reserved.
 // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
 
+using System.Linq;
+using System.Text;
 using System.Text.RegularExpressions;
 using Microsoft.AspNetCore.Server.IntegrationTesting.IIS;
 using Microsoft.Extensions.Logging.Testing;
@@ -14,17 +16,16 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         {
             Assert.True(deploymentResult.HostProcess.HasExited);
 
-            var eventLogRegex = new Regex($"Event Log: {expectedRegexMatchString}");
+            var builder = new StringBuilder();
 
-            int count = 0;
             foreach (var context in testSink.Writes)
             {
-                if (eventLogRegex.IsMatch(context.Message))
+                builder.Append(context.Message);
-                {
-                    count++;
-                }
             }
-            Assert.Equal(1, count);
+
+            var eventLogRegex = new Regex($"Event Log: (.*?){expectedRegexMatchString}(.*?)End Event Log Message.", RegexOptions.Singleline);
+
+            Assert.Matches(eventLogRegex, builder.ToString());
         }
     }
 }

test/Common.FunctionalTests/Utilities/FunctionalTestsBase.cs

@@ -18,7 +18,7 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting
         {
         }
 
-        protected ApplicationDeployer _deployer;
+        protected IISDeployerBase _deployer;
 
         protected ApplicationDeployer CreateDeployer(IISDeploymentParameters parameters)
         {
@@ -38,18 +38,18 @@ namespace Microsoft.AspNetCore.Server.IntegrationTesting
 
         protected virtual async Task<IISDeploymentResult> DeployAsync(IISDeploymentParameters parameters)
         {
-            _deployer = CreateDeployer(parameters);
+            _deployer = (IISDeployerBase)CreateDeployer(parameters);
             return (IISDeploymentResult)await _deployer.DeployAsync();
         }
 
         public override void Dispose()
         {
-            StopServer();
+            StopServer(false);
         }
 
-        public void StopServer()
+        public void StopServer(bool gracefulShutdown = true)
         {
-            _deployer?.Dispose();
+            _deployer?.Dispose(gracefulShutdown);
             _deployer = null;
         }
     }

test/Common.FunctionalTests/Utilities/SkipIfDebugAttribute.cs

@@ -0,0 +1,22 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System;
+using Microsoft.AspNetCore.Server.IntegrationTesting;
+using Microsoft.AspNetCore.Testing.xunit;
+
+namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
+{
+    [AttributeUsage(AttributeTargets.Assembly | AttributeTargets.Class | AttributeTargets.Method)]
+    public sealed class SkipIfDebugAttribute : Attribute, ITestCondition
+    {
+        public bool IsMet =>
+        #if DEBUG
+            false;
+        #else 
+            true;
+        #endif
+
+        public string SkipReason => "Test cannot be run in Debug mode.";
+    }
+}

test/CommonLibTests/FileOutputManagerTests.cpp

@@ -34,6 +34,7 @@ namespace FileOutManagerStartupTests
 
             auto tempDirectory = TempDirectory();
             FileOutputManager* pManager = new FileOutputManager;
+
             pManager->Initialize(fileNamePrefix.c_str(), tempDirectory.path().c_str());
             {
                 FileManagerWrapper wrapper(pManager);
@@ -47,19 +48,17 @@ namespace FileOutManagerStartupTests
                 ASSERT_EQ(filename.substr(0, fileNamePrefix.size()), fileNamePrefix);
 
                 std::wstring content = Helpers::ReadFileContent(std::wstring(p.path()));
-                ASSERT_EQ(content.length(), DWORD(4));
-                ASSERT_STREQ(content.c_str(), expected);
             }
         }
     };
 
-    TEST_F(FileOutputManagerTest, DISABLED_WriteToFileCheckContentsWritten)
+    TEST_F(FileOutputManagerTest, WriteToFileCheckContentsWritten)
     {
         Test(L"", stdout);
         Test(L"log", stdout);
     }
 
-    TEST_F(FileOutputManagerTest, DISABLED_WriteToFileCheckContentsWrittenErr)
+    TEST_F(FileOutputManagerTest, WriteToFileCheckContentsWrittenErr)
     {
         Test(L"", stderr);
         Test(L"log", stderr);
@@ -68,8 +67,7 @@ namespace FileOutManagerStartupTests
 
 namespace FileOutManagerOutputTests
 {
-
+    TEST(FileOutManagerOutputTest, StdOut)
-    TEST(FileOutManagerOutputTest, DISABLED_StdErr)
     {
         PCSTR expected = "test";
 
@@ -80,7 +78,9 @@ namespace FileOutManagerOutputTests
         {
             FileManagerWrapper wrapper(pManager);
 
-            printf(expected, stderr);
+            fprintf(stdout, expected);
+            pManager->Stop();
+
             STRA straContent;
             ASSERT_TRUE(pManager->GetStdOutContent(&straContent));
 
@@ -88,7 +88,7 @@ namespace FileOutManagerOutputTests
         }
     }
 
-    TEST(FileOutManagerOutputTest, DISABLED_CheckFileOutput)
+    TEST(FileOutManagerOutputTest, StdErr)
     {
         PCSTR expected = "test";
 
@@ -99,7 +99,9 @@ namespace FileOutManagerOutputTests
         {
             FileManagerWrapper wrapper(pManager);
 
-            printf(expected);
+            fprintf(stderr, expected);
+            pManager->Stop();
+
             STRA straContent;
             ASSERT_TRUE(pManager->GetStdOutContent(&straContent));
 
@@ -107,9 +109,9 @@ namespace FileOutManagerOutputTests
         }
     }
 
-    TEST(FileOutManagerOutputTest, DISABLED_CapAt4KB)
+    TEST(FileOutManagerOutputTest, CapAt30KB)
     {
-        PCSTR expected = "test";
+        PCSTR expected = "hello world";
 
         auto tempDirectory = TempDirectory();
 
@@ -118,16 +120,39 @@ namespace FileOutManagerOutputTests
         {
             FileManagerWrapper wrapper(pManager);
 
-            for (int i = 0; i < 1200; i++)
+            for (int i = 0; i < 3000; i++)
             {
                 printf(expected);
             }
-
+            pManager->Stop();
             STRA straContent;
             ASSERT_TRUE(pManager->GetStdOutContent(&straContent));
 
-            ASSERT_EQ(straContent.QueryCCH(), 4096);
+            ASSERT_EQ(straContent.QueryCCH(), 30000);
+        }
+    }
+
+
+    TEST(FileOutManagerOutputTest, StartStopRestoresCorrectly)
+    {
+        PCSTR expected = "test";
+
+        auto tempDirectory = TempDirectory();
+
+        for (int i = 0; i < 10; i++)
+        {
+            FileOutputManager* pManager = new FileOutputManager;
+            pManager->Initialize(L"", tempDirectory.path().c_str());
+            {
+                FileManagerWrapper wrapper(pManager);
+
+                printf(expected);
+                pManager->Stop();
+                STRA straContent;
+                ASSERT_TRUE(pManager->GetStdOutContent(&straContent));
+
+                ASSERT_STREQ(straContent.QueryStr(), expected);
+            }
         }
     }
 }
-

test/CommonLibTests/PipeOutputManagerTests.cpp

@@ -23,14 +23,58 @@ public:
 
 namespace PipeOutputManagerTests
 {
-    TEST(PipeManagerOutputTest, NotifyStartupCompleteCallsDispose)
+    TEST(PipeManagerOutputTest, StdOut)
     {
         PCWSTR expected = L"test";
+        STRA output;
+
+        PipeOutputManager* pManager = new PipeOutputManager(true);
 
-        PipeOutputManager* pManager = new PipeOutputManager();
         ASSERT_EQ(S_OK, pManager->Start());
+        fwprintf(stdout, expected);
+
+        ASSERT_EQ(S_OK, pManager->Stop());
+
+        pManager->GetStdOutContent(&output);
+        ASSERT_STREQ(output.QueryStr(), "test");
+        delete pManager;
     }
 
+    TEST(PipeManagerOutputTest, StdErr)
+    {
+        PCWSTR expected = L"test";
+        STRA output;
+
+        PipeOutputManager* pManager = new PipeOutputManager();
+
+        ASSERT_EQ(S_OK, pManager->Start());
+        fwprintf(stderr, expected);
+        ASSERT_EQ(S_OK, pManager->Stop());
+
+        pManager->GetStdOutContent(&output);
+        ASSERT_STREQ(output.QueryStr(), "test");
+        delete pManager;
+    }
+
+    TEST(PipeManagerOutputTest, CheckMaxPipeSize)
+    {
+        std::wstring test;
+        STRA output;
+        for (int i = 0; i < 3000; i++)
+        {
+            test.append(L"hello world");
+        }
+
+        PipeOutputManager* pManager = new PipeOutputManager();
+
+        ASSERT_EQ(S_OK, pManager->Start());
+        wprintf(test.c_str());
+        ASSERT_EQ(S_OK, pManager->Stop());
+
+        pManager->GetStdOutContent(&output);
+        ASSERT_EQ(output.QueryCCH(), (DWORD)30000);
+        delete pManager;
+    }
     TEST(PipeManagerOutputTest, SetInvalidHandlesForErrAndOut)
     {
         auto m_fdPreviousStdOut = _dup(_fileno(stdout));
@@ -50,6 +94,61 @@ namespace PipeOutputManagerTests
         // Test will fail if we didn't redirect stdout back to a file descriptor.
         // This is because gtest relies on console output to know if a test succeeded or failed.
         // If the output still points to a file/pipe, the test (and all other tests after it) will fail.
+        delete pManager;
+    }
+
+    TEST(PipeManagerOutputTest, CreateDeleteMultipleTimesStdOutWorks)
+    {
+        for (int i = 0; i < 10; i++)
+        {
+            auto stdoutBefore = _fileno(stdout);
+            auto stderrBefore = _fileno(stderr);
+            PCWSTR expected = L"test";
+            STRA output;
+
+            PipeOutputManager* pManager = new PipeOutputManager();
+
+            ASSERT_EQ(S_OK, pManager->Start());
+            fwprintf(stdout, expected);
+
+            ASSERT_EQ(S_OK, pManager->Stop());
+
+            pManager->GetStdOutContent(&output);
+            ASSERT_STREQ(output.QueryStr(), "test");
+            ASSERT_EQ(stdoutBefore, _fileno(stdout));
+            ASSERT_EQ(stderrBefore, _fileno(stderr));
+            delete pManager;
+        }
+        // When this returns, we get an AV from gtest.
+    }
+
+    TEST(PipeManagerOutputTest, CreateDeleteKeepOriginalStdErr)
+    {
+        for (int i = 0; i < 10; i++)
+        {
+            auto stdoutBefore = _fileno(stdout);
+            auto stderrBefore = _fileno(stderr);
+            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());
+            fwprintf(stderr, expected);
+            ASSERT_EQ(S_OK, pManager->Stop());
+
+            pManager->GetStdOutContent(&output);
+            ASSERT_STREQ(output.QueryStr(), "test");
+            ASSERT_EQ(stdoutBefore, _fileno(stdout));
+
+            ASSERT_EQ(stderrBefore, _fileno(stderr));
+
+            delete pManager;
+        }
+
+        wprintf(L"Hello!");
     }
 }
 

test/IIS.FunctionalTests/Inprocess/StdOutRedirectionTests.cs

@@ -0,0 +1,171 @@
+// Copyright (c) .NET Foundation. All rights reserved.
+// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
+
+using System;
+using System.IO;
+using System.Linq;
+using System.Threading.Tasks;
+using Microsoft.AspNetCore.Server.IIS.FunctionalTests.Utilities;
+using Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests;
+using Microsoft.AspNetCore.Server.IntegrationTesting;
+using Microsoft.AspNetCore.Server.IntegrationTesting.IIS;
+using Microsoft.AspNetCore.Testing.xunit;
+using Newtonsoft.Json;
+using Xunit;
+
+namespace IIS.FunctionalTests.Inprocess
+{
+    [Collection(PublishedSitesCollection.Name)]
+    public class StdOutRedirectionTests : IISFunctionalTestBase
+    {
+        private readonly PublishedSitesFixture _fixture;
+        private readonly string _logFolderPath;
+
+        public StdOutRedirectionTests(PublishedSitesFixture fixture)
+        {
+            _logFolderPath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString());
+            _fixture = fixture;
+        }
+
+        public override void Dispose()
+        {
+            base.Dispose();
+            if (Directory.Exists(_logFolderPath))
+            {
+                Directory.Delete(_logFolderPath, true);
+            }
+        }
+
+        [ConditionalFact]
+        [SkipIfDebug]
+        public async Task FrameworkNotFoundExceptionLogged_Pipe()
+        {
+            var deploymentParameters = _fixture.GetBaseDeploymentParameters(_fixture.StartupExceptionWebsite, publish: true);
+
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            InvalidateRuntimeConfig(deploymentResult);
+
+            var response = await deploymentResult.HttpClient.GetAsync("/");
+            Assert.False(response.IsSuccessStatusCode);
+
+            StopServer();
+
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult, TestSink,
+                "The specified framework 'Microsoft.NETCore.App', version '2.9.9' was not found.");
+        }
+
+        [ConditionalFact]
+        [SkipIfDebug]
+        public async Task FrameworkNotFoundExceptionLogged_File()
+        {
+            var deploymentParameters =
+                _fixture.GetBaseDeploymentParameters(_fixture.StartupExceptionWebsite, publish: true);
+
+            deploymentParameters.EnableLogging(_logFolderPath);
+
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            InvalidateRuntimeConfig(deploymentResult);
+
+            var response = await deploymentResult.HttpClient.GetAsync("/");
+            Assert.False(response.IsSuccessStatusCode);
+
+            StopServer();
+
+            var fileInDirectory = Directory.GetFiles(_logFolderPath).Single();
+            var contents = File.ReadAllText(fileInDirectory);
+            var expectedString = "The specified framework 'Microsoft.NETCore.App', version '2.9.9' was not found.";
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult, TestSink, expectedString);
+            Assert.Contains(expectedString, contents);
+        }
+
+        [ConditionalFact]
+        [SkipIfDebug]
+        public async Task EnableCoreHostTraceLogging_TwoLogFilesCreated()
+        {
+            var deploymentParameters =
+                _fixture.GetBaseDeploymentParameters(_fixture.StartupExceptionWebsite, publish: true);
+            deploymentParameters.EnvironmentVariables["COREHOST_TRACE"] = "1";
+
+            deploymentParameters.EnableLogging(_logFolderPath);
+
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            var response = await deploymentResult.HttpClient.GetAsync("/");
+            Assert.False(response.IsSuccessStatusCode);
+
+            StopServer();
+
+            var filesInDirectory = Directory.GetFiles(_logFolderPath);
+            Assert.Equal(2, filesInDirectory.Length);
+            foreach (var file in filesInDirectory)
+            {
+                var contents = File.ReadAllText(file);
+                EventLogHelpers.VerifyEventLogEvent(deploymentResult, TestSink, "Invoked hostfxr");
+                Assert.Contains("Invoked hostfxr", contents);
+            }
+        }
+
+        [ConditionalTheory]
+        [SkipIfDebug]
+        [InlineData("CheckLargeStdErrWrites")]
+        [InlineData("CheckLargeStdOutWrites")]
+        [InlineData("CheckOversizedStdErrWrites")]
+        [InlineData("CheckOversizedStdOutWrites")]
+        public async Task EnableCoreHostTraceLogging_PipeCaptureNativeLogs(string path)
+        {
+            var deploymentParameters = _fixture.GetBaseDeploymentParameters(_fixture.StartupExceptionWebsite, publish: true);
+            deploymentParameters.EnvironmentVariables["COREHOST_TRACE"] = "1";
+            deploymentParameters.WebConfigBasedEnvironmentVariables["ASPNETCORE_INPROCESS_STARTUP_VALUE"] = path;
+
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            var response = await deploymentResult.HttpClient.GetAsync("/");
+
+            Assert.False(response.IsSuccessStatusCode);
+
+            StopServer();
+
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult, TestSink, "Invoked hostfxr");
+        }
+
+        [ConditionalTheory]
+        [SkipIfDebug]
+        [InlineData("CheckLargeStdErrWrites")]
+        [InlineData("CheckLargeStdOutWrites")]
+        [InlineData("CheckOversizedStdErrWrites")]
+        [InlineData("CheckOversizedStdOutWrites")]
+        public async Task EnableCoreHostTraceLogging_FileCaptureNativeLogs(string path)
+        {
+            var deploymentParameters =
+                _fixture.GetBaseDeploymentParameters(_fixture.StartupExceptionWebsite, publish: true);
+            deploymentParameters.EnvironmentVariables["COREHOST_TRACE"] = "1";
+            deploymentParameters.WebConfigBasedEnvironmentVariables["ASPNETCORE_INPROCESS_STARTUP_VALUE"] = path;
+
+            deploymentParameters.EnableLogging(_logFolderPath);
+
+            var deploymentResult = await DeployAsync(deploymentParameters);
+
+            var response = await deploymentResult.HttpClient.GetAsync("/");
+            Assert.False(response.IsSuccessStatusCode);
+
+            StopServer();
+
+            var fileInDirectory = Directory.GetFiles(_logFolderPath).First();
+            var contents = File.ReadAllText(fileInDirectory);
+
+            EventLogHelpers.VerifyEventLogEvent(deploymentResult, TestSink, "Invoked hostfxr");
+            Assert.Contains("Invoked hostfxr", contents);
+        }
+
+        private static void InvalidateRuntimeConfig(IISDeploymentResult deploymentResult)
+        {
+            var path = Path.Combine(deploymentResult.ContentRoot, "StartupExceptionWebSite.runtimeconfig.json");
+            dynamic depsFileContent = JsonConvert.DeserializeObject(File.ReadAllText(path));
+            depsFileContent["runtimeOptions"]["framework"]["version"] = "2.9.9";
+            var output = JsonConvert.SerializeObject(depsFileContent);
+            File.WriteAllText(path, output);
+        }
+    }
+}

test/IISExpress.FunctionalTests/InProcess/ShutdownTests.cs

@@ -42,22 +42,21 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
         public async Task GracefulShutdown_DoesNotCrashProcess()
         {
             var parameters = _fixture.GetBaseDeploymentParameters(publish: true);
-            parameters.GracefulShutdown = true;
             var result = await DeployAsync(parameters);
 
             var response = await result.HttpClient.GetAsync("/HelloWorld");
-            StopServer();
+            StopServer(gracefulShutdown: true);
             Assert.True(result.HostProcess.ExitCode == 0);
         }
 
         [ConditionalFact]
-        public async Task ForcefulShutdown_DoesrashProcess()
+        public async Task ForcefulShutdown_DoesCrashProcess()
         {
             var parameters = _fixture.GetBaseDeploymentParameters(publish: true);
             var result = await DeployAsync(parameters);
 
             var response = await result.HttpClient.GetAsync("/HelloWorld");
-            StopServer();
+            StopServer(gracefulShutdown: false);
             Assert.True(result.HostProcess.ExitCode == 1);
         }
     }