From d923bb8c0fd6ccf92b1ee21c40cc64f0f556f513 Mon Sep 17 00:00:00 2001 From: eleanorjboyd <26030610+eleanorjboyd@users.noreply.github.com> Date: Fri, 25 Sep 2026 10:13:59 -0700 Subject: [PATCH] Track terminal activation outcomes and confirmed state (#1822) Distinguish shell command success, failure, timeout and unknown completion before updating activation state. Record bounded telemetry for both shell integration and unverified sendText attempts, with regression coverage for deactivation and environment switching.\n\nCo-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> --- src/common/telemetry/constants.ts | 22 ++ .../terminal/terminalActivationState.ts | 165 +++++++-------- src/features/terminal/terminalManager.ts | 8 +- .../terminalActivationState.unit.test.ts | 200 ++++++++++++++++++ 4 files changed, 301 insertions(+), 94 deletions(-) create mode 100644 src/test/features/terminal/terminalActivationState.unit.test.ts diff --git a/src/common/telemetry/constants.ts b/src/common/telemetry/constants.ts index 6b3432eb3..f157c6409 100644 --- a/src/common/telemetry/constants.ts +++ b/src/common/telemetry/constants.ts @@ -49,6 +49,11 @@ export enum EventNames { * - errorType: string (error class name, on failure only) */ ENVIRONMENT_DISCOVERY = 'ENVIRONMENT_DISCOVERY', + /** + * One event per terminal activation/deactivation command attempt. + * Legacy sendText cannot confirm command completion and is reported as unverified. + */ + TERMINAL_ACTIVATION_OUTCOME = 'TERMINAL.ACTIVATION_OUTCOME', MANAGER_READY_TIMEOUT = 'MANAGER_READY.TIMEOUT', /** * Telemetry event for individual manager registration failure. @@ -234,6 +239,23 @@ export enum EventNames { // Map all events to their properties export interface IEventNamePropertyMapping { + /* __GDPR__ + "terminal.activation_outcome": { + "operation": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" }, + "outcome": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" }, + "method": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" }, + "shell": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" }, + "trigger": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" }, + "": { "classification": "SystemMetaData", "purpose": "FeatureInsight", "isMeasurement": true, "owner": "eleanorjboyd" } + } + */ + [EventNames.TERMINAL_ACTIVATION_OUTCOME]: { + operation: 'activate' | 'deactivate'; + outcome: 'succeeded' | 'failed' | 'timedOut' | 'unknown' | 'unverified' | 'noCommand'; + method: 'shellIntegration' | 'sendText'; + shell: string; + trigger: 'terminalOpen' | 'preExisting' | 'explicit' | 'environmentSwitch' | 'unknown'; + }; /* __GDPR__ "extension.activation_duration": { "duration" : { "classification": "SystemMetaData", "purpose": "FeatureInsight", "owner": "eleanorjboyd" } diff --git a/src/features/terminal/terminalActivationState.ts b/src/features/terminal/terminalActivationState.ts index bd9a74d22..c9c6e5779 100644 --- a/src/features/terminal/terminalActivationState.ts +++ b/src/features/terminal/terminalActivationState.ts @@ -9,10 +9,17 @@ import { } from 'vscode'; import { PythonEnvironment } from '../../api'; import { traceError, traceInfo, traceVerbose } from '../../common/logging'; +import { StopWatch } from '../../common/stopWatch'; +import { EventNames } from '../../common/telemetry/constants'; +import { sendTelemetryEvent } from '../../common/telemetry/sender'; import { onDidEndTerminalShellExecution, onDidStartTerminalShellExecution } from '../../common/window.apis'; import { getActivationCommand, getDeactivationCommand } from '../common/activation'; +import { identifyTerminalShell } from '../common/shellDetector'; import { getShellIntegrationTimeout, isTaskTerminal, shouldSkipTerminalActivation } from './utils'; +type ActivationTrigger = 'terminalOpen' | 'preExisting' | 'explicit' | 'environmentSwitch' | 'unknown'; +type CommandOutcome = 'succeeded' | 'failed' | 'timedOut' | 'unknown' | 'unverified' | 'noCommand'; + export interface DidChangeTerminalActivationStateEvent { terminal: Terminal; environment: PythonEnvironment; @@ -21,8 +28,8 @@ export interface DidChangeTerminalActivationStateEvent { export interface TerminalActivation { isActivated(terminal: Terminal, environment?: PythonEnvironment): boolean; - activate(terminal: Terminal, environment: PythonEnvironment): Promise; - deactivate(terminal: Terminal): Promise; + activate(terminal: Terminal, environment: PythonEnvironment, trigger?: ActivationTrigger): Promise; + deactivate(terminal: Terminal, trigger?: ActivationTrigger): Promise; onDidChangeTerminalActivationState: Event; } @@ -50,8 +57,8 @@ export class TerminalActivationImpl implements TerminalActivationInternal { private onTerminalClosed = this.onTerminalClosedEmitter.event; private activatedTerminals = new Map(); - private activatingTerminals = new Map>(); - private deactivatingTerminals = new Map>(); + private activatingTerminals = new Map>(); + private deactivatingTerminals = new Map>(); constructor() { this.disposables.push( @@ -85,7 +92,11 @@ export class TerminalActivationImpl implements TerminalActivationInternal { return this.activatedTerminals.get(terminal); } - async activate(terminal: Terminal, environment: PythonEnvironment): Promise { + async activate( + terminal: Terminal, + environment: PythonEnvironment, + trigger: ActivationTrigger = 'unknown', + ): Promise { if (shouldSkipTerminalActivation(terminal)) { traceVerbose('Skipping activation for this terminal'); return; @@ -98,12 +109,14 @@ export class TerminalActivationImpl implements TerminalActivationInternal { if (this.deactivatingTerminals.has(terminal)) { traceVerbose('Terminal is being deactivated, cannot activate.'); - return this.deactivatingTerminals.get(terminal); + await this.deactivatingTerminals.get(terminal); + return; } if (this.activatingTerminals.has(terminal)) { traceVerbose('Terminal is being activated, skipping.'); - return this.activatingTerminals.get(terminal); + await this.activatingTerminals.get(terminal); + return; } const terminalEnv = this.activatedTerminals.get(terminal); @@ -115,25 +128,28 @@ export class TerminalActivationImpl implements TerminalActivationInternal { traceInfo( `Terminal is activated with a different environment, deactivating: ${terminalEnv.environmentPath.fsPath}`, ); - await this.deactivate(terminal); + await this.deactivate(terminal, 'environmentSwitch'); } } try { - const promise = this.activateInternal(terminal, environment); + const promise = this.runCommand(terminal, environment, 'activate', trigger); traceVerbose(`Activating terminal: ${environment.environmentPath.fsPath}`); this.activatingTerminals.set(terminal, promise); - await promise; + const outcome = await promise; this.activatingTerminals.delete(terminal); - this.updateActivationState(terminal, environment, true); - traceInfo(`Terminal is activated: ${environment.environmentPath.fsPath}`); + if (outcome === 'succeeded' || outcome === 'unverified') { + // sendText has no completion signal; preserve its existing optimistic UI behavior. + this.updateActivationState(terminal, environment, true); + traceInfo(`Terminal activation sent: ${environment.environmentPath.fsPath} (${outcome})`); + } } catch (ex) { this.activatingTerminals.delete(terminal); traceError('Failed to activate environment:\r\n', ex); } } - async deactivate(terminal: Terminal): Promise { + async deactivate(terminal: Terminal, trigger: ActivationTrigger = 'unknown'): Promise { if (isTaskTerminal(terminal)) { traceVerbose('Cannot deactivate environment in a task terminal'); return; @@ -141,24 +157,28 @@ export class TerminalActivationImpl implements TerminalActivationInternal { if (this.activatingTerminals.has(terminal)) { traceVerbose('Terminal is being activated, cannot deactivate.'); - return this.activatingTerminals.get(terminal); + await this.activatingTerminals.get(terminal); + return; } if (this.deactivatingTerminals.has(terminal)) { traceVerbose('Terminal is being deactivated, skipping.'); - return this.deactivatingTerminals.get(terminal); + await this.deactivatingTerminals.get(terminal); + return; } const terminalEnv = this.activatedTerminals.get(terminal); if (terminalEnv) { try { - const promise = this.deactivateInternal(terminal, terminalEnv); + const promise = this.runCommand(terminal, terminalEnv, 'deactivate', trigger); traceVerbose(`Deactivating terminal: ${terminalEnv.environmentPath.fsPath}`); this.deactivatingTerminals.set(terminal, promise); - await promise; + const outcome = await promise; this.deactivatingTerminals.delete(terminal); - this.updateActivationState(terminal, terminalEnv, false); - traceInfo(`Terminal is deactivated: ${terminalEnv.environmentPath.fsPath}`); + if (outcome === 'succeeded' || outcome === 'unverified') { + this.updateActivationState(terminal, terminalEnv, false); + traceInfo(`Terminal deactivation sent: ${terminalEnv.environmentPath.fsPath} (${outcome})`); + } } catch (ex) { this.deactivatingTerminals.delete(terminal); traceError('Failed to deactivate environment:\r\n', ex); @@ -183,93 +203,62 @@ export class TerminalActivationImpl implements TerminalActivationInternal { this.disposables.forEach((d) => d.dispose()); } - private async activateInternal(terminal: Terminal, environment: PythonEnvironment): Promise { - if (terminal.shellIntegration) { - await this.activateUsingShellIntegration(terminal.shellIntegration, terminal, environment); - } else { - this.activateLegacy(terminal, environment); - } - } - - private async deactivateInternal(terminal: Terminal, environment: PythonEnvironment): Promise { - if (terminal.shellIntegration) { - await this.deactivateUsingShellIntegration(terminal.shellIntegration, terminal, environment); - } else { - this.deactivateLegacy(terminal, environment); - } - } - - private activateLegacy(terminal: Terminal, environment: PythonEnvironment) { - const activationCommands = getActivationCommand(terminal, environment); - if (activationCommands) { - terminal.sendText(activationCommands); - this.activatedTerminals.set(terminal, environment); - } - } - - private deactivateLegacy(terminal: Terminal, environment: PythonEnvironment) { - const deactivationCommands = getDeactivationCommand(terminal, environment); - if (deactivationCommands) { - terminal.sendText(deactivationCommands); - this.activatedTerminals.delete(terminal); - } - } - - private async activateUsingShellIntegration( - shellIntegration: TerminalShellIntegration, + private async runCommand( terminal: Terminal, environment: PythonEnvironment, - ): Promise { - const activationCommand = getActivationCommand(terminal, environment); - if (activationCommand) { - try { - await this.executeTerminalShellCommandInternal(shellIntegration, activationCommand); - this.activatedTerminals.set(terminal, environment); - } catch { - traceError('Failed to activate environment using shell integration'); + operation: 'activate' | 'deactivate', + trigger: ActivationTrigger, + ): Promise { + const watch = new StopWatch(); + const method = terminal.shellIntegration ? 'shellIntegration' : 'sendText'; + let outcome: CommandOutcome = 'failed'; + try { + const command = + operation === 'activate' + ? getActivationCommand(terminal, environment) + : getDeactivationCommand(terminal, environment); + if (!command) { + outcome = 'noCommand'; + } else if (terminal.shellIntegration) { + outcome = await this.executeTerminalShellCommandInternal(terminal.shellIntegration, command); + } else { + terminal.sendText(command); + outcome = 'unverified'; } - } else { - traceVerbose('No activation commands found for terminal.'); + } catch (error) { + traceError(`Failed to ${operation} terminal environment`, error); } - } - - private async deactivateUsingShellIntegration( - shellIntegration: TerminalShellIntegration, - terminal: Terminal, - environment: PythonEnvironment, - ): Promise { - const deactivationCommand = getDeactivationCommand(terminal, environment); - if (deactivationCommand) { - try { - await this.executeTerminalShellCommandInternal(shellIntegration, deactivationCommand); - this.activatedTerminals.delete(terminal); - } catch { - traceError('Failed to deactivate environment using shell integration'); - } - } else { - traceVerbose('No deactivation commands found for terminal.'); + if (outcome !== 'succeeded' && outcome !== 'unverified') { + traceError(`Terminal ${operation} outcome: ${outcome}`); } + sendTelemetryEvent(EventNames.TERMINAL_ACTIVATION_OUTCOME, watch.elapsedTime, { + operation, + outcome, + method, + shell: identifyTerminalShell(terminal), + trigger, + }); + return outcome; } private async executeTerminalShellCommandInternal( shellIntegration: TerminalShellIntegration, command: string, - ): Promise { + ): Promise { const execution = shellIntegration.executeCommand(command); const disposables: Disposable[] = []; const timeoutMs = getShellIntegrationTimeout(); - const promise = new Promise((resolve) => { + const promise = new Promise((resolve) => { const timer = setTimeout(() => { - traceError(`Shell execution timed out: ${command}`); - resolve(); + resolve('timedOut'); }, timeoutMs); disposables.push( new Disposable(() => clearTimeout(timer)), this.onTerminalShellExecutionEnd((e: TerminalShellExecutionEndEvent) => { if (e.execution === execution) { - resolve(); + resolve(e.exitCode === 0 ? 'succeeded' : e.exitCode === undefined ? 'unknown' : 'failed'); } }), this.onTerminalShellExecutionStart((e: TerminalShellExecutionStartEvent) => { @@ -281,11 +270,7 @@ export class TerminalActivationImpl implements TerminalActivationInternal { }); try { - await promise; - return true; - } catch { - traceError(`Failed to execute shell command: ${command}`); - return false; + return await promise; } finally { disposables.forEach((d) => d.dispose()); } diff --git a/src/features/terminal/terminalManager.ts b/src/features/terminal/terminalManager.ts index 6564309e8..147acd401 100644 --- a/src/features/terminal/terminalManager.ts +++ b/src/features/terminal/terminalManager.ts @@ -251,7 +251,7 @@ export class TerminalManagerImpl implements TerminalManager { }, async () => { await waitForShellIntegration(terminal); - await this.activate(terminal, environment); + await this.ta.activate(terminal, environment, 'terminalOpen'); }, ); } else { @@ -402,7 +402,7 @@ export class TerminalManagerImpl implements TerminalManager { const env = this.ta.getEnvironment(t) ?? (await getEnvironmentForTerminal(api, t)); if (env && isActivatableEnvironment(env)) { - await this.activate(t, env); + await this.ta.activate(t, env, 'preExisting'); } } @@ -456,11 +456,11 @@ export class TerminalManagerImpl implements TerminalManager { } public activate(terminal: Terminal, environment: PythonEnvironment): Promise { - return this.ta.activate(terminal, environment); + return this.ta.activate(terminal, environment, 'explicit'); } public deactivate(terminal: Terminal): Promise { - return this.ta.deactivate(terminal); + return this.ta.deactivate(terminal, 'explicit'); } isActivated(terminal: Terminal, environment?: PythonEnvironment): boolean { diff --git a/src/test/features/terminal/terminalActivationState.unit.test.ts b/src/test/features/terminal/terminalActivationState.unit.test.ts new file mode 100644 index 000000000..f989ac9fb --- /dev/null +++ b/src/test/features/terminal/terminalActivationState.unit.test.ts @@ -0,0 +1,200 @@ +import * as assert from 'assert'; +import * as sinon from 'sinon'; +import { + EventEmitter, + Terminal, + TerminalShellExecution, + TerminalShellExecutionEndEvent, + TerminalShellExecutionStartEvent, + TerminalShellIntegration, + Uri, +} from 'vscode'; +import { PythonEnvironment } from '../../../api'; +import { EventNames } from '../../../common/telemetry/constants'; +import * as telemetry from '../../../common/telemetry/sender'; +import * as windowApis from '../../../common/window.apis'; +import * as activationCommands from '../../../features/common/activation'; +import * as shellDetector from '../../../features/common/shellDetector'; +import { TerminalActivationImpl } from '../../../features/terminal/terminalActivationState'; +import * as terminalUtils from '../../../features/terminal/utils'; + +suite('TerminalActivation - command outcomes', () => { + let activation: TerminalActivationImpl; + let ends: EventEmitter; + let starts: EventEmitter; + let clock: sinon.SinonFakeTimers; + let sendTelemetry: sinon.SinonStub; + let executeCommand: sinon.SinonStub; + let sendText: sinon.SinonStub; + let terminal: Terminal; + const execution = {} as TerminalShellExecution; + const environment: PythonEnvironment = { + envId: { id: 'test-env', managerId: 'test-manager' }, + name: 'Test', + displayName: 'Test', + displayPath: 'Test', + version: '3.12', + environmentPath: Uri.file('test-env'), + sysPrefix: Uri.file('test-env').fsPath, + execInfo: { run: { executable: 'python' } }, + }; + + setup(() => { + clock = sinon.useFakeTimers(); + ends = new EventEmitter(); + starts = new EventEmitter(); + sinon.stub(windowApis, 'onDidEndTerminalShellExecution').callsFake((listener) => ends.event(listener)); + sinon.stub(windowApis, 'onDidStartTerminalShellExecution').callsFake((listener) => starts.event(listener)); + sinon.stub(windowApis, 'onDidCloseTerminal').returns({ dispose() {} }); + sinon.stub(terminalUtils, 'shouldSkipTerminalActivation').returns(false); + sinon.stub(terminalUtils, 'isTaskTerminal').returns(false); + sinon.stub(terminalUtils, 'getShellIntegrationTimeout').returns(500); + sinon.stub(shellDetector, 'identifyTerminalShell').returns('bash'); + sinon.stub(activationCommands, 'getActivationCommand').returns('activate'); + sinon.stub(activationCommands, 'getDeactivationCommand').returns('deactivate'); + sendTelemetry = sinon.stub(telemetry, 'sendTelemetryEvent'); + executeCommand = sinon.stub().returns(execution); + sendText = sinon.stub(); + terminal = { + shellIntegration: { executeCommand } as unknown as TerminalShellIntegration, + sendText, + } as unknown as Terminal; + activation = new TerminalActivationImpl(); + }); + + teardown(() => { + activation.dispose(); + ends.dispose(); + starts.dispose(); + clock.restore(); + sinon.restore(); + }); + + function finish(exitCode?: number): void { + ends.fire({ terminal, shellIntegration: terminal.shellIntegration!, execution, exitCode }); + } + + function expectOutcome(operation: 'activate' | 'deactivate', outcome: string, method = 'shellIntegration'): void { + const event = sendTelemetry.getCalls().find((call) => call.args[2]?.operation === operation); + assert.ok(event, `Expected ${operation} telemetry`); + assert.strictEqual(event.args[0], EventNames.TERMINAL_ACTIVATION_OUTCOME); + assert.strictEqual(event.args[2].outcome, outcome); + assert.strictEqual(event.args[2].method, method); + assert.strictEqual(event.args[2].shell, 'bash'); + assert.strictEqual(typeof event.args[1], 'number'); + assert.deepStrictEqual(Object.keys(event.args[2]).sort(), ['method', 'operation', 'outcome', 'shell', 'trigger']); + } + + test('marks activation only after exit code zero', async () => { + const pending = activation.activate(terminal, environment, 'terminalOpen'); + assert.strictEqual(activation.isActivated(terminal), false); + finish(0); + await pending; + assert.strictEqual(activation.isActivated(terminal), true); + expectOutcome('activate', 'succeeded'); + assert.strictEqual(sendTelemetry.firstCall.args[2].trigger, 'terminalOpen'); + }); + + test('nonzero exit code does not mark activation', async () => { + const pending = activation.activate(terminal, environment); + finish(1); + await pending; + assert.strictEqual(activation.isActivated(terminal), false); + expectOutcome('activate', 'failed'); + }); + + test('missing exit code is unknown rather than success', async () => { + const pending = activation.activate(terminal, environment); + finish(); + await pending; + assert.strictEqual(activation.isActivated(terminal), false); + expectOutcome('activate', 'unknown'); + }); + + test('timeout is unconfirmed, and a late completion cannot update state', async () => { + const pending = activation.activate(terminal, environment); + await clock.tickAsync(500); + await pending; + assert.strictEqual(activation.isActivated(terminal), false); + expectOutcome('activate', 'timedOut'); + assert.strictEqual(sendTelemetry.firstCall.args[1], 500); + finish(0); + assert.strictEqual(activation.isActivated(terminal), false); + assert.strictEqual(sendTelemetry.callCount, 1); + }); + + test('executeCommand throwing reports failure without changing state', async () => { + executeCommand.throws(new Error('execution failed')); + await activation.activate(terminal, environment); + assert.strictEqual(activation.isActivated(terminal), false); + expectOutcome('activate', 'failed'); + }); + + test('failed deactivation preserves state', async () => { + const initial = activation.activate(terminal, environment); + finish(0); + await initial; + sendTelemetry.resetHistory(); + + const pending = activation.deactivate(terminal); + finish(1); + await pending; + assert.strictEqual(activation.getEnvironment(terminal), environment); + expectOutcome('deactivate', 'failed'); + }); + + test('timed-out deactivation keeps the last confirmed environment', async () => { + const initial = activation.activate(terminal, environment); + finish(0); + await initial; + sendTelemetry.resetHistory(); + + const pending = activation.deactivate(terminal); + await clock.tickAsync(500); + await pending; + assert.strictEqual(activation.getEnvironment(terminal), environment); + expectOutcome('deactivate', 'timedOut'); + }); + + test('a stale deactivation failure does not permanently block replacement activation', async () => { + const initial = activation.activate(terminal, environment); + finish(0); + await initial; + sendTelemetry.resetHistory(); + const replacement: PythonEnvironment = { + ...environment, + envId: { id: 'replacement', managerId: environment.envId.managerId }, + }; + const activationStarted = new Promise((resolve) => { + executeCommand.onThirdCall().callsFake(() => { + resolve(); + return execution; + }); + }); + const pending = activation.activate(terminal, replacement); + finish(1); + assert.strictEqual(activation.getEnvironment(terminal), environment); + await activationStarted; + finish(0); + await pending; + assert.strictEqual(activation.getEnvironment(terminal), replacement); + assert.strictEqual(executeCommand.callCount, 3); + expectOutcome('deactivate', 'failed'); + expectOutcome('activate', 'succeeded'); + }); + + test('sendText remains optimistic but is reported as unverified', async () => { + terminal = { sendText } as unknown as Terminal; + await activation.activate(terminal, environment); + assert.strictEqual(activation.isActivated(terminal), true); + sinon.assert.calledOnceWithExactly(sendText, 'activate'); + expectOutcome('activate', 'unverified', 'sendText'); + }); + + test('missing activation command does not change state', async () => { + (activationCommands.getActivationCommand as sinon.SinonStub).returns(undefined); + await activation.activate(terminal, environment); + assert.strictEqual(activation.isActivated(terminal), false); + expectOutcome('activate', 'noCommand'); + }); +});