Skip to content

Added outcome telemetry for cold start - #41200

Open
shuaiyuanxx wants to merge 7 commits into
masterfrom
user/shawn/add-outcome-telemetry
Open

Added outcome telemetry for cold start#41200
shuaiyuanxx wants to merge 7 commits into
masterfrom
user/shawn/add-outcome-telemetry

Conversation

@shuaiyuanxx

Copy link
Copy Markdown
Contributor

Summary of the Pull Request

Adds CreateInstanceOutcome telemetry for WSL cold starts to report whether instance creation succeeded, failed, or exceeded a three-minute timeout.

PR Checklist

  • Closes: Link to issue #xxx
  • Communication: I've discussed this with core contributors already. If work hasn't been agreed, this work might be rejected
  • Tests: Added/updated if needed and all pass
  • Localization: All end user facing strings can be localized
  • Dev docs: Added/updated if needed
  • Documentation updated: If checked, please file a pull request on our docs repo and link it here: #xxx

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:

  • Success when cold-start creation completes successfully within three minutes.
  • Failure when creation returns an error within three minutes.
  • Timeout when 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 CreateInstanceBegin and CreateInstanceEnd telemetry remains unchanged.

Validation Steps Performed

Manually tested.

Copilot AI review requested due to automatic review settings July 29, 2026 04:36
@shuaiyuanxx
shuaiyuanxx requested a review from a team as a code owner July 29, 2026 04:36

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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::_CreateInstance to emit CreateInstanceOutcome telemetry with outcome, elapsed time, timeout threshold, and HRESULT.
  • Updates the src/windows/common CMakeLists 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.

Comment thread src/windows/common/TimedOperationOutcomeReporter.h Outdated
Copilot AI review requested due to automatic review settings July 29, 2026 04:42

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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>
Copilot AI review requested due to automatic review settings July 29, 2026 04:53

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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);
    }

@shuaiyuanxx
shuaiyuanxx enabled auto-merge (squash) July 29, 2026 04:59

@craigloewen-msft craigloewen-msft left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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?

Copilot AI review requested due to automatic review settings July 31, 2026 02:05

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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));

@shuaiyuanxx

Copy link
Copy Markdown
Contributor Author

@craigloewen-msft Thanks for the clarification. I’ve updated the implementation to follow the WSLCCreateSession pattern:

  • Removed CreateInstanceBegin and CreateInstanceEnd.
  • Removed the timer-based timeout reporting.
  • Wrapped instance creation with wil::ResultFromException.
  • Emit a single CreateInstanceOutcome event after the operation completes, containing CreationTimeMs and the final Result.
  • Propagate failures after emitting the event.

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 CreateInstanceOutcome, because execution never reaches the telemetry call. Ctrl+C or terminating the client also does not reliably cancel the service-side operation.

This matches the WSLCCreateSession pattern and makes the event the single source of truth for completed startup attempts. Detecting operations that never return would require separate watchdog or correlation-based telemetry. Please let me know if that should be handled independently

@craigloewen-msft

Copy link
Copy Markdown
Member

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?

Copilot AI review requested due to automatic review settings August 3, 2026 02:25

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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"));

Copilot AI review requested due to automatic review settings August 3, 2026 02:29

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

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; } with result = 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 records result/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();

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants