Include failed HRESULTs and exceptions in FREB log (#1548)

src/AspNetCoreModuleV2/AspNetCore/AppOfflineHandler.cpp

@@ -5,7 +5,7 @@
 
 #include "HandleWrapper.h"
 
-REQUEST_NOTIFICATION_STATUS AppOfflineHandler::OnExecuteRequestHandler()
+REQUEST_NOTIFICATION_STATUS AppOfflineHandler::ExecuteRequestHandler()
 {
     HTTP_DATA_CHUNK   DataChunk {};
     auto pResponse = m_pContext.GetResponse();

src/AspNetCoreModuleV2/AspNetCore/AppOfflineHandler.h

@@ -10,12 +10,13 @@ class AppOfflineHandler: public REQUEST_HANDLER
 {
 public:
     AppOfflineHandler(IHttpContext& pContext, const std::string appOfflineContent)
-        : m_pContext(pContext),
+        : REQUEST_HANDLER(pContext),
+          m_pContext(pContext),
           m_strAppOfflineContent(appOfflineContent)
     {
     }
 
-    REQUEST_NOTIFICATION_STATUS OnExecuteRequestHandler() override;
+    REQUEST_NOTIFICATION_STATUS ExecuteRequestHandler() override;
 
 private:
     IHttpContext& m_pContext;

src/AspNetCoreModuleV2/AspNetCore/ApplicationFactory.h

@@ -34,9 +34,11 @@ public:
         _In_  IHttpContext          *pHttpContext,
         _Outptr_ IAPPLICATION       **pApplication) const
     {
+        // m_location.data() is const ptr copy to local to get mutable pointer
+        auto location = m_location;
         std::array<APPLICATION_PARAMETER, 2> parameters {
             {
-                {"InProcessExeLocation", m_location.data()},
+                {"InProcessExeLocation", location.data()},
                 {"TraceContext", pHttpContext->GetTraceContext()}
             }
         };

src/AspNetCoreModuleV2/AspNetCore/ancm.mof

@@ -5,7 +5,7 @@
 /*
  * AspNetCore module trace events layout
  * Uncomment the following class to run mof2trace to generate header file
- * comment it back before checking it in 
+ * comment it back before checking it in
 [Dynamic,
   Description("IIS: WWW Server"),
   Guid("{3a2a4e84-4c21-4981-ae10-3fda0d9b0f83}"),
@@ -187,7 +187,7 @@ class ANCMWinHttpCallBack:ANCM_Events
 
 [Dynamic,
  Description("Starting inprocess execute request") : amended,
- EventType(8),
+ EventType(7),
  EventLevel(4),
  EventTypeName("ANCM_INPROC_EXECUTE_REQUEST_START") : amended
 ]
@@ -203,7 +203,7 @@ class ANCMExecuteStart:ANCM_Events
 
 [Dynamic,
  Description("Ending inprocess execute request") : amended,
- EventType(10),
+ EventType(8),
  EventLevel(5),
  EventTypeName("ANCM_INPROC_EXECUTE_REQUEST_COMPLETION") : amended
 ]
@@ -224,7 +224,7 @@ class ANCMExecuteEnd:ANCM_Events
 
 [Dynamic,
  Description("Starting inprocess async completion") : amended,
- EventType(8),
+ EventType(9),
  EventLevel(5),
  EventTypeName("ANCM_INPROC_ASYNC_COMPLETION_START") : amended
 ]
@@ -293,7 +293,7 @@ class ANCMRequestDisconnect:ANCM_Events
 
 [Dynamic,
  Description("Indicate managed request complete") : amended,
- EventType(12),
+ EventType(13),
  EventLevel(4),
  EventTypeName("ANCM_INPROC_MANAGED_REQUEST_COMPLETION") : amended
 ]
@@ -306,3 +306,66 @@ class ANCMManagedRequestCompletion:ANCM_Events
      read]
      object  ContextId;
 };
+
+[Dynamic,
+ Description("Failed HRESULT") : amended,
+ EventType(14),
+ EventLevel(3),
+ EventTypeName("ANCM_HRESULT_FAILED") : amended
+]
+class ANCMHRESULTFailed:ANCM_Events
+{
+    [WmiDataId(1),
+     Description("Context ID") : amended,
+     extension("Guid"),
+     ActivityID,
+     read]
+     object  ContextId;
+     [WmiDataId(2),
+     Description("Failed source file location") : amended,
+     StringTermination("NullTerminated"),
+     read]
+     string File;
+     [WmiDataId(3),
+     Description("Failed line number") : amended,
+     format("d"),
+     read]
+     uint32 Line;
+     [WmiDataId(4),
+     Description("HResult") : amended,
+     format("x"),
+     read]
+     uint32 HResult;
+};
+
+[Dynamic,
+ Description("Caught exception") : amended,
+ EventType(15),
+ EventLevel(3),
+ EventTypeName("ANCM_EXCEPTION_CAUGHT") : amended
+]
+class ANCMExceptionCaughFailed:ANCM_Events
+{
+    [WmiDataId(1),
+     Description("Context ID") : amended,
+     extension("Guid"),
+     ActivityID,
+     read]
+     object  ContextId;
+     [WmiDataId(2),
+     Description("Exception catch file location") : amended,
+     StringTermination("NullTerminated"),
+     read]
+     string File;
+     [WmiDataId(3),
+     Description("Exception catch line number") : amended,
+     format("d"),
+     read]
+     uint32 Line;
+     [WmiDataId(2),
+     Description("Exception description") : amended,
+     StringTermination("NullTerminated"),
+     read]
+     string Description;
+};
+

src/AspNetCoreModuleV2/AspNetCore/proxymodule.cpp

@@ -86,6 +86,7 @@ ASPNET_CORE_PROXY_MODULE::OnExecuteRequestHandler(
     HRESULT hr = S_OK;
     REQUEST_NOTIFICATION_STATUS retVal = RQ_NOTIFICATION_CONTINUE;
 
+    TraceContextScope traceScope(pHttpContext->GetTraceContext());
     // We don't want OnAsyncCompletion to complete request before OnExecuteRequestHandler exits
     auto lock = SRWExclusiveLock(m_requestLock);
 
@@ -131,13 +132,14 @@ Finished:
 __override
 REQUEST_NOTIFICATION_STATUS
 ASPNET_CORE_PROXY_MODULE::OnAsyncCompletion(
-    IHttpContext *,
+    IHttpContext * pHttpContext,
     DWORD,
     BOOL,
     IHttpEventProvider *,
     IHttpCompletionInfo *   pCompletionInfo
 )
 {
+    TraceContextScope traceScope(pHttpContext->GetTraceContext());
     // We don't want OnAsyncCompletion to complete request before OnExecuteRequestHandler exits
     auto lock = SRWExclusiveLock(m_requestLock);
 

src/AspNetCoreModuleV2/CommonLib/CommonLib.vcxproj

@@ -205,6 +205,7 @@
     <ClInclude Include="config_utility.h" />
     <ClInclude Include="Environment.h" />
     <ClInclude Include="EventLog.h" />
+    <ClInclude Include="EventTracing.h" />
     <ClInclude Include="exceptions.h" />
     <ClInclude Include="file_utility.h" />
     <ClInclude Include="FileOutputManager.h" />
@@ -219,8 +220,7 @@
     <ClInclude Include="IOutputManager.h" />
     <ClInclude Include="irequesthandler.h" />
     <ClInclude Include="LoggingHelpers.h" />
-    <ClInclude Include="ModuleHelpers.h" />    
+    <ClInclude Include="ModuleHelpers.h" />
-    <ClInclude Include="ModuleTracer.h" />
     <ClInclude Include="NonCopyable.h" />
     <ClInclude Include="NullOutputManager.h" />
     <ClInclude Include="PipeOutputManager.h" />

src/AspNetCoreModuleV2/CommonLib/EventTracing.h

@@ -0,0 +1,28 @@
+// Copyright (c) Microsoft Corporation. All rights reserved.
+// Licensed under the MIT License. See License.txt in the project root for license information.
+
+#pragma once
+
+#include <httptrace.h>
+
+#pragma warning( push )
+#pragma warning ( disable : ALL_CODE_ANALYSIS_WARNINGS )
+
+#include "aspnetcore_event.h"
+
+#pragma warning( pop )
+
+template< class EVENT, typename ...Params >
+void RaiseEvent(IHttpTraceContext * pTraceContext,Params&&... params)
+{
+    if (pTraceContext != nullptr && EVENT::IsEnabled(pTraceContext))
+    {
+        EVENT::RaiseEvent(pTraceContext, std::forward<Params>(params)...);
+    }
+}
+
+template< class EVENT, typename ...Params >
+void RaiseEvent(IHttpContext * pHttpContext,Params&&... params)
+{
+    ::RaiseEvent<EVENT>(pHttpContext->GetTraceContext(), std::forward<Params>(params)...);
+}

src/AspNetCoreModuleV2/CommonLib/ModuleTracer.h

@@ -1,98 +0,0 @@
-// Copyright (c) .NET Foundation and contributors. All rights reserved.
-// Licensed under the MIT license. See LICENSE file in the project root for full license information.
-
-#pragma once
-#include "aspnetcore_event.h"
-
-class ModuleTracer
-{
-public:
-
-    ModuleTracer(IHttpTraceContext* traceContext)
-    {
-        m_traceContext = traceContext;
-    }
-
-    VOID
-    ExecuteRequestStart()
-    {
-        if (ANCMEvents::ANCM_INPROC_EXECUTE_REQUEST_START::IsEnabled(m_traceContext))
-        {
-            ANCMEvents::ANCM_INPROC_EXECUTE_REQUEST_START::RaiseEvent(
-                m_traceContext,
-                NULL);
-        }
-    }
-
-    VOID
-    ExecuteRequestEnd(REQUEST_NOTIFICATION_STATUS status)
-    {
-        if (ANCMEvents::ANCM_INPROC_EXECUTE_REQUEST_COMPLETION::IsEnabled(m_traceContext))
-        {
-            ANCMEvents::ANCM_INPROC_EXECUTE_REQUEST_COMPLETION::RaiseEvent(
-                m_traceContext,
-                NULL,
-                status);
-        }
-    }
-
-    VOID
-    AsyncCompletionStart()
-    {
-
-        if (ANCMEvents::ANCM_INPROC_ASYNC_COMPLETION_START::IsEnabled(m_traceContext))
-        {
-            ANCMEvents::ANCM_INPROC_ASYNC_COMPLETION_START::RaiseEvent(
-                m_traceContext,
-                NULL);
-        }
-    }
-
-    VOID
-    AsyncCompletionEnd(REQUEST_NOTIFICATION_STATUS status)
-    {
-        if (ANCMEvents::ANCM_INPROC_ASYNC_COMPLETION_COMPLETION::IsEnabled(m_traceContext))
-        {
-            ANCMEvents::ANCM_INPROC_ASYNC_COMPLETION_COMPLETION::RaiseEvent(
-                m_traceContext,
-                NULL,
-                status);
-        }
-    }
-
-    VOID
-    RequestShutdown()
-    {
-        if (ANCMEvents::ANCM_INPROC_REQUEST_SHUTDOWN::IsEnabled(m_traceContext))
-        {
-            ANCMEvents::ANCM_INPROC_REQUEST_SHUTDOWN::RaiseEvent(
-                m_traceContext,
-                NULL);
-        }
-    }
-
-    VOID
-    RequestDisconnect()
-    {
-        if (ANCMEvents::ANCM_INPROC_REQUEST_DISCONNECT::IsEnabled(m_traceContext))
-        {
-            ANCMEvents::ANCM_INPROC_REQUEST_DISCONNECT::RaiseEvent(
-                m_traceContext,
-                NULL);
-        }
-    }
-
-    VOID
-    ManagedCompletion()
-    {
-        if (ANCMEvents::ANCM_INPROC_MANAGED_REQUEST_COMPLETION::IsEnabled(m_traceContext))
-        {
-            ANCMEvents::ANCM_INPROC_MANAGED_REQUEST_COMPLETION::RaiseEvent(
-                m_traceContext,
-                NULL);
-        }
-    }
-
-private:
-    IHttpTraceContext * m_traceContext;
-};

src/AspNetCoreModuleV2/CommonLib/ServerErrorHandler.h

@@ -10,8 +10,9 @@ class ServerErrorHandler : public REQUEST_HANDLER
 {
 public:
 
-    ServerErrorHandler(IHttpContext &pContext, USHORT statusCode, USHORT subStatusCode, std::string statusText, HRESULT hr, HINSTANCE moduleInstance, bool disableStartupPage, int page)
+    ServerErrorHandler(IHttpContext &pContext, USHORT statusCode, USHORT subStatusCode, std::string statusText, HRESULT hr, HINSTANCE moduleInstance, bool disableStartupPage, int page) noexcept
-        : m_pContext(pContext),
+        : REQUEST_HANDLER(pContext),
+          m_pContext(pContext),
           m_HR(hr),
           m_disableStartupPage(disableStartupPage),
           m_page(page),
@@ -22,7 +23,7 @@ public:
     {
     }
 
-    REQUEST_NOTIFICATION_STATUS OnExecuteRequestHandler() override
+    REQUEST_NOTIFICATION_STATUS ExecuteRequestHandler() override
     {
         static std::string s_html500Page = GetHtml(m_moduleInstance, m_page);
 

src/AspNetCoreModuleV2/CommonLib/application.h

@@ -7,6 +7,7 @@
 #include "iapplication.h"
 #include "ntassert.h"
 #include "SRWExclusiveLock.h"
+#include "exceptions.h"
 
 class APPLICATION : public IAPPLICATION
 {
@@ -20,6 +21,7 @@ public:
         _In_  IHttpContext       *pHttpContext,
         _Outptr_result_maybenull_ IREQUEST_HANDLER  **pRequestHandler) override
     {
+        TraceContextScope traceScope(pHttpContext->GetTraceContext());
         *pRequestHandler = nullptr;
 
         if (m_fStopCalled)

src/AspNetCoreModuleV2/CommonLib/exceptions.h

@@ -9,6 +9,9 @@
 #include "debugutil.h"
 #include "StringHelpers.h"
 #include "InvalidOperationException.h"
+#include "ntassert.h"
+#include "NonCopyable.h"
+#include "EventTracing.h"
 
 #define LOCATION_INFO_ENABLED TRUE
 
@@ -53,7 +56,7 @@
     __pragma(warning(pop))
 
 
-#define FINISHED(hrr)                                           do { _HR_RET(hrr); if (_CHECK_FAILED(__hrRet)) { LogHResultFailed(LOCATION_INFO, __hrRet); } hr = __hrRet; _GOTO_FINISHED(); } while (0, 0) 
+#define FINISHED(hrr)                                           do { _HR_RET(hrr); if (_CHECK_FAILED(__hrRet)) { LogHResultFailed(LOCATION_INFO, __hrRet); } hr = __hrRet; _GOTO_FINISHED(); } while (0, 0)
 #define FINISHED_IF_FAILED(hrr)                                 do { _HR_RET(hrr); if (FAILED(__hrRet)) { LogHResultFailed(LOCATION_INFO, __hrRet); hr = __hrRet; _GOTO_FINISHED(); }} while (0, 0)
 #define FINISHED_IF_NULL_ALLOC(ptr)                             do { if ((ptr) == nullptr) { hr = LogHResultFailed(LOCATION_INFO, E_OUTOFMEMORY); _GOTO_FINISHED(); }} while (0, 0)
 #define FINISHED_LAST_ERROR_IF(condition)                       do { if (condition) { hr = LogLastError(LOCATION_INFO); _GOTO_FINISHED(); }} while (0, 0)
@@ -74,6 +77,18 @@
 #define SUCCEEDED_LOG(hr)                                       SUCCEEDED(LOG_IF_FAILED(hr))
 #define FAILED_LOG(hr)                                          FAILED(LOG_IF_FAILED(hr))
 
+inline thread_local IHttpTraceContext* g_traceContext;
+
+ __declspec(noinline) inline VOID TraceHRESULT(LOCATION_ARGUMENTS HRESULT hr)
+{
+    ::RaiseEvent<ANCMEvents::ANCM_HRESULT_FAILED>(g_traceContext, nullptr, fileName, lineNumber, hr);
+}
+
+ __declspec(noinline) inline VOID TraceException(LOCATION_ARGUMENTS const std::exception& exception)
+{
+     ::RaiseEvent<ANCMEvents::ANCM_EXCEPTION_CAUGHT>(g_traceContext, nullptr, fileName, lineNumber, exception.what());
+}
+
 class ResultException: public std::runtime_error
 {
 public:
@@ -86,7 +101,7 @@ public:
     HRESULT GetResult() const noexcept { return m_hr; }
 
 private:
-    
+
 #pragma warning( push )
 #pragma warning ( disable : 26495 ) // bug in CA: m_hr is reported as uninitialized
     const HRESULT m_hr = S_OK;
@@ -103,6 +118,7 @@ private:
     const auto lastError = GetLastError();
     const auto hr = HRESULT_FROM_WIN32(lastError);
 
+    TraceHRESULT(LOCATION_CALL hr);
     DebugPrintf(ASPNETCORE_DEBUG_FLAG_ERROR, LOCATION_FORMAT "Operation failed with LastError: %d HR: 0x%x", LOCATION_CALL lastError, hr);
 
     return hr;
@@ -120,6 +136,7 @@ private:
 
  __declspec(noinline) inline VOID ReportException(LOCATION_ARGUMENTS const std::exception& exception)
 {
+    TraceException(LOCATION_CALL exception);
     DebugPrintf(ASPNETCORE_DEBUG_FLAG_ERROR, "Exception '%s' caught at " LOCATION_FORMAT, exception.what(), LOCATION_CALL_ONLY);
 }
 
@@ -127,6 +144,7 @@ private:
 {
     if (FAILED(hr))
     {
+        TraceHRESULT(LOCATION_CALL hr);
         DebugPrintf(ASPNETCORE_DEBUG_FLAG_ERROR,  "Failed HRESULT returned: 0x%x at " LOCATION_FORMAT, hr, LOCATION_CALL_ONLY);
     }
     return hr;
@@ -178,3 +196,21 @@ __declspec(noinline) inline std::wstring GetUnexpectedExceptionMessage(const std
 {
     return format(L"Unexpected exception: %S", ex.what());
 }
+
+class TraceContextScope: NonCopyable
+{
+public:
+    TraceContextScope(IHttpTraceContext* pTraceContext) noexcept
+    {
+        m_pPreviousTraceContext = g_traceContext;
+        g_traceContext = pTraceContext;
+    }
+
+    ~TraceContextScope()
+    {
+        g_traceContext = m_pPreviousTraceContext;
+    }
+ private:
+     IHttpTraceContext* m_pPreviousTraceContext;
+};
+

src/AspNetCoreModuleV2/CommonLib/iapplication.h

@@ -9,7 +9,7 @@
 struct APPLICATION_PARAMETER
 {
     LPCSTR pzName;
-    const void *pValue;
+    void *pValue;
 };
 
 class IAPPLICATION
@@ -61,3 +61,15 @@ std::unique_ptr<IAPPLICATION, IAPPLICATION_DELETER> make_application(Params&&...
 #pragma warning( pop )
 }
 
+template< class TYPE >
+TYPE FindParameter(LPCSTR sRequiredParameter, APPLICATION_PARAMETER *pParameters, DWORD nParameters)
+{
+    for (DWORD i = 0; i < nParameters; i++)
+    {
+        if (_stricmp(pParameters[i].pzName, sRequiredParameter) == 0)
+        {
+            return reinterpret_cast<TYPE>(pParameters[i].pValue);
+        }
+    }
+    return nullptr;
+}

src/AspNetCoreModuleV2/CommonLib/requesthandler.h

@@ -5,14 +5,22 @@
 
 #include "irequesthandler.h"
 #include "ntassert.h"
+#include "exceptions.h"
 
 //
 // Pure abstract class
 //
 class REQUEST_HANDLER: public virtual IREQUEST_HANDLER
 {
-
 public:
+    REQUEST_HANDLER(IHttpContext& pHttpContext) noexcept : m_pHttpContext(pHttpContext)
+    {
+    }
+
+    virtual
+    REQUEST_NOTIFICATION_STATUS
+    ExecuteRequestHandler() = 0;
+
     VOID
     ReferenceRequestHandler() noexcept override
     {
@@ -30,7 +38,26 @@ public:
         }
     }
 
-    REQUEST_NOTIFICATION_STATUS OnAsyncCompletion(DWORD cbCompletion, HRESULT hrCompletionStatus) override
+
+    REQUEST_NOTIFICATION_STATUS
+    OnExecuteRequestHandler() final
+    {
+        TraceContextScope traceScope(m_pHttpContext.GetTraceContext());
+        return ExecuteRequestHandler();
+    }
+
+    REQUEST_NOTIFICATION_STATUS
+    OnAsyncCompletion(
+        DWORD      cbCompletion,
+        HRESULT    hrCompletionStatus
+    ) final
+    {
+        TraceContextScope traceScope(m_pHttpContext.GetTraceContext());
+        return AsyncCompletion(cbCompletion, hrCompletionStatus);
+    };
+
+    virtual
+    REQUEST_NOTIFICATION_STATUS AsyncCompletion(DWORD cbCompletion, HRESULT hrCompletionStatus)
     {
         UNREFERENCED_PARAMETER(cbCompletion);
         UNREFERENCED_PARAMETER(hrCompletionStatus);
@@ -47,5 +74,6 @@ public:
     }
 
 private:
-    mutable LONG                    m_cRefs = 1;
+    IHttpContext& m_pHttpContext;
+    mutable LONG  m_cRefs = 1;
 };

src/AspNetCoreModuleV2/InProcessRequestHandler/ShuttingDownApplication.h

@@ -8,11 +8,13 @@
 class ShuttingDownHandler : public REQUEST_HANDLER
 {
 public:
-    ShuttingDownHandler(IHttpContext* pContext) : m_pContext(pContext)
+    ShuttingDownHandler(IHttpContext* pContext)
+        : REQUEST_HANDLER(*pContext),
+          m_pContext(pContext)
     {
     }
 
-    REQUEST_NOTIFICATION_STATUS OnExecuteRequestHandler() override
+    REQUEST_NOTIFICATION_STATUS ExecuteRequestHandler() override
     {
         return ServerShutdownMessage(m_pContext);
     }

src/AspNetCoreModuleV2/InProcessRequestHandler/dllmain.cpp

@@ -17,7 +17,6 @@
 #include "WebConfigConfigurationSource.h"
 #include "ConfigurationLoadException.h"
 #include "StartupExceptionApplication.h"
-#include "aspnetcore_event.h"
 
 DECLARE_DEBUG_PRINT_OBJECT("aspnetcorev2_inprocess.dll");
 
@@ -100,6 +99,7 @@ CreateApplication(
     _Out_ IAPPLICATION          **ppApplication
 )
 {
+    TraceContextScope traceScope(FindParameter<IHttpTraceContext*>("TraceContext", pParameters, nParameters));
     try
     {
         HRESULT hr = S_OK;

src/AspNetCoreModuleV2/InProcessRequestHandler/inprocessapplication.cpp

@@ -28,12 +28,10 @@ IN_PROCESS_APPLICATION::IN_PROCESS_APPLICATION(
 {
     DBG_ASSERT(m_pConfig);
 
-    for (DWORD i = 0; i < nParameters; i++)
+    const auto knownLocation = FindParameter<PCWSTR>(s_exeLocationParameterName, pParameters, nParameters);
+    if (knownLocation != nullptr)
     {
-        if (_stricmp(pParameters[i].pzName, s_exeLocationParameterName) == 0)
+        m_dotnetExeKnownLocation = knownLocation;
-        {
-            m_dotnetExeKnownLocation = reinterpret_cast<PCWSTR>(pParameters[i].pValue);
-        }
     }
 }
 

src/AspNetCoreModuleV2/InProcessRequestHandler/inprocesshandler.cpp

@@ -6,18 +6,18 @@
 #include "IOutputManager.h"
 #include "ShuttingDownApplication.h"
 #include "ntassert.h"
-#include "ModuleTracer.h"
 
 ALLOC_CACHE_HANDLER * IN_PROCESS_HANDLER::sm_pAlloc = NULL;
 
 IN_PROCESS_HANDLER::IN_PROCESS_HANDLER(
     _In_ std::unique_ptr<IN_PROCESS_APPLICATION, IAPPLICATION_DELETER> pApplication,
-    _In_ IHttpContext   *pW3Context,
+    _In_ IHttpContext *pW3Context,
     _In_ PFN_REQUEST_HANDLER pRequestHandler,
     _In_ void * pRequestHandlerContext,
     _In_ PFN_DISCONNECT_HANDLER pDisconnectHandler,
     _In_ PFN_ASYNC_COMPLETION_HANDLER pAsyncCompletion
-): m_pManagedHttpContext(nullptr),
+): REQUEST_HANDLER(*pW3Context),
+   m_pManagedHttpContext(nullptr),
    m_requestNotificationStatus(RQ_NOTIFICATION_PENDING),
    m_fManagedRequestComplete(FALSE),
    m_pW3Context(pW3Context),
@@ -26,7 +26,6 @@ IN_PROCESS_HANDLER::IN_PROCESS_HANDLER(
    m_pRequestHandlerContext(pRequestHandlerContext),
    m_pAsyncCompletionHandler(pAsyncCompletion),
    m_pDisconnectHandler(pDisconnectHandler),
-   m_moduleTracer(pW3Context->GetTraceContext()),
    m_disconnectFired(false)
 {
     InitializeSRWLock(&m_srwDisconnectLock);
@@ -34,14 +33,13 @@ IN_PROCESS_HANDLER::IN_PROCESS_HANDLER(
 
 __override
 REQUEST_NOTIFICATION_STATUS
-IN_PROCESS_HANDLER::OnExecuteRequestHandler()
+IN_PROCESS_HANDLER::ExecuteRequestHandler()
 {
-    // FREB log
+    ::RaiseEvent<ANCMEvents::ANCM_INPROC_EXECUTE_REQUEST_START>(m_pW3Context, nullptr);
-    m_moduleTracer.ExecuteRequestStart();
 
     if (m_pRequestHandler == NULL)
     {
-        m_moduleTracer.ExecuteRequestEnd(RQ_NOTIFICATION_FINISH_REQUEST);
+        ::RaiseEvent<ANCMEvents::ANCM_INPROC_EXECUTE_REQUEST_COMPLETION>(m_pW3Context, nullptr, RQ_NOTIFICATION_FINISH_REQUEST);
         return RQ_NOTIFICATION_FINISH_REQUEST;
     }
     else if (m_pApplication->QueryBlockCallbacksIntoManaged())
@@ -50,24 +48,25 @@ IN_PROCESS_HANDLER::OnExecuteRequestHandler()
     }
 
     auto status = m_pRequestHandler(this, m_pRequestHandlerContext);
-    m_moduleTracer.ExecuteRequestEnd(status);
+    ::RaiseEvent<ANCMEvents::ANCM_INPROC_EXECUTE_REQUEST_COMPLETION>(m_pW3Context, nullptr, status);
     return status;
 }
 
 __override
 REQUEST_NOTIFICATION_STATUS
-IN_PROCESS_HANDLER::OnAsyncCompletion(
+IN_PROCESS_HANDLER::AsyncCompletion(
     DWORD       cbCompletion,
     HRESULT     hrCompletionStatus
 )
 {
-    m_moduleTracer.AsyncCompletionStart();
+
+    ::RaiseEvent<ANCMEvents::ANCM_INPROC_ASYNC_COMPLETION_START>(m_pW3Context, nullptr);
 
     if (m_fManagedRequestComplete)
     {
         // means PostCompletion has been called and this is the associated callback.
-        m_moduleTracer.AsyncCompletionEnd(m_requestNotificationStatus);
+        ::RaiseEvent<ANCMEvents::ANCM_INPROC_ASYNC_COMPLETION_COMPLETION>(m_pW3Context, nullptr, m_requestNotificationStatus);
-        return m_requestNotificationStatus; 
+        return m_requestNotificationStatus;
     }
     if (m_pApplication->QueryBlockCallbacksIntoManaged())
     {
@@ -81,20 +80,20 @@ IN_PROCESS_HANDLER::OnAsyncCompletion(
     // Call the managed handler for async completion.
 
     auto status = m_pAsyncCompletionHandler(m_pManagedHttpContext, hrCompletionStatus, cbCompletion);
-    m_moduleTracer.AsyncCompletionEnd(status);
+    ::RaiseEvent<ANCMEvents::ANCM_INPROC_ASYNC_COMPLETION_COMPLETION>(m_pW3Context, nullptr, status);
     return status;
 }
 
-REQUEST_NOTIFICATION_STATUS IN_PROCESS_HANDLER::ServerShutdownMessage()
+REQUEST_NOTIFICATION_STATUS IN_PROCESS_HANDLER::ServerShutdownMessage() const
 {
-    m_moduleTracer.RequestShutdown();
+    ::RaiseEvent<ANCMEvents::ANCM_INPROC_REQUEST_SHUTDOWN>(m_pW3Context, nullptr);
     return ShuttingDownHandler::ServerShutdownMessage(m_pW3Context);
 }
 
 VOID
 IN_PROCESS_HANDLER::NotifyDisconnect()
 {
-    m_moduleTracer.RequestDisconnect();
+    ::RaiseEvent<ANCMEvents::ANCM_INPROC_REQUEST_DISCONNECT>(m_pW3Context, nullptr);
 
     if (m_pApplication->QueryBlockCallbacksIntoManaged() ||
         m_fManagedRequestComplete)
@@ -126,7 +125,7 @@ IN_PROCESS_HANDLER::IndicateManagedRequestComplete(
 {
     m_fManagedRequestComplete = TRUE;
     m_pManagedHttpContext = nullptr;
-    m_moduleTracer.ManagedCompletion();
+    ::RaiseEvent<ANCMEvents::ANCM_INPROC_MANAGED_REQUEST_COMPLETION>(m_pW3Context, nullptr);
 }
 
 VOID

src/AspNetCoreModuleV2/InProcessRequestHandler/inprocesshandler.h

@@ -7,7 +7,6 @@
 #include <memory>
 #include "iapplication.h"
 #include "inprocessapplication.h"
-#include "ModuleTracer.h"
 
 class IN_PROCESS_APPLICATION;
 
@@ -26,11 +25,11 @@ public:
 
     __override
     REQUEST_NOTIFICATION_STATUS
-    OnExecuteRequestHandler() override;
+    ExecuteRequestHandler() override;
 
     __override
     REQUEST_NOTIFICATION_STATUS
-    OnAsyncCompletion(
+    AsyncCompletion(
         DWORD       cbCompletion,
         HRESULT     hrCompletionStatus
     ) override;
@@ -72,7 +71,7 @@ public:
 
 private:
     REQUEST_NOTIFICATION_STATUS
-    ServerShutdownMessage();
+    ServerShutdownMessage() const;
 
     PVOID m_pManagedHttpContext;
     BOOL m_fManagedRequestComplete;
@@ -84,7 +83,6 @@ private:
     PFN_ASYNC_COMPLETION_HANDLER m_pAsyncCompletionHandler;
     PFN_DISCONNECT_HANDLER       m_pDisconnectHandler;
     static ALLOC_CACHE_HANDLER *   sm_pAlloc;
-    ModuleTracer m_moduleTracer;
     bool m_disconnectFired;
     SRWLOCK m_srwDisconnectLock;
 };

src/AspNetCoreModuleV2/OutOfProcessRequestHandler/dllmain.cpp

@@ -250,8 +250,7 @@ CreateApplication(
     _Out_ IAPPLICATION      **ppApplication
 )
 {
-    UNREFERENCED_PARAMETER(pParameters);
+    TraceContextScope traceScope(FindParameter<IHttpTraceContext*>("TraceContext", pParameters, nParameters));
-    UNREFERENCED_PARAMETER(nParameters);
 
     InitializeGlobalConfiguration(pServer);
 

src/AspNetCoreModuleV2/OutOfProcessRequestHandler/forwardinghandler.cpp

@@ -26,7 +26,7 @@ RESPONSE_HEADER_HASH *      FORWARDING_HANDLER::sm_pResponseHeaderHash = NULL;
 FORWARDING_HANDLER::FORWARDING_HANDLER(
     _In_ IHttpContext                  *pW3Context,
     _In_ std::unique_ptr<OUT_OF_PROCESS_APPLICATION, IAPPLICATION_DELETER> pApplication
-) : REQUEST_HANDLER(),
+) : REQUEST_HANDLER(*pW3Context),
     m_Signature(FORWARDING_HANDLER_SIGNATURE),
     m_RequestStatus(FORWARDER_START),
     m_fClientDisconnected(FALSE),
@@ -90,7 +90,7 @@ FORWARDING_HANDLER::~FORWARDING_HANDLER(
 
 __override
 REQUEST_NOTIFICATION_STATUS
-FORWARDING_HANDLER::OnExecuteRequestHandler()
+FORWARDING_HANDLER::ExecuteRequestHandler()
 {
     REQUEST_NOTIFICATION_STATUS retVal = RQ_NOTIFICATION_CONTINUE;
     HRESULT                     hr = S_OK;
@@ -320,7 +320,7 @@ Failure:
     else if (fFailedToStartKestrel && !m_pApplication->QueryConfig()->QueryDisableStartUpErrorPage())
     {
         ServerErrorHandler handler(*m_pW3Context, 502, 5, "Bad Gateway", hr, g_hOutOfProcessRHModule, m_pApplication->QueryConfig()->QueryDisableStartUpErrorPage(), OUT_OF_PROCESS_RH_STATIC_HTML);
-        handler.OnExecuteRequestHandler();
+        handler.ExecuteRequestHandler();
     }
     else
     {
@@ -353,7 +353,7 @@ Finished:
 
 __override
 REQUEST_NOTIFICATION_STATUS
-FORWARDING_HANDLER::OnAsyncCompletion(
+FORWARDING_HANDLER::AsyncCompletion(
     DWORD           cbCompletion,
     HRESULT         hrCompletionStatus
 )

src/AspNetCoreModuleV2/OutOfProcessRequestHandler/forwardinghandler.h

@@ -30,11 +30,11 @@ public:
 
     __override
     REQUEST_NOTIFICATION_STATUS
-    OnExecuteRequestHandler();
+    ExecuteRequestHandler();
 
     __override
     REQUEST_NOTIFICATION_STATUS
-    OnAsyncCompletion(
+    AsyncCompletion(
         DWORD       cbCompletion,
         HRESULT     hrCompletionStatus
     );

src/AspNetCoreModuleV2/OutOfProcessRequestHandler/stdafx.h

@@ -57,7 +57,7 @@
 #include "requesthandler.h"
 #include "application.h"
 #include "resources.h"
-#include "aspnetcore_event.h"
+#include "EventTracing.h"
 #include "aspnetcore_msg.h"
 #include "requesthandler_config.h"
 

test/Common.FunctionalTests/Inprocess/FrebTests.cs

@@ -49,6 +49,22 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
             AssertFrebLogs(result, FrebChecks());
         }
 
+        [ConditionalFact]
+        [RequiresNewShim]
+        [RequiresIIS(IISCapability.FailedRequestTracingModule)]
+        public async Task FrebIncludesHResultFailures()
+        {
+            var parameters = _fixture.GetBaseDeploymentParameters(publish: true);
+            parameters.TransformArguments((args, _) => string.Empty);
+            var result = await SetupFrebApp(parameters);
+
+            await result.HttpClient.GetAsync("HelloWorld");
+
+            StopServer();
+
+            AssertFrebLogs(result, new FrebLogItem("ANCM_HRESULT_FAILED"), new FrebLogItem("ANCM_EXCEPTION_CAUGHT"));
+        }
+
         [ConditionalFact]
         [RequiresIIS(IISCapability.FailedRequestTracingModule)]
         public async Task CheckFailedRequestEvents()
@@ -86,9 +102,9 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
             AssertFrebLogs(result, new FrebLogItem("ANCM_INPROC_REQUEST_DISCONNECT"), new FrebLogItem("ANCM_INPROC_MANAGED_REQUEST_COMPLETION"));
         }
 
-        private async Task<IISDeploymentResult> SetupFrebApp()
+        private async Task<IISDeploymentResult> SetupFrebApp(IISDeploymentParameters parameters = null)
         {
-            var parameters = _fixture.GetBaseDeploymentParameters(publish: true);
+            parameters = parameters ?? _fixture.GetBaseDeploymentParameters(publish: true);
             parameters.EnableFreb("Verbose", _logFolderPath);
 
             Directory.CreateDirectory(_logFolderPath);

test/Common.FunctionalTests/LogFileTests.cs

@@ -51,7 +51,7 @@ namespace Microsoft.AspNetCore.Server.IISIntegration.FunctionalTests
             var deploymentResult = await DeployAsync(deploymentParameters);
 
             await Helpers.AssertStarts(deploymentResult, path);
-                
+
             StopServer();
 
             var contents = Helpers.ReadAllTextFromFile(Helpers.GetExpectedLogName(deploymentResult, _logFolderPath), Logger);