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