Skip to content

Commit 7fb4c06

Browse files
StellaHuang95Copiloteleanorjboyd
authored
Add PET version, build ID, and commit SHA to telemetry (microsoft#1574)
## Context PET (Python Environment Tools) is the Rust JSON-RPC service this extension uses to discover Python environments. PET ships independently of the extension and is bundled as a binary inside the VSIX, so the PET version a user is running can drift from the extension version. When we see a performance regression or a failure in PET telemetry today, we have no way to map it back to the **exact PET source code** the user is running — we know `pet --version` (already telemetered via `PET.VERSION`) but a single PET version line can correspond to many commits across multiple builds. This PR closes that gap by stamping every PET telemetry event with the binary's `petVersion`, `petBuildId`, and `petCommitSha`, sourced directly from the running PET process via a new `info` JSON-RPC request. We can then `summarize by petCommitSha` in Kusto and join straight to git log to find the offending change. ## Related PRs PET side (both merged): - microsoft/python-environment-tools#470 — adds the `info` JSON-RPC request returning `petVersion` and optional `buildId` - microsoft/python-environment-tools#473 — extends the `info` response with optional `commitSha` baked in from CI env vars (`PET_COMMIT_SHA` / `BUILD_SOURCEVERSION` / `GITHUB_SHA`) Supersedes / replaces: - microsoft#1548 — earlier draft that only added `petVersion` + `petBuildId` and accidentally corrupted the enum docstring for `PET_RESOLVE` / `MIGRATION_SYSTEM_ENV_MANAGER`. Please close. ## What this PR does 1. **Defines a typed `NativePetInfo` interface** matching PET's `info` response shape (`petVersion: string`, `buildId?: string`, `commitSha?: string`). 2. **Sends one `info` RPC per PET process start** in `kickoffInfoFetch(connection)`, called immediately after `connection.listen()` inside `start()`. The call is **fire-and-forget** with a 2 s timeout — `start()` does not await it, so discovery is never blocked. The response is cached in `this.petInfo` for the lifetime of that PET process. `this.petInfo` is reset to `undefined` on every `start()` (initial spawn + every crash-recovery restart). 3. **Guards against stale responses** via `connection !== this.connection` checks in both `.then` and `.catch`, so a late reply from a previous PET process can't clobber the cache of a newer one after a restart. 4. **Spreads `getPetInfoProperties()` into the six existing PET telemetry call sites** (success + error paths of `PET_RESOLVE`, `PET_REFRESH`, `PET_PROCESS_RESTART`). The helper always returns concrete strings, defaulting each field to `'unknown'`, so Kusto group-bys work without null handling. 5. **Adds GDPR comments + TypeScript types** for the three new fields on `PET_RESOLVE`, `PET_REFRESH`, `PET_PROCESS_RESTART`. All classified as `SystemMetaData` / `PerformanceAndHealth`. ## Files changed | File | Why | |---|---| | `src/managers/common/nativePythonFinder.ts` | `INFO_TIMEOUT_MS` constant, `NativePetInfo` interface, `petInfo` field, `kickoffInfoFetch` + `getPetInfoProperties` helpers, kickoff wiring in `start()`, payload spread at six telemetry sites | | `src/common/telemetry/constants.ts` | New `petVersion` / `petBuildId` / `petCommitSha` properties on `PET_RESOLVE`, `PET_REFRESH`, `PET_PROCESS_RESTART` (GDPR blocks + TS types) | ## Compatibility with older PET binaries The extension currently ships PET as a bundled binary (downloaded by the Azure pipelines from PET CI artifacts). Until the PET release branch picks up microsoft#470 / microsoft#473, the bundled binary won't have the `info` handler. In that case: - PET responds with JSON-RPC error code `-1` (`Failed to find handler for request info`) - `sendRequestWithTimeout` rejects → `.catch` swallows → `petInfo` stays `undefined` - All three telemetry properties report `'unknown'` - One harmless `[pet] Failed to find handler for method: info` line surfaces from PET's stderr into the Python Environments output channel Discovery, refresh, resolve, and restart all continue to work normally. No crash, no functional regression — just `'unknown'` values in telemetry until PET catches up. ## Crash attribution semantics A subtle but important detail of where the spread is placed: the crashing PET's commit hash **is** captured in `PET_REFRESH` / `PET_RESOLVE` error events because we call `sendTelemetryEvent(..., ...this.getPetInfoProperties())` **before** killing the process and resetting the cache. So when a user reports "PET crashed during refresh", we can identify which exact commit was running. The `PET_PROCESS_RESTART` success event itself reports `'unknown'` for the **new** PET (its `info` reply usually hasn't landed in the few ms between `start()` and the telemetry call), but the new binary's identity surfaces on the very next refresh/resolve. ## Performance impact - One extra JSON-RPC roundtrip **per PET process lifetime** (typically once per VS Code session), not per telemetry event - ~3 string allocations per telemetry event from the spread — invisible against existing payload assembly - `kickoffInfoFetch` returns `void` synchronously; the response runs on the microtask queue and never blocks refresh/resolve - 2 s timeout caps the worst case if PET hangs entirely ## Validation - `npm run lint` ✅ - `npx tsc -p . --noEmit` ✅ - `npm run compile-tests` ✅ - `npm run unittest` — 1141 passing, 2 pending (unchanged from baseline) ✅ - `npm run compile` (webpack production bundle) ✅ ## Manual testing To get non-`'unknown'` values locally, build PET from main and drop the binary into `python-env-tools/bin/`: ```powershell # In the PET repo: $env:PET_COMMIT_SHA = (git rev-parse HEAD) $env:PET_BUILD_ID = "local-dev" cargo build --release --package pet # In this repo: Copy-Item <pet-repo>\target\release\pet.exe .\python-env-tools\bin\pet.exe -Force ``` Then F5 → open the Python Environments view → run `Python Environments: Refresh Environments`. Set the Python Environments output channel to Debug level to see the `[pet] info: { petVersion, buildId, commitSha }` line confirming the cache was populated. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Co-authored-by: Eleanor Boyd <26030610+eleanorjboyd@users.noreply.github.com>
1 parent 34c9e53 commit 7fb4c06

2 files changed

Lines changed: 106 additions & 2 deletions

File tree

src/common/telemetry/constants.ts

Lines changed: 27 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -593,6 +593,9 @@ export interface IEventNamePropertyMapping {
593593
"breakdownGlobalVirtualEnvs": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "owner": "eleanorjboyd" },
594594
"breakdownWorkspaces": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "isMeasurement": true, "owner": "eleanorjboyd" },
595595
"locatorsJson": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
596+
"petVersion": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
597+
"petBuildId": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
598+
"petCommitSha": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
596599
"<duration>": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "eleanorjboyd" }
597600
}
598601
*/
@@ -615,6 +618,12 @@ export interface IEventNamePropertyMapping {
615618
breakdownWorkspaces?: number;
616619
/** JSON-serialized Record<locatorName, ms>. Parse with parse_json() in Kusto. */
617620
locatorsJson?: string;
621+
/** PET crate version reported by the `info` RPC. 'unknown' if the call failed or the PET binary doesn't implement it. */
622+
petVersion?: string;
623+
/** PET build identifier (CI build run ID) reported by the `info` RPC. 'unknown' if unavailable. */
624+
petBuildId?: string;
625+
/** PET source git commit SHA reported by the `info` RPC. 'unknown' if unavailable. */
626+
petCommitSha?: string;
618627
};
619628

620629
/* __GDPR__
@@ -639,6 +648,9 @@ export interface IEventNamePropertyMapping {
639648
"result": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
640649
"errorType": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
641650
"triggerReason": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
651+
"petVersion": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
652+
"petBuildId": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
653+
"petCommitSha": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
642654
"<duration>": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "eleanorjboyd" }
643655
}
644656
*/
@@ -654,18 +666,33 @@ export interface IEventNamePropertyMapping {
654666
* start_failed | unknown.
655667
*/
656668
triggerReason: string;
669+
/** PET crate version reported by the `info` RPC. 'unknown' if the call failed or the PET binary doesn't implement it. */
670+
petVersion?: string;
671+
/** PET build identifier (CI build run ID) reported by the `info` RPC. 'unknown' if unavailable. */
672+
petBuildId?: string;
673+
/** PET source git commit SHA reported by the `info` RPC. 'unknown' if unavailable. */
674+
petCommitSha?: string;
657675
};
658676

659677
/* __GDPR__
660678
"pet.resolve": {
661679
"result": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
662680
"errorType": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
681+
"petVersion": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
682+
"petBuildId": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
683+
"petCommitSha": { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
663684
"<duration>": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "eleanorjboyd" }
664685
}
665686
*/
666687
[EventNames.PET_RESOLVE]: {
667688
result: 'success' | 'timeout' | 'error';
668689
errorType?: string;
690+
/** PET crate version reported by the `info` RPC. 'unknown' if the call failed or the PET binary doesn't implement it. */
691+
petVersion?: string;
692+
/** PET build identifier (CI build run ID) reported by the `info` RPC. 'unknown' if unavailable. */
693+
petBuildId?: string;
694+
/** PET source git commit SHA reported by the `info` RPC. 'unknown' if unavailable. */
695+
petCommitSha?: string;
669696
};
670697

671698
/* __GDPR__

src/managers/common/nativePythonFinder.ts

Lines changed: 79 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -24,6 +24,7 @@ const CONFIGURE_TIMEOUT_MS = 30_000; // 30 seconds for configuration
2424
const MAX_CONFIGURE_TIMEOUT_MS = 60_000; // Max configure timeout after retries (60s)
2525
const REFRESH_TIMEOUT_MS = 30_000; // 30 seconds for full refresh (with 1 retry = 60s max)
2626
const RESOLVE_TIMEOUT_MS = 30_000; // 30 seconds for single resolve
27+
const INFO_TIMEOUT_MS = 2_000; // `info` is a const lookup on PET; 2s is generous
2728

2829
// CLI fallback timeout: generous budget since it's a full process spawn doing a full scan
2930
const CLI_FALLBACK_TIMEOUT_MS = 120_000; // 2 minutes
@@ -265,6 +266,17 @@ interface PetTelemetryNotification {
265266
};
266267
}
267268

269+
/**
270+
* Response shape of the PET `info` JSON-RPC request.
271+
* `buildId` / `commitSha` are populated only when the PET binary was built by CI
272+
* with the appropriate env vars set; local dev builds omit them.
273+
*/
274+
interface NativePetInfo {
275+
petVersion: string;
276+
buildId?: string;
277+
commitSha?: string;
278+
}
279+
268280
/**
269281
* Error thrown when a JSON-RPC request times out.
270282
*/
@@ -322,6 +334,13 @@ class NativePythonFinderImpl implements NativePythonFinder {
322334
private isRestarting: boolean = false;
323335
private processExitReason: string | undefined = undefined;
324336
private readonly configureRetry = new ConfigureRetryState();
337+
/**
338+
* Cached PET `info` response for the current connection. Reset to undefined on every
339+
* `start()` and re-populated asynchronously by `kickoffInfoFetch()`. Telemetry callers
340+
* read this via `getPetInfoProperties()`; if the fetch hasn't finished yet (or the PET
341+
* binary is too old to implement `info`), telemetry reports 'unknown'.
342+
*/
343+
private petInfo: NativePetInfo | undefined;
325344

326345
constructor(
327346
private readonly outputChannel: LogOutputChannel,
@@ -353,7 +372,10 @@ class NativePythonFinderImpl implements NativePythonFinder {
353372
this.outputChannel.info(`Resolved Python Environment ${environment.executable}`);
354373
// Reset restart attempts on successful request
355374
this.restartAttempts = 0;
356-
sendTelemetryEvent(EventNames.PET_RESOLVE, sw.elapsedTime, { result: 'success' });
375+
sendTelemetryEvent(EventNames.PET_RESOLVE, sw.elapsedTime, {
376+
result: 'success',
377+
...this.getPetInfoProperties(),
378+
});
357379
return environment;
358380
} catch (ex) {
359381
// On resolve timeout or connection error (not configure — configure handles its own timeout),
@@ -376,6 +398,7 @@ class NativePythonFinderImpl implements NativePythonFinder {
376398
{
377399
result: errorType === 'spawn_timeout' ? 'timeout' : 'error',
378400
errorType,
401+
...this.getPetInfoProperties(),
379402
},
380403
ex instanceof Error ? ex : undefined,
381404
);
@@ -460,6 +483,7 @@ class NativePythonFinderImpl implements NativePythonFinder {
460483
attempt,
461484
result: 'success',
462485
triggerReason,
486+
...this.getPetInfoProperties(),
463487
});
464488

465489
// Reset restart attempts on successful start (process didn't immediately fail)
@@ -468,7 +492,13 @@ class NativePythonFinderImpl implements NativePythonFinder {
468492
sendTelemetryEvent(
469493
EventNames.PET_PROCESS_RESTART,
470494
sw.elapsedTime,
471-
{ attempt, result: 'error', errorType: classifyError(ex), triggerReason },
495+
{
496+
attempt,
497+
result: 'error',
498+
errorType: classifyError(ex),
499+
triggerReason,
500+
...this.getPetInfoProperties(),
501+
},
472502
ex instanceof Error ? ex : undefined,
473503
);
474504
this.outputChannel.error('[pet] Failed to restart Python Environment Tools:', ex);
@@ -701,9 +731,54 @@ class NativePythonFinderImpl implements NativePythonFinder {
701731
);
702732

703733
connection.listen();
734+
735+
// Stamp PET telemetry with version/buildId/commitSha. Fire-and-forget — must not block refresh.
736+
this.petInfo = undefined;
737+
this.kickoffInfoFetch(connection);
738+
704739
return connection;
705740
}
706741

742+
/**
743+
* Asks the PET server for its build metadata (version + optional buildId + optional commitSha)
744+
* and caches it in `this.petInfo` for downstream telemetry. Runs once per `start()` call.
745+
*
746+
* Fire-and-forget by design — the response is not awaited so refresh/resolve callers are
747+
* never blocked. The 2 s timeout caps the worst case if PET is misbehaving. If a newer
748+
* connection has replaced `this.connection` by the time the response arrives, the response
749+
* is dropped to avoid clobbering the cache for the newer process.
750+
*/
751+
private kickoffInfoFetch(connection: rpc.MessageConnection): void {
752+
sendRequestWithTimeout<NativePetInfo>(connection, 'info', {}, INFO_TIMEOUT_MS)
753+
.then((result) => {
754+
if (connection !== this.connection) {
755+
return;
756+
}
757+
this.petInfo = result;
758+
this.outputChannel.debug('[pet] info:', result);
759+
})
760+
.catch((ex) => {
761+
if (connection !== this.connection) {
762+
return;
763+
}
764+
// Older PET binaries don't implement `info`; leave petInfo undefined so telemetry reports 'unknown'.
765+
this.outputChannel.debug('[pet] info request failed:', ex);
766+
});
767+
}
768+
769+
/**
770+
* Builds the petVersion/petBuildId/petCommitSha properties for PET telemetry events.
771+
* Always returns concrete strings (defaulting to 'unknown') so Kusto can group by them
772+
* without dealing with nulls.
773+
*/
774+
private getPetInfoProperties(): { petVersion: string; petBuildId: string; petCommitSha: string } {
775+
return {
776+
petVersion: this.petInfo?.petVersion ?? 'unknown',
777+
petBuildId: this.petInfo?.buildId ?? 'unknown',
778+
petCommitSha: this.petInfo?.commitSha ?? 'unknown',
779+
};
780+
}
781+
707782
private async doRefresh(options?: NativePythonEnvironmentKind | Uri[]): Promise<NativeInfo[]> {
708783
let lastError: unknown;
709784

@@ -840,6 +915,7 @@ class NativePythonFinderImpl implements NativePythonFinder {
840915
searchPathCount,
841916
attempt,
842917
locatorsJson: refreshPerf ? JSON.stringify(refreshPerf.locators) : undefined,
918+
...this.getPetInfoProperties(),
843919
},
844920
);
845921
} catch (ex) {
@@ -853,6 +929,7 @@ class NativePythonFinderImpl implements NativePythonFinder {
853929
unresolvedCount,
854930
attempt,
855931
errorType,
932+
...this.getPetInfoProperties(),
856933
},
857934
ex instanceof Error ? ex : undefined,
858935
);

0 commit comments

Comments
 (0)