From ef5198e231449e42a5e4fa0862ead6f04c394aa1 Mon Sep 17 00:00:00 2001 From: "Dustin L. Howett" Date: Fri, 9 Oct 2020 15:20:12 -0700 Subject: [PATCH] Hook up the WIL fallback error tracer in Terminal (#7864) This pull request introduces (a very, very stripped-down copy of) the WIL fallback error reporter. It emits error records, usually immediately before the application implodes, into the event stream. This should improve diagnosability of issues that take Terminal down, and allow us to give out a .wprp file to gather traces from users. (cherry picked from commit cd768934be6206e7a837a13aa0f1d05b47dd5d8c) --- .github/actions/spell-check/expect/expect.txt | 1 + src/cascadia/TerminalApp/init.cpp | 2 + src/cascadia/TerminalConnection/init.cpp | 2 + src/cascadia/TerminalControl/init.cpp | 2 + src/cascadia/WindowsTerminal/main.cpp | 2 + src/inc/WilErrorReporting.h | 61 +++++++++++++++++++ 6 files changed, 70 insertions(+) create mode 100644 src/inc/WilErrorReporting.h diff --git a/.github/actions/spell-check/expect/expect.txt b/.github/actions/spell-check/expect/expect.txt index 5f5968581f1..8e59251ffdc 100644 --- a/.github/actions/spell-check/expect/expect.txt +++ b/.github/actions/spell-check/expect/expect.txt @@ -998,6 +998,7 @@ hpj hpp HPR HPROPSHEETPAGE +HProvider HREDRAW hresult HRSRC diff --git a/src/cascadia/TerminalApp/init.cpp b/src/cascadia/TerminalApp/init.cpp index 5f79877f3e1..1f1159478d7 100644 --- a/src/cascadia/TerminalApp/init.cpp +++ b/src/cascadia/TerminalApp/init.cpp @@ -3,6 +3,7 @@ #include "pch.h" #include +#include // Note: Generate GUID using TlgGuid.exe tool TRACELOGGING_DEFINE_PROVIDER( @@ -19,6 +20,7 @@ BOOL WINAPI DllMain(HINSTANCE hInstDll, DWORD reason, LPVOID /*reserved*/) case DLL_PROCESS_ATTACH: DisableThreadLibraryCalls(hInstDll); TraceLoggingRegister(g_hTerminalAppProvider); + Microsoft::Console::ErrorReporting::EnableFallbackFailureReporting(g_hTerminalAppProvider); break; case DLL_PROCESS_DETACH: if (g_hTerminalAppProvider) diff --git a/src/cascadia/TerminalConnection/init.cpp b/src/cascadia/TerminalConnection/init.cpp index 0d1e411aa17..ffde5a38578 100644 --- a/src/cascadia/TerminalConnection/init.cpp +++ b/src/cascadia/TerminalConnection/init.cpp @@ -3,6 +3,7 @@ #include "pch.h" #include +#include // Note: Generate GUID using TlgGuid.exe tool #pragma warning(suppress : 26477) // One of the macros uses 0/NULL. We don't have control to make it nullptr. @@ -21,6 +22,7 @@ BOOL WINAPI DllMain(HINSTANCE hInstDll, DWORD reason, LPVOID /*reserved*/) case DLL_PROCESS_ATTACH: DisableThreadLibraryCalls(hInstDll); TraceLoggingRegister(g_hTerminalConnectionProvider); + Microsoft::Console::ErrorReporting::EnableFallbackFailureReporting(g_hTerminalConnectionProvider); break; case DLL_PROCESS_DETACH: if (g_hTerminalConnectionProvider) diff --git a/src/cascadia/TerminalControl/init.cpp b/src/cascadia/TerminalControl/init.cpp index 8d73866c511..4ff87caba57 100644 --- a/src/cascadia/TerminalControl/init.cpp +++ b/src/cascadia/TerminalControl/init.cpp @@ -3,6 +3,7 @@ #include "pch.h" #include +#include // Note: Generate GUID using TlgGuid.exe tool TRACELOGGING_DEFINE_PROVIDER( @@ -19,6 +20,7 @@ BOOL WINAPI DllMain(HINSTANCE hInstDll, DWORD reason, LPVOID /*reserved*/) case DLL_PROCESS_ATTACH: DisableThreadLibraryCalls(hInstDll); TraceLoggingRegister(g_hTerminalControlProvider); + Microsoft::Console::ErrorReporting::EnableFallbackFailureReporting(g_hTerminalControlProvider); break; case DLL_PROCESS_DETACH: if (g_hTerminalControlProvider) diff --git a/src/cascadia/WindowsTerminal/main.cpp b/src/cascadia/WindowsTerminal/main.cpp index 63d007a9800..726ded30444 100644 --- a/src/cascadia/WindowsTerminal/main.cpp +++ b/src/cascadia/WindowsTerminal/main.cpp @@ -5,6 +5,7 @@ #include "AppHost.h" #include "resource.h" #include "../types/inc/User32Utils.hpp" +#include using namespace winrt; using namespace winrt::Windows::UI; @@ -91,6 +92,7 @@ int __stdcall wWinMain(HINSTANCE, HINSTANCE, LPWSTR, int) TraceLoggingDescription("Event emitted immediately on startup"), TraceLoggingKeyword(MICROSOFT_KEYWORD_MEASURES), TelemetryPrivacyDataTag(PDT_ProductAndServicePerformance)); + ::Microsoft::Console::ErrorReporting::EnableFallbackFailureReporting(g_hWindowsTerminalProvider); // If Terminal is spawned by a shortcut that requests that it run in a new process group // while attached to a console session, that request is nonsense. That request will, however, diff --git a/src/inc/WilErrorReporting.h b/src/inc/WilErrorReporting.h new file mode 100644 index 00000000000..9e9f3a81b3b --- /dev/null +++ b/src/inc/WilErrorReporting.h @@ -0,0 +1,61 @@ +/*++ +Copyright (c) Microsoft Corporation +Licensed under the MIT license. + +Module Name: +- WilErrorReporting.h +--*/ +#pragma once + +#include +#include + +#define CONSOLE_WIL_TRACELOGGING_COMMON_FAILURE_PARAMS(failure) \ + TraceLoggingUInt32((failure).hr, "hresult", "Failure error code"), \ + TraceLoggingString((failure).pszFile, "fileName", "Source code file name where the error occurred"), \ + TraceLoggingUInt32((failure).uLineNumber, "lineNumber", "Line number within the source code file where the error occurred"), \ + TraceLoggingString((failure).pszModule, "module", "Name of the binary where the error occurred"), \ + TraceLoggingUInt32(static_cast((failure).type), "failureType", "Indicates what type of failure was observed (exception, returned error, logged error or fail fast"), \ + TraceLoggingWideString((failure).pszMessage, "message", "Custom message associated with the failure (if any)"), \ + TraceLoggingUInt32((failure).threadId, "threadId", "Identifier of the thread the error occurred on"), \ + TraceLoggingString((failure).pszCallContext, "callContext", "List of containing this error"), \ + TraceLoggingUInt32((failure).callContextOriginating.contextId, "originatingContextId", "Identifier for the oldest activity containing this error"), \ + TraceLoggingString((failure).callContextOriginating.contextName, "originatingContextName", "Name of the oldest activity containing this error"), \ + TraceLoggingWideString((failure).callContextOriginating.contextMessage, "originatingContextMessage", "Custom message associated with the oldest activity containing this error (if any)"), \ + TraceLoggingUInt32((failure).callContextCurrent.contextId, "currentContextId", "Identifier for the newest activity containing this error"), \ + TraceLoggingString((failure).callContextCurrent.contextName, "currentContextName", "Name of the newest activity containing this error"), \ + TraceLoggingWideString((failure).callContextCurrent.contextMessage, "currentContextMessage", "Custom message associated with the newest activity containing this error (if any)") + +#define CONSOLE_WIL_TRACELOGGING_FAILURE_PARAMS(failure) \ + TelemetryPrivacyDataTag(PDT_ProductAndServicePerformance), \ + TraceLoggingStruct(14, "wilResult"), \ + CONSOLE_WIL_TRACELOGGING_COMMON_FAILURE_PARAMS(failure) + +namespace Microsoft::Console::ErrorReporting +{ + __declspec(selectany) TraceLoggingHProvider FallbackProvider; + __declspec(noinline) inline void WINAPI ReportFailureToFallbackProvider(bool alreadyReported, const wil::FailureInfo& failure) noexcept + try + { + if (!alreadyReported && FallbackProvider) + { +#pragma warning(suppress : 26477 26485 26494 26482 26446) // We don't control TraceLoggingWrite + TraceLoggingWrite(FallbackProvider, "FallbackError", TraceLoggingKeyword(MICROSOFT_KEYWORD_TELEMETRY), TraceLoggingLevel(WINEVENT_LEVEL_ERROR), CONSOLE_WIL_TRACELOGGING_FAILURE_PARAMS(failure)); + } + } + catch (...) + { + // Don't log anything. We just failed to trace, where will we go now? + } + + __declspec(noinline) inline void EnableFallbackFailureReporting(TraceLoggingHProvider provider) noexcept + try + { + FallbackProvider = provider; + ::wil::SetResultTelemetryFallback(::Microsoft::Console::ErrorReporting::ReportFailureToFallbackProvider); + } + catch (...) + { + // Don't log anything. We just failed to set up WIL -- how are we going to log anything? + } +}