Skip to content

Commit 1423907

Browse files
committed
Add telemetry events for unittest execution and discovery cycles
- Introduced new telemetry events: UNITTEST_RUN_DONE and UNITTEST_TREE_UPDATE. - Enhanced existing telemetry events to capture additional properties such as mode, trigger, and duration. - Updated the telemetry context for test discovery to include more detailed metrics. - Refactored telemetry emission to ensure accurate reporting during test execution and discovery processes.
1 parent 347b1ac commit 1423907

9 files changed

Lines changed: 419 additions & 41 deletions

File tree

src/client/telemetry/constants.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -48,7 +48,9 @@ export enum EventName {
4848
UNITTEST_DISCOVERY_DONE = 'UNITTEST.DISCOVERY.DONE',
4949
UNITTEST_RUN_STOP = 'UNITTEST.RUN.STOP',
5050
UNITTEST_RUN = 'UNITTEST.RUN',
51+
UNITTEST_RUN_DONE = 'UNITTEST.RUN.DONE',
5152
UNITTEST_RUN_ALL_FAILED = 'UNITTEST.RUN_ALL_FAILED',
53+
UNITTEST_TREE_UPDATE = 'UNITTEST.TREE.UPDATE',
5254
UNITTEST_DISABLED = 'UNITTEST.DISABLED',
5355

5456
PYTHON_EXPERIMENTS_INIT_PERFORMANCE = 'PYTHON_EXPERIMENTS_INIT_PERFORMANCE',

src/client/telemetry/index.ts

Lines changed: 147 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -2127,7 +2127,9 @@ export interface IEventNamePropertyMapping {
21272127
*/
21282128
/* __GDPR__
21292129
"unittest.discovery.trigger" : {
2130-
"trigger" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" }
2130+
"trigger" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2131+
"filekind" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2132+
"mssincelasttrigger" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true }
21312133
}
21322134
*/
21332135
[EventName.UNITTEST_DISCOVERY_TRIGGER]: {
@@ -2142,6 +2144,16 @@ export interface IEventNamePropertyMapping {
21422144
* interpreter : Triggered by interpreter change.
21432145
*/
21442146
trigger: 'auto' | 'ui' | 'commandpalette' | 'watching' | 'interpreter';
2147+
/**
2148+
* For 'auto' / 'watching' triggers, classifies the file whose change triggered discovery.
2149+
* Used to detect whether discovery is firing on non-test files (see #25866).
2150+
*/
2151+
fileKind?: 'test' | 'conftest' | 'non-test' | 'unknown';
2152+
/**
2153+
* Milliseconds since the previous discovery trigger fired (any source).
2154+
* Helps detect chatty re-trigger storms.
2155+
*/
2156+
msSinceLastTrigger?: number;
21452157
};
21462158
/**
21472159
* Telemetry event sent with details about discovering tests
@@ -2165,7 +2177,13 @@ export interface IEventNamePropertyMapping {
21652177
/* __GDPR__
21662178
"unittest.discovery.done" : {
21672179
"tool" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2168-
"failed" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" }
2180+
"failed" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2181+
"mode" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2182+
"trigger" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2183+
"failurecategory" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
2184+
"totaldurationms" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true },
2185+
"testcount" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true },
2186+
"exitcode" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true }
21692187
}
21702188
*/
21712189
[EventName.UNITTEST_DISCOVERY_DONE]: {
@@ -2181,6 +2199,39 @@ export interface IEventNamePropertyMapping {
21812199
* @type {boolean}
21822200
*/
21832201
failed: boolean;
2202+
/**
2203+
* Discovery code path: 'project' = Python Environments API / project-based;
2204+
* 'legacy' = single-workspace adapter fallback.
2205+
*/
2206+
mode?: 'project' | 'legacy';
2207+
/**
2208+
* Source that triggered the discovery (mirrors UNITTEST_DISCOVERY_TRIGGER.trigger).
2209+
*/
2210+
trigger?: 'auto' | 'ui' | 'commandpalette' | 'watching' | 'interpreter';
2211+
/**
2212+
* Coarse failure category. Only populated when `failed` is true.
2213+
*/
2214+
failureCategory?:
2215+
| 'subprocess-exit-non-zero'
2216+
| 'pipe-error'
2217+
| 'pytest-collect-error'
2218+
| 'plugin-exception'
2219+
| 'timeout'
2220+
| 'env-resolution'
2221+
| 'cancelled'
2222+
| 'unknown';
2223+
/**
2224+
* Wall-clock duration of the discovery cycle in milliseconds.
2225+
*/
2226+
totalDurationMs?: number;
2227+
/**
2228+
* Number of test items discovered (leaf nodes).
2229+
*/
2230+
testCount?: number;
2231+
/**
2232+
* Subprocess exit code, when known (failed discoveries).
2233+
*/
2234+
exitCode?: number;
21842235
};
21852236
/**
21862237
* Telemetry event sent when cancelling discovering tests
@@ -2222,6 +2273,100 @@ export interface IEventNamePropertyMapping {
22222273
"unittest.run.all_failed" : { "owner": "eleanorjboyd" }
22232274
*/
22242275
[EventName.UNITTEST_RUN_ALL_FAILED]: never | undefined;
2276+
/**
2277+
* Telemetry event sent at the end of a test run, capturing duration and pipe health.
2278+
* Companion to UNITTEST_RUN (which is emitted at run start).
2279+
*/
2280+
/* __GDPR__
2281+
"unittest.run.done" : {
2282+
"tool" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2283+
"debugging" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2284+
"mode" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2285+
"failed" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2286+
"failurecategory" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
2287+
"pipeclosedearly" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
2288+
"durationms" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true },
2289+
"requestedcount" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true },
2290+
"reportedcount" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true },
2291+
"missingcount" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true },
2292+
"exitcode" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true }
2293+
}
2294+
*/
2295+
[EventName.UNITTEST_RUN_DONE]: {
2296+
tool: TestTool;
2297+
debugging: boolean;
2298+
mode: 'project' | 'legacy';
2299+
/**
2300+
* `true` if the run ended without reporting all requested results,
2301+
* or if the subprocess crashed / threw.
2302+
*/
2303+
failed: boolean;
2304+
/**
2305+
* Coarse failure category when `failed` is true.
2306+
*/
2307+
failureCategory?:
2308+
| 'pipe-cancelled'
2309+
| 'subprocess-crash'
2310+
| 'no-results'
2311+
| 'env-mismatch'
2312+
| 'cancelled'
2313+
| 'unknown';
2314+
/**
2315+
* `true` if the result pipe was disposed before the subprocess fully
2316+
* reported all requested test results (see #25872).
2317+
*/
2318+
pipeClosedEarly?: boolean;
2319+
/**
2320+
* Wall-clock duration of the run in milliseconds.
2321+
*/
2322+
durationMs?: number;
2323+
/**
2324+
* Number of test items the user asked to run.
2325+
*/
2326+
requestedCount?: number;
2327+
/**
2328+
* Number of distinct test results reported back over the pipe.
2329+
*/
2330+
reportedCount?: number;
2331+
/**
2332+
* requestedCount - reportedCount (signals #25892 "all skipped" pattern).
2333+
*/
2334+
missingCount?: number;
2335+
/**
2336+
* Subprocess exit code when known.
2337+
*/
2338+
exitCode?: number;
2339+
};
2340+
/**
2341+
* Telemetry event emitted after the test tree is updated with new discovery results.
2342+
* Used to detect full-rebuild-on-every-save pattern (see #25822, #25866).
2343+
*/
2344+
/* __GDPR__
2345+
"unittest.tree.update" : {
2346+
"tool" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2347+
"mode" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" },
2348+
"rebuiltfromscratch" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd" },
2349+
"beforecount" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true },
2350+
"aftercount" : { "classification": "SystemMetaData", "purpose": "PerformanceAndHealth", "owner": "eleanorjboyd", "isMeasurement": true }
2351+
}
2352+
*/
2353+
[EventName.UNITTEST_TREE_UPDATE]: {
2354+
tool: TestTool;
2355+
mode: 'project' | 'legacy';
2356+
/**
2357+
* `true` if the discovery handler cleared and rebuilt all test items rather
2358+
* than performing an incremental update.
2359+
*/
2360+
rebuiltFromScratch: boolean;
2361+
/**
2362+
* Number of root test items in the controller before this update.
2363+
*/
2364+
beforeCount: number;
2365+
/**
2366+
* Number of root test items in the controller after this update.
2367+
*/
2368+
afterCount: number;
2369+
};
22252370
/**
22262371
* Telemetry event sent when testing is disabled for a workspace.
22272372
*/

src/client/testing/testController/common/projectTestExecution.ts

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ import { CancellationToken, FileCoverageDetail, TestItem, TestRun, TestRunProfil
55
import { traceError, traceInfo, traceVerbose, traceWarn } from '../../../logging';
66
import { sendTelemetryEvent } from '../../../telemetry';
77
import { EventName } from '../../../telemetry/constants';
8+
import { StopWatch } from '../../../common/utils/stopWatch';
89
import { IPythonExecutionFactory } from '../../../common/process/types';
910
import { ITestDebugLauncher } from '../../common/types';
1011
import { ProjectAdapter } from './projectAdapter';
@@ -70,13 +71,35 @@ export async function executeTestsForProjects(
7071
debugging: isDebugMode,
7172
});
7273

74+
const stopWatch = new StopWatch();
75+
let failed = false;
76+
let failureCategory:
77+
| 'pipe-cancelled'
78+
| 'subprocess-crash'
79+
| 'no-results'
80+
| 'env-mismatch'
81+
| 'cancelled'
82+
| 'unknown'
83+
| undefined;
7384
try {
7485
await executeTestsForProject(project, items, runInstance, request, deps);
7586
} catch (error) {
87+
failed = true;
88+
failureCategory = token.isCancellationRequested ? 'cancelled' : 'unknown';
7689
// Don't log cancellation as an error
7790
if (!token.isCancellationRequested) {
7891
traceError(`[test-by-project] Execution failed for project ${project.projectName}:`, error);
7992
}
93+
} finally {
94+
sendTelemetryEvent(EventName.UNITTEST_RUN_DONE, undefined, {
95+
tool: project.testProvider,
96+
debugging: isDebugMode,
97+
mode: 'project',
98+
failed,
99+
failureCategory,
100+
durationMs: stopWatch.elapsedTime,
101+
requestedCount: items.length,
102+
});
80103
}
81104
});
82105

src/client/testing/testController/common/resultResolver.ts

Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -7,10 +7,29 @@ import { TestProvider } from '../../types';
77
import { traceInfo } from '../../../logging';
88
import { sendTelemetryEvent } from '../../../telemetry';
99
import { EventName } from '../../../telemetry/constants';
10+
import { StopWatch } from '../../../common/utils/stopWatch';
1011
import { TestItemIndex } from './testItemIndex';
1112
import { TestDiscoveryHandler } from './testDiscoveryHandler';
1213
import { TestExecutionHandler } from './testExecutionHandler';
1314
import { TestCoverageHandler } from './testCoverageHandler';
15+
import { DiscoveredTestNode, DiscoveredTestItem } from './types';
16+
17+
/**
18+
* Trigger source label for the current discovery cycle (matches
19+
* UNITTEST_DISCOVERY_TRIGGER.trigger values).
20+
*/
21+
export type DiscoveryTriggerKind = 'auto' | 'ui' | 'commandpalette' | 'watching' | 'interpreter';
22+
23+
/**
24+
* Per-cycle context the controller passes to the resolver so DISCOVERY_DONE can
25+
* include trigger source, mode, and wall-clock duration without having to plumb
26+
* these through every adapter call.
27+
*/
28+
export interface DiscoveryCycleContext {
29+
mode: 'project' | 'legacy';
30+
trigger?: DiscoveryTriggerKind;
31+
stopWatch: StopWatch;
32+
}
1433

1534
export class PythonResultResolver implements ITestResultResolver {
1635
testController: TestController;
@@ -39,6 +58,12 @@ export class PythonResultResolver implements ITestResultResolver {
3958
*/
4059
private projectName?: string;
4160

61+
/**
62+
* Per-cycle telemetry context set by the controller before invoking discovery.
63+
* Consumed (and cleared) by resolveDiscovery to emit UNITTEST_DISCOVERY_DONE.
64+
*/
65+
private discoveryCycle?: DiscoveryCycleContext;
66+
4267
constructor(
4368
testController: TestController,
4469
testProvider: TestProvider,
@@ -75,6 +100,39 @@ export class PythonResultResolver implements ITestResultResolver {
75100
return this.projectId;
76101
}
77102

103+
/**
104+
* Set per-discovery-cycle telemetry context. Called by the controller right
105+
* before invoking the discovery adapter so resolveDiscovery / failure paths
106+
* can include trigger, mode, and duration in UNITTEST_DISCOVERY_DONE.
107+
*/
108+
public beginDiscoveryCycle(ctx: Omit<DiscoveryCycleContext, 'stopWatch'>): void {
109+
this.discoveryCycle = { ...ctx, stopWatch: new StopWatch() };
110+
}
111+
112+
/**
113+
* Returns and clears the current discovery cycle context, if any.
114+
*/
115+
private takeDiscoveryCycle(): DiscoveryCycleContext | undefined {
116+
const cycle = this.discoveryCycle;
117+
this.discoveryCycle = undefined;
118+
return cycle;
119+
}
120+
121+
/**
122+
* Returns the current discovery cycle context without clearing it.
123+
* Used by error paths that still want to clear via takeDiscoveryCycle.
124+
*/
125+
public peekDiscoveryCycle(): DiscoveryCycleContext | undefined {
126+
return this.discoveryCycle;
127+
}
128+
129+
/**
130+
* Clears the current discovery cycle context.
131+
*/
132+
public clearDiscoveryCycle(): void {
133+
this.discoveryCycle = undefined;
134+
}
135+
78136
public resolveDiscovery(payload: DiscoveredTestPayload, token?: CancellationToken): void {
79137
PythonResultResolver.discoveryHandler.processDiscovery(
80138
payload,
@@ -86,9 +144,15 @@ export class PythonResultResolver implements ITestResultResolver {
86144
this.projectId,
87145
this.projectName,
88146
);
147+
const cycle = this.takeDiscoveryCycle();
148+
const mode = cycle?.mode ?? (this.projectId ? 'project' : 'legacy');
89149
sendTelemetryEvent(EventName.UNITTEST_DISCOVERY_DONE, undefined, {
90150
tool: this.testProvider,
91151
failed: false,
152+
mode,
153+
trigger: cycle?.trigger,
154+
totalDurationMs: cycle?.stopWatch.elapsedTime,
155+
testCount: payload?.tests ? countDiscoveredTests(payload.tests) : 0,
92156
});
93157
}
94158

@@ -135,3 +199,19 @@ export class PythonResultResolver implements ITestResultResolver {
135199
this.testItemIndex.cleanupStaleReferences(this.testController);
136200
}
137201
}
202+
203+
/**
204+
* Recursively counts leaf test items in a discovered test tree.
205+
* Used to populate UNITTEST_DISCOVERY_DONE.testCount.
206+
*/
207+
function countDiscoveredTests(node: DiscoveredTestNode | DiscoveredTestItem): number {
208+
if ((node as DiscoveredTestNode).children === undefined) {
209+
// No children -> leaf (DiscoveredTestItem).
210+
return 1;
211+
}
212+
let total = 0;
213+
for (const child of (node as DiscoveredTestNode).children) {
214+
total += countDiscoveredTests(child);
215+
}
216+
return total;
217+
}

src/client/testing/testController/common/testDiscoveryHandler.ts

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,8 @@ import * as util from 'util';
66
import { DiscoveredTestPayload } from './types';
77
import { TestProvider } from '../../types';
88
import { traceError, traceWarn } from '../../../logging';
9+
import { sendTelemetryEvent } from '../../../telemetry';
10+
import { EventName } from '../../../telemetry/constants';
911
import { Testing } from '../../../common/utils/localize';
1012
import { createErrorTestItem } from './testItemUtilities';
1113
import { buildErrorNodeOptions, populateTestTree } from './utils';
@@ -54,6 +56,9 @@ export class TestDiscoveryHandler {
5456
// if any tests exist, they should be populated in the test tree, regardless of whether there were errors or not.
5557
// parse and insert test data.
5658

59+
// Snapshot root-item count before update for UNITTEST_TREE_UPDATE telemetry.
60+
const beforeCount = testController.items.size;
61+
5762
// Clear existing mappings before rebuilding test tree
5863
testItemIndex.clear();
5964

@@ -73,6 +78,19 @@ export class TestDiscoveryHandler {
7378
projectId,
7479
projectName,
7580
);
81+
82+
// Emit TREE_UPDATE so we can quantify how often the tree is being rebuilt
83+
// from scratch versus changing incrementally (see #25822, #25866).
84+
// populateTestTree currently always rebuilds the subtree under the workspace/project root,
85+
// so rebuiltFromScratch is true today; we keep the field so future incremental updates
86+
// can flip it to false without a schema change.
87+
sendTelemetryEvent(EventName.UNITTEST_TREE_UPDATE, undefined, {
88+
tool: testProvider,
89+
mode: projectId ? 'project' : 'legacy',
90+
rebuiltFromScratch: true,
91+
beforeCount,
92+
afterCount: testController.items.size,
93+
});
7694
}
7795
}
7896

0 commit comments

Comments
 (0)