Skip to content

Commit

Permalink
Set keyword flags on all tracelog events (#10098)
Browse files Browse the repository at this point in the history 
Set keyword flags on all events so those sharing a provider with
telemetry do not fire unless tracing is enabled

## PR Checklist
* [x] Closes #10093
* [x] I work here
* [x] Tests passed
* [x] Documentation added in `til.h` about how keywords work and at the
  only other site of keywords we define in the Host project tracing
  files.

## Detailed Description of the Pull Request / Additional comments
I initially thought that we would need to split providers here to
accomplish this... but @DHowett helped me realize that might be a lot of
additional metadata and bloat binary size. So with help from a friend
from fundamentals, I realized that we could use Keywords to
differentiate here. We can no longer define 0 keywords as that
represents an any/all scenario. Every `TraceLoggingWrite` event now
needs a keyword. When our events have a keyword, they're not included in
any trace. Additionally, when we have an explicit keyword to check that
is different from the ones used for the telemetry pipeline, we can
ensure that we only do "hard work" to generate debug trace data when an
"ALL" type listener like TraceView or Windows Performance Recorder with
our profiles is listening to these providers for ALL keyworded events.

## Validation Steps Performed
- [x] - Built with full release build config to confirm performance is
  worse than dev builds BECAUSE of the telemetry event collector camping
  our provider and triggering full trace event generation on shared
  providers.
- [x] - Built with full release build config to enable statistics
  collection and validated trace event collection is excluded and trace
  event short-circuits work with this change.
- [x] - Checked that TraceView still sees both telemetry and tracing
  events
- [x] - Checked that WPR with our .wprp profile sees both telemetry and
  tracing events

(cherry picked from commit 66fdc64)

# Conflicts:
#	src/cascadia/Remoting/Monarch.cpp
#	src/cascadia/Remoting/Peasant.cpp
#	src/cascadia/WindowsTerminal/IslandWindow.cpp
  • Loading branch information
@miniksa @DHowett
miniksa authored and DHowett committed May 17, 2021
1 parent 0499604 commit a736712
Show file tree
Hide file tree
Showing 12 changed files with 276 additions and 130 deletions.
2 changes: 2 additions & 0 deletions src/ConsolePerf.wprp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -43,6 +43,7 @@
<EventProvider Id="EventProvider-Microsoft.Windows.Console.Server" Name="1A541C01-589A-496E-85A7-A9E02170166D"/>
<EventProvider Id="EventProvider-Microsoft.Windows.Console.VirtualTerminal.Parser" Name="c9ba2a84-d3ca-5e19-2bd6-776a0910cb9d"/>
<EventProvider Id="EventProvider-Microsoft.Windows.Console.Render.VtEngine" Name="c9ba2a95-d3ca-5e19-2bd6-776a0910cb9d"/>
<EventProvider Id="EventProvider-Microsoft.Windows.Console.UIA" Name="e7ebce59-2161-572d-b263-2f16a6afb9e5"/>
<!-- Now define some profiles. We'll call them by ID when collecting. Also, the Base is where it is inheriting from and is a .wprpi file built... -->
<!-- ... into WPR automatically. Go look in the WPR install directory or in the documentation to find it. -->
<Profile Id="ConsolePerfProfile.Verbose.File" Base="GeneralProfile.Light.File" LoggingMode="File" Name="ConsolePerfProfile" DetailLevel="Verbose" Description="Console Performance default profile">
Expand All @@ -66,6 +67,7 @@
<EventProviderId Value="EventProvider-Microsoft.Windows.Console.Server"/>
<EventProviderId Value="EventProvider-Microsoft.Windows.Console.VirtualTerminal.Parser"/>
<EventProviderId Value="EventProvider-Microsoft.Windows.Console.Render.VtEngine"/>
<EventProviderId Value="EventProvider-Microsoft.Windows.Console.UIA"/>
</EventProviders>
</EventCollectorId>
</Collectors>
Expand Down
2 changes: 2 additions & 0 deletions src/Terminal.wprp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@
<EventProvider Id="EventProvider_TerminalApp" Name="24a1622f-7da7-5c77-3303-d850bd1ab2ed" />
<EventProvider Id="EventProvider_TerminalWin32Host" Name="56c06166-2e2e-5f4d-7ff3-74f4b78c87d6" />
<EventProvider Id="EventProvider_TerminalRemoting" Name="d6f04aad-629f-539a-77c1-73f5c3e4aa7b" />
<EventProvider Id="EventProvider_TerminalDirectX" Name="c93e739e-ae50-5a14-78e7-f171e947535d" />
<Profile Id="Terminal.Verbose.File" Name="Terminal" Description="Terminal" LoggingMode="File" DetailLevel="Verbose">
<Collectors>
<EventCollectorId Value="EventCollector_Terminal">
Expand All @@ -21,6 +22,7 @@
<EventProviderId Value="EventProvider_TerminalApp" />
<EventProviderId Value="EventProvider_TerminalWin32Host" />
<EventProviderId Value="EventProvider_TerminalRemoting" />
<EventProviderId Value="EventProvider_TerminalDirectX" />
</EventProviders>
</EventCollectorId>
</Collectors>
Expand Down
45 changes: 30 additions & 15 deletions src/cascadia/Remoting/WindowManager.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
// stay in this jail until we do.
TraceLoggingWrite(g_hRemotingProvider,
"WindowManager_ExceptionInCtor",
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
}
}
}
Expand Down Expand Up @@ -99,7 +100,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingBoolean(_shouldCreateWindow, "CreateWindow", "true iff we should create a new window"),
TraceLoggingUInt64(givenID.value(), "Id", "The ID we should assign our peasant"),
TraceLoggingWideString(givenName.c_str(), "Name", "The name we should assign this window"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
}
else
{
Expand All @@ -108,7 +110,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingBoolean(_shouldCreateWindow, "CreateWindow", "true iff we should create a new window"),
TraceLoggingPointer(nullptr, "Id", "No ID provided"),
TraceLoggingWideString(givenName.c_str(), "Name", "The name we should assign this window"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
}
}
else
Expand Down Expand Up @@ -140,7 +143,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingBoolean(_shouldCreateWindow, "CreateWindow", "true iff we should create a new window"),
TraceLoggingUInt64(givenID.value(), "Id", "The ID we should assign our peasant"),
TraceLoggingWideString(givenName.c_str(), "Name", "The name we should assign this window"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
}
else if (responseId == WindowingBehaviorUseName)
{
Expand All @@ -151,7 +155,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingBoolean(_shouldCreateWindow, "CreateWindow", "true iff we should create a new window"),
TraceLoggingUInt64(0, "Id", "The ID we should assign our peasant"),
TraceLoggingWideString(givenName.c_str(), "Name", "The name we should assign this window"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
}
else
{
Expand All @@ -160,7 +165,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingBoolean(_shouldCreateWindow, "CreateWindow", "true iff we should create a new window"),
TraceLoggingUInt64(0, "Id", "The ID we should assign our peasant"),
TraceLoggingWideString(L"", "Name", "The name we should assign this window"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
}
}

Expand Down Expand Up @@ -228,7 +234,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
"WindowManager_ConnectedToMonarch",
TraceLoggingUInt64(_monarch.GetPID(), "monarchPID", "The PID of the new Monarch"),
TraceLoggingBoolean(_isKing, "isKing", "true if we are the new monarch"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));

if (_peasant)
{
Expand Down Expand Up @@ -294,7 +301,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingWrite(g_hRemotingProvider,
"WindowManager_CreateOurPeasant",
TraceLoggingUInt64(_peasant.GetID(), "peasantID", "The ID of our new peasant"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));

return _peasant;
}
Expand Down Expand Up @@ -369,7 +377,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
"WindowManager_FailedToOpenMonarch",
TraceLoggingUInt64(peasantID, "peasantID", "Our peasant ID"),
TraceLoggingUInt64(gle, "lastError", "The result of GetLastError"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));

exitThreadRequested = _performElection();
continue;
Expand All @@ -385,7 +394,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingWrite(g_hRemotingProvider,
"WindowManager_MonarchDied",
TraceLoggingUInt64(peasantID, "peasantID", "Our peasant ID"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
// Connect to the new monarch, which might be us!
// If we become the monarch, then we'll return true and exit this thread.
exitThreadRequested = _performElection();
Expand All @@ -396,7 +406,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingWrite(g_hRemotingProvider,
"WindowManager_MonarchWaitInterrupted",
TraceLoggingUInt64(peasantID, "peasantID", "Our peasant ID"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
exitThreadRequested = true;
break;

Expand All @@ -405,7 +416,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingWrite(g_hRemotingProvider,
"WindowManager_MonarchWaitTimeout",
TraceLoggingUInt64(peasantID, "peasantID", "Our peasant ID"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
exitThreadRequested = true;
break;

Expand All @@ -417,7 +429,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
"WindowManager_WaitFailed",
TraceLoggingUInt64(peasantID, "peasantID", "Our peasant ID"),
TraceLoggingUInt64(gle, "lastError", "The result of GetLastError"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
ExitProcess(0);
}
}
Expand All @@ -441,7 +454,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingWrite(g_hRemotingProvider,
"WindowManager_ExceptionInWaitThread",
TraceLoggingUInt64(peasantID, "peasantID", "Our peasant ID"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
bool foundNewMonarch = false;
while (!foundNewMonarch)
{
Expand All @@ -461,7 +475,8 @@ namespace winrt::Microsoft::Terminal::Remoting::implementation
TraceLoggingWrite(g_hRemotingProvider,
"WindowManager_ExceptionInNestedWaitThread",
TraceLoggingUInt64(peasantID, "peasantID", "Our peasant ID"),
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE));
TraceLoggingLevel(WINEVENT_LEVEL_VERBOSE),
TraceLoggingKeyword(TIL_KEYWORD_TRACE));
}
}
}
Expand Down
6 changes: 5 additions & 1 deletion src/host/exe/exemain.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -143,7 +143,11 @@ static bool ShouldUseLegacyConhost(const ConsoleArguments& args)
// because there's already a count of how many total processes were launched.
// Total - legacy = new console.
// We expect legacy launches to be infrequent enough to not cause an issue.
TraceLoggingWrite(g_ConhostLauncherProvider, "IsLegacyLoaded", TraceLoggingBool(true, "ConsoleLegacy"), TraceLoggingKeyword(MICROSOFT_KEYWORD_TELEMETRY));
TraceLoggingWrite(g_ConhostLauncherProvider,
"IsLegacyLoaded",
TraceLoggingBool(true, "ConsoleLegacy"),
TraceLoggingKeyword(MICROSOFT_KEYWORD_TELEMETRY),
TelemetryPrivacyDataTag(PDT_ProductAndServiceUsage));

const PCWSTR pszConhostDllName = L"ConhostV1.dll";

Expand Down
Loading

0 comments on commit a736712

Please sign in to comment.