Added outcome telemetry for cold start - #41200
Conversation
There was a problem hiding this comment.
Pull request overview
This PR adds a new telemetry signal to better understand WSL cold-start instance creation outcomes by emitting a single outcome event (success/failure/timeout) in addition to the existing begin/end events.
Changes:
- Adds
TimedOperationOutcomeReporter, an RAII helper that arms a one-shot threadpool timer and reports exactly one outcome via an atomic gate. - Instruments
LxssUserSessionImpl::_CreateInstanceto emitCreateInstanceOutcometelemetry with outcome, elapsed time, timeout threshold, and HRESULT. - Updates the
src/windows/commonCMakeLists to compile and export the new helper.
Reviewed changes
Copilot reviewed 4 out of 4 changed files in this pull request and generated 1 comment.
| File | Description |
|---|---|
| src/windows/service/exe/LxssUserSession.cpp | Adds CreateInstanceOutcome telemetry emission around instance creation. |
| src/windows/common/TimedOperationOutcomeReporter.h | Declares a helper for one-shot outcome reporting (success/failure/timeout). |
| src/windows/common/TimedOperationOutcomeReporter.cpp | Implements the helper using a threadpool timer and a one-time reporting gate. |
| src/windows/common/CMakeLists.txt | Adds the new helper source/header to the common library build. |
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 4 out of 4 changed files in this pull request and generated no new comments.
Comments suppressed due to low confidence (2)
src/windows/common/TimedOperationOutcomeReporter.h:21
- TimedOperationOutcomeReporter.h declares Thread Pool callback types (PTP_CALLBACK_INSTANCE/PTP_TIMER) but doesn't include <windows.h> (or another header that guarantees those typedefs). This makes the header depend on includer order, unlike nearby headers such as SlowOperationWatcher.h which include <windows.h> explicitly.
#include <atomic>
#include <chrono>
#include <functional>
#include <wil/resource.h>
#include "wslutil.h"
src/windows/service/exe/LxssUserSession.cpp:2578
- TimedOperationOutcomeReporter construction uses THROW_* and can throw (e.g., CreateThreadpoolTimer failure). Since this is in the cold-start path and the PR description says the timeout telemetry is telemetry-only and must not affect instance creation, reporter setup should be best-effort here (a telemetry setup failure must not abort _CreateInstance).
std::atomic<HRESULT> outcomeResult{result};
TimedOperationOutcomeReporter outcomeReporter{
createInstanceTimeout,
[distroName, version, instanceId, createInstanceTimeoutMs, &outcomeResult](
TimedOperationOutcome Outcome, std::chrono::milliseconds Elapsed) {
Co-authored-by: Copilot Autofix powered by AI <175728472+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 4 out of 4 changed files in this pull request and generated no new comments.
Comments suppressed due to low confidence (1)
src/windows/common/TimedOperationOutcomeReporter.cpp:54
- Complete()/Report() does not cancel the underlying threadpool timer when the operation finishes before the timeout. That means the timer callback will still be queued and run later (it becomes a no-op due to m_reported, but it still consumes a threadpool callback). Consider canceling the timer on the first successful Report() to avoid unnecessary work for the common fast-path completion case.
if (!m_reported.exchange(true))
{
m_callback(Outcome, Elapsed);
}
craigloewen-msft
left a comment
There was a problem hiding this comment.
This operation looks like it's doing some kind of 'Timed output', do we need that?
IMO the root ask here is to "Move us from tracking WSL startup success with 'CreateInstanceBegin' and 'CreateInstanceEnd' events to instead a single source of truth telemetry event".
That new event should follow the exact same pattern / usage of WSLCCreateSession, which this new event doesn't seem to.
Is it possible to adjust this PR to reflect that?
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 1 out of 1 changed files in this pull request and generated no new comments.
Comments suppressed due to low confidence (2)
src/windows/service/exe/LxssUserSession.cpp:2565
- The PR description says the new cold-start telemetry reports Success/Failure/Timeout and that existing CreateInstanceBegin/CreateInstanceEnd telemetry remains unchanged. In this hunk, CreateInstanceBegin/End are removed and the new CreateInstanceOutcome event does not include an explicit outcome/timeout threshold (or any 3-minute timeout logic). Either the implementation is incomplete, or the PR description needs to be updated to match what’s actually being logged.
wsl::windows::common::wslutil::StopWatch stopWatch;
const auto result = wil::ResultFromException([&]() {
auto clientKey = m_lifetimeManager.GetRegistrationId();
src/windows/service/exe/LxssUserSession.cpp:2661
- CreateInstanceOutcome uses field names "Name" and "Version", and it omits instanceId. In this same function/hunk, other instance-related events use the established schema keys "distroName"/"version"/"instanceId" (e.g., InitializeInstanceBegin/End immediately above). Using a different schema here makes querying/joining telemetry harder, and the missing instanceId also contradicts the PR description.
WSL_LOG(
"CreateInstanceOutcome",
TelemetryPrivacyDataTag(PDT_ProductAndServiceUsage),
TraceLoggingKeyword(MICROSOFT_KEYWORD_CRITICAL_DATA),
TraceLoggingValue(configuration.Name.c_str(), "Name"),
TraceLoggingValue(WSL_PACKAGE_VERSION, "wslVersion"),
TraceLoggingValue(version, "Version"),
TraceLoggingValue(stopWatch.ElapsedMilliseconds(), "CreationTimeMs"),
TraceLoggingValue(result, "Result"),
TraceLoggingLevel(WINEVENT_LEVEL_INFO));
|
@craigloewen-msft Thanks for the clarification. I’ve updated the implementation to follow the
One limitation of this completion-based pattern is that a true hang—such as an HCS operation waiting indefinitely or a synchronous plugin callback that never returns—will not emit This matches the |
|
It's good to call out that limitation - but I think that's ok. Can we keep the old events alive for now (And remove them in a future update) so we can compare and contrast? Lastly, right now the "WSL_LOG" macro is being used and not the "WSL_LOG_TELEMETRY" macro. It's a bit confusing (Especially since we have other areas like the 'ExecCritical' where we use WSL_LOG) can we fix that as part of this PR too? |
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 1 out of 1 changed files in this pull request and generated no new comments.
Suppressed comments (1)
src/windows/service/exe/LxssUserSession.cpp:2679
- The PR description says CreateInstanceOutcome reports a 3-minute timeout outcome (Success/Failure/Timeout) and includes the timeout threshold (and “WSL version”), but the implementation here only logs elapsed milliseconds and an HRESULT (no explicit Outcome/Timeout fields and no timer/3-minute threshold). Either implement the timeout/outcome reporting described (e.g., add a timer-based ‘Timeout’ outcome + threshold fields) or update the PR description/event schema to match what’s actually emitted so downstream telemetry consumers don’t rely on fields/outcomes that never occur.
// This telemetry event is used to keep track of instance creation performance (via CreationTimeMs) and failure reasons (via Result).
WSL_LOG_TELEMETRY(
"CreateInstanceOutcome",
PDT_ProductAndServicePerformance,
TraceLoggingValue(configuration.Name.c_str(), "distroName"),
TraceLoggingValue(version, "version"),
TraceLoggingValue(instanceId, "instanceId"),
TraceLoggingValue(stopWatch.ElapsedMilliseconds(), "CreationTimeMs"),
TraceLoggingValue(result, "Result"));
There was a problem hiding this comment.
Pull request overview
Copilot reviewed 1 out of 1 changed files in this pull request and generated no new comments.
Suppressed comments (2)
src/windows/service/exe/LxssUserSession.cpp:2676
- PR description says this change introduces a timer-based reporter that emits exactly one of {Success, Failure, Timeout} (with a 3-minute threshold) for cold-start instance creation. The current implementation only logs CreateInstanceOutcome after the create path finishes and has no timeout path or explicit outcome/threshold fields, so it does not match the described behavior/contract. Either update the PR description/title to match the implemented telemetry, or implement the described timeout-capable single-shot outcome reporting (including outcome + timeout threshold fields).
WSL_LOG_TELEMETRY(
"CreateInstanceOutcome",
PDT_ProductAndServicePerformance,
TraceLoggingValue(configuration.Name.c_str(), "distroName"),
TraceLoggingValue(version, "version"),
src/windows/service/exe/LxssUserSession.cpp:2585
- This change replaces the previous
try/catch { result = wil::ResultFromCaughtException(); throw; }withresult = wil::ResultFromException(...)+THROW_IF_FAILED(result). That alters exception propagation (original exception types/stack are no longer rethrown; everything becomes an HRESULT-based WIL exception), which can affect crash diagnostics and any callers that distinguished exception types. If the intent is telemetry-only, consider keeping the old rethrow behavior and moving the outcome logging into a scope-exit so it still recordsresult/duration on both success and failure without changing the thrown exception type.
wsl::windows::common::wslutil::StopWatch stopWatch;
result = wil::ResultFromException([&]() {
auto clientKey = m_lifetimeManager.GetRegistrationId();
Summary of the Pull Request
Adds
CreateInstanceOutcometelemetry for WSL cold starts to report whether instance creation succeeded, failed, or exceeded a three-minute timeout.PR Checklist
Detailed Description of the Pull Request / Additional comments
Introduces
TimedOperationOutcomeReporter, which uses a one-shot thread-pool timer and an atomic completion gate to report exactly one outcome:Successwhen cold-start creation completes successfully within three minutes.Failurewhen creation returns an error within three minutes.Timeoutwhen creation remains incomplete after three minutes.The timeout is telemetry-only and does not cancel or otherwise affect instance creation.
The new event includes the distro name, WSL version, instance ID, outcome, elapsed time, timeout threshold, and HRESULT. Existing
CreateInstanceBeginandCreateInstanceEndtelemetry remains unchanged.Validation Steps Performed
Manually tested.