From 9fe4ecad09cad4a68271aeffd4e1ceedfb443947 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Tue, 12 May 2026 14:43:00 +0000 Subject: [PATCH 1/9] feat(telemetry): instrument auth and workspace state --- CHANGELOG.md | 4 +- src/api/authInterceptor.ts | 20 +++ src/core/container.ts | 1 + src/extension.ts | 2 + src/instrumentation/auth.ts | 49 +++++++ src/instrumentation/workspace.ts | 74 ++++++++++ src/login/loginCoordinator.ts | 128 ++++++++++-------- src/oauth/sessionManager.ts | 27 +++- src/remote/remote.ts | 9 +- src/remote/workspaceStateMachine.ts | 60 +++++++- src/workspace/workspaceMonitor.ts | 35 +++++ test/unit/api/authInterceptor.test.ts | 32 ++++- test/unit/login/loginCoordinator.test.ts | 30 +++- test/unit/oauth/sessionManager.test.ts | 66 ++++++++- .../unit/remote/workspaceStateMachine.test.ts | 90 +++++++++++- test/unit/workspace/workspaceMonitor.test.ts | 55 +++++++- 16 files changed, 608 insertions(+), 74 deletions(-) create mode 100644 src/instrumentation/auth.ts create mode 100644 src/instrumentation/workspace.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index ad5ef218b9..7edc62be09 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -23,10 +23,12 @@ local telemetry. - Local telemetry now records `http.requests` rollups for per-route HTTP health without emitting one event per request. -- Connection lifecycle now records local telemetry: SSH process +- Local telemetry now records connection lifecycle: SSH process discovery/loss/recovery with sampled network info, and reconnecting WebSocket open, drop, reconnect, and state transitions, so connection stability is captured alongside other local telemetry. +- Local telemetry now records authentication refresh/recovery prompts plus + workspace and agent state transitions for connection lifecycle diagnostics. ### Fixed diff --git a/src/api/authInterceptor.ts b/src/api/authInterceptor.ts index d362c1d12e..f28c659647 100644 --- a/src/api/authInterceptor.ts +++ b/src/api/authInterceptor.ts @@ -1,6 +1,11 @@ import { type AxiosError, isAxiosError } from "axios"; +import { AuthTelemetry } from "../instrumentation/auth"; import { OAuthError } from "../oauth/errors"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; import { toSafeHost } from "../util"; import type * as vscode from "vscode"; @@ -28,6 +33,7 @@ export type AuthRequiredHandler = (hostname: string) => Promise; */ export class AuthInterceptor implements vscode.Disposable { private readonly interceptorId: number; + private readonly authTelemetry: AuthTelemetry; private authRequiredPromise: Promise | null = null; constructor( @@ -36,7 +42,9 @@ export class AuthInterceptor implements vscode.Disposable { private readonly oauthSessionManager: OAuthSessionManager, private readonly secretsManager: SecretsManager, private readonly onAuthRequired?: AuthRequiredHandler, + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) { + this.authTelemetry = new AuthTelemetry(telemetry); this.interceptorId = this.client .getAxiosInstance() .interceptors.response.use( @@ -54,6 +62,9 @@ export class AuthInterceptor implements vscode.Disposable { if (error.config) { const config = error.config as { _retryAttempted?: boolean }; if (config._retryAttempted) { + if (error.response?.status === 401) { + this.authTelemetry.intercept401("none"); + } throw error; } } @@ -64,6 +75,7 @@ export class AuthInterceptor implements vscode.Disposable { const baseUrl = this.client.getHost(); if (!baseUrl) { + this.authTelemetry.intercept401("none"); throw error; } const hostname = toSafeHost(baseUrl); @@ -77,11 +89,14 @@ export class AuthInterceptor implements vscode.Disposable { ): Promise { this.logger.debug("Received 401 response, attempting recovery"); + let loggedRecovery = false; + if (await this.oauthSessionManager.isLoggedInWithOAuth(hostname)) { try { const newTokens = await this.oauthSessionManager.refreshToken(); this.client.setSessionToken(newTokens.access_token); this.logger.debug("Token refresh successful, retrying request"); + this.authTelemetry.intercept401("refresh_success"); return this.retryRequest(error, newTokens.access_token); } catch (refreshError) { if (refreshError instanceof OAuthError) { @@ -98,6 +113,8 @@ export class AuthInterceptor implements vscode.Disposable { } if (this.onAuthRequired) { + this.authTelemetry.intercept401("login_required"); + loggedRecovery = true; const success = await this.executeAuthRequired(hostname); if (success) { const auth = await this.secretsManager.getSessionAuth(hostname); @@ -108,6 +125,9 @@ export class AuthInterceptor implements vscode.Disposable { } } + if (!loggedRecovery) { + this.authTelemetry.intercept401("none"); + } throw error; } diff --git a/src/core/container.ts b/src/core/container.ts index 042eb81f24..9a0f5a27a2 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -105,6 +105,7 @@ export class ServiceContainer implements vscode.Disposable { this.cliCredentialManager, this.oauthCallback, context.extension.id, + this.telemetryService, ); this.duplicateWorkspaceIpc = new DuplicateWorkspaceIpc( context.secrets, diff --git a/src/extension.ts b/src/extension.ts index 3067014c2c..ba79017314 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -128,6 +128,7 @@ async function doActivate( deployment, serviceContainer, handleAuthFailure, + telemetryService, ); ctx.subscriptions.push(oauthSessionManager); @@ -152,6 +153,7 @@ async function doActivate( await handleAuthFailure(); return false; }, + telemetryService, ); ctx.subscriptions.push(authInterceptor); diff --git a/src/instrumentation/auth.ts b/src/instrumentation/auth.ts new file mode 100644 index 0000000000..6d033d2b50 --- /dev/null +++ b/src/instrumentation/auth.ts @@ -0,0 +1,49 @@ +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; + +export type AuthTokenRefreshTrigger = "background" | "reactive"; +export type AuthIntercept401Recovery = + | "refresh_success" + | "login_required" + | "none"; +export type AuthLoginPromptTrigger = "auth_required" | "missing_session"; + +interface LoginPromptResult { + readonly success: boolean; +} + +export class AuthTelemetry { + public constructor( + private readonly telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, + ) {} + + public traceTokenRefresh( + trigger: AuthTokenRefreshTrigger, + fn: () => Promise, + ): Promise { + return this.telemetry.trace("auth.token_refresh", fn, { trigger }); + } + + public intercept401(recovery: AuthIntercept401Recovery): void { + this.telemetry.log("auth.intercept_401", { recovery }); + } + + public traceLoginPrompt( + trigger: AuthLoginPromptTrigger, + fn: () => Promise, + ): Promise { + return this.telemetry.trace( + "auth.login_prompt", + async (span) => { + const result = await fn(); + if (!result.success) { + span.markAborted(); + } + return result; + }, + { trigger }, + ); + } +} diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts new file mode 100644 index 0000000000..bfee871140 --- /dev/null +++ b/src/instrumentation/workspace.ts @@ -0,0 +1,74 @@ +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; + +import type { + BuildReason, + WorkspaceAgentLifecycle, + WorkspaceAgentStatus, + WorkspaceStatus, + WorkspaceTransition, +} from "coder/site/src/api/typesGenerated"; + +export const INITIAL_STATE = "unknown"; + +type InitialState = typeof INITIAL_STATE; + +interface WorkspaceStateTransition { + readonly from: WorkspaceStatus | InitialState; + readonly to: WorkspaceStatus; + readonly transition?: WorkspaceTransition; + readonly reason?: BuildReason; + readonly observedDurationMs?: number; +} + +interface WorkspaceAgentStateTransition { + readonly agentName: string; + readonly fromStatus: WorkspaceAgentStatus | InitialState; + readonly toStatus: WorkspaceAgentStatus; + readonly fromLifecycleState: WorkspaceAgentLifecycle | InitialState; + readonly toLifecycleState: WorkspaceAgentLifecycle; + readonly observedDurationMs?: number; +} + +export class WorkspaceTelemetry { + public constructor( + private readonly telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, + ) {} + + public workspaceStateTransition(transition: WorkspaceStateTransition): void { + this.telemetry.log( + "workspace.state_transitioned", + { + from: transition.from, + to: transition.to, + ...(transition.transition && { transition: transition.transition }), + ...(transition.reason && { reason: transition.reason }), + }, + transition.observedDurationMs === undefined + ? {} + : { observedDurationMs: transition.observedDurationMs }, + ); + } + + public agentStateTransition(transition: WorkspaceAgentStateTransition): void { + this.telemetry.log( + "workspace.agent.state_transitioned", + { + agentName: transition.agentName, + fromStatus: transition.fromStatus, + toStatus: transition.toStatus, + fromLifecycleState: transition.fromLifecycleState, + toLifecycleState: transition.toLifecycleState, + }, + transition.observedDurationMs === undefined + ? {} + : { observedDurationMs: transition.observedDurationMs }, + ); + } + + public traceUpdateTriggered(fn: () => Promise): Promise { + return this.telemetry.trace("workspace.update.triggered", () => fn()); + } +} diff --git a/src/login/loginCoordinator.ts b/src/login/loginCoordinator.ts index 018d9558ee..c457b6670f 100644 --- a/src/login/loginCoordinator.ts +++ b/src/login/loginCoordinator.ts @@ -5,11 +5,19 @@ import * as vscode from "vscode"; import { CoderApi } from "../api/coderApi"; import { needToken } from "../api/utils"; import { CertificateError } from "../error/certificateError"; +import { + AuthTelemetry, + type AuthLoginPromptTrigger, +} from "../instrumentation/auth"; import { OAuthAuthorizer } from "../oauth/authorizer"; import { buildOAuthTokenData } from "../oauth/utils"; import { withOptionalProgress } from "../progress"; import { maybeAskAuthMethod, maybeAskUrl } from "../promptUtils"; import { isKeyringEnabled } from "../settings/cli"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; import { vscodeProposed } from "../vscodeProposed"; import type { User } from "coder/site/src/api/typesGenerated"; @@ -38,6 +46,7 @@ export interface LoginOptions { export class LoginCoordinator implements vscode.Disposable { private loginQueue: Promise = Promise.resolve(); private readonly oauthAuthorizer: OAuthAuthorizer; + private readonly authTelemetry: AuthTelemetry; constructor( private readonly secretsManager: SecretsManager, @@ -46,7 +55,9 @@ export class LoginCoordinator implements vscode.Disposable { private readonly cliCredentialManager: CliCredentialManager, oauthCallback: OAuthCallback, extensionId: string, + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) { + this.authTelemetry = new AuthTelemetry(telemetry); this.oauthAuthorizer = new OAuthAuthorizer( secretsManager, oauthCallback, @@ -80,63 +91,72 @@ export class LoginCoordinator implements vscode.Disposable { * Shows dialog then login - for system-initiated auth (remote, OAuth refresh). */ public async ensureLoggedInWithDialog( - options: LoginOptions & { message?: string; detailPrefix?: string }, + options: LoginOptions & { + message?: string; + detailPrefix?: string; + trigger?: AuthLoginPromptTrigger; + }, ): Promise { const { safeHostname, url, detailPrefix, message } = options; - return this.executeWithGuard(async () => { - // Show dialog promise - const dialogPromise = vscodeProposed.window - .showErrorMessage( - message || "Authentication Required", - { - modal: true, - useCustom: true, - detail: - (detailPrefix || `Authentication needed for ${safeHostname}.`) + - "\n\nIf you've already logged in, you may close this dialog.", - }, - "Login", - ) - .then(async (action) => { - if (action === "Login") { - // Proceed with the login flow, handling logging in from another window - const storedAuth = - await this.secretsManager.getSessionAuth(safeHostname); - const newUrl = await maybeAskUrl( - this.mementoManager, - url, - storedAuth?.url, - ); - if (!newUrl) { - throw new Error("URL must be provided"); - } - - const result = await this.attemptLogin( - { url: newUrl, safeHostname }, - false, - options.token, - ); - - await this.persistSessionAuth(result, safeHostname, newUrl); - - return result; - } else { - // User cancelled - return { success: false } as const; + return this.authTelemetry.traceLoginPrompt( + options.trigger ?? "auth_required", + () => + this.executeWithGuard(async () => { + // Show dialog promise + const dialogPromise = vscodeProposed.window + .showErrorMessage( + message || "Authentication Required", + { + modal: true, + useCustom: true, + detail: + (detailPrefix || + `Authentication needed for ${safeHostname}.`) + + "\n\nIf you've already logged in, you may close this dialog.", + }, + "Login", + ) + .then(async (action) => { + if (action === "Login") { + // Proceed with the login flow, handling logging in from another window + const storedAuth = + await this.secretsManager.getSessionAuth(safeHostname); + const newUrl = await maybeAskUrl( + this.mementoManager, + url, + storedAuth?.url, + ); + if (!newUrl) { + throw new Error("URL must be provided"); + } + + const result = await this.attemptLogin( + { url: newUrl, safeHostname }, + false, + options.token, + ); + + await this.persistSessionAuth(result, safeHostname, newUrl); + + return result; + } else { + // User cancelled + return { success: false } as const; + } + }); + + // Race between user clicking login and cross-window detection + const { + promise: crossWindowPromise, + dispose: disposeCrossWindowListener, + } = this.waitForCrossWindowLogin(safeHostname); + try { + return await Promise.race([dialogPromise, crossWindowPromise]); + } finally { + disposeCrossWindowListener(); } - }); - - // Race between user clicking login and cross-window detection - const { - promise: crossWindowPromise, - dispose: disposeCrossWindowListener, - } = this.waitForCrossWindowLogin(safeHostname); - try { - return await Promise.race([dialogPromise, crossWindowPromise]); - } finally { - disposeCrossWindowListener(); - } - }); + }), + ); } private async persistSessionAuth( diff --git a/src/oauth/sessionManager.ts b/src/oauth/sessionManager.ts index 32ab7e7810..3360d79fc7 100644 --- a/src/oauth/sessionManager.ts +++ b/src/oauth/sessionManager.ts @@ -1,4 +1,12 @@ import { CoderApi } from "../api/coderApi"; +import { + AuthTelemetry, + type AuthTokenRefreshTrigger, +} from "../instrumentation/auth"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; import { DEFAULT_OAUTH_SCOPES, REFRESH_GRANT_TYPE } from "./constants"; import { OAuthError, parseOAuthError } from "./errors"; @@ -58,24 +66,31 @@ export class OAuthSessionManager implements vscode.Disposable { deployment: Deployment | null, container: ServiceContainer, onAuthRequired: () => Promise = () => Promise.resolve(), + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ): OAuthSessionManager { const manager = new OAuthSessionManager( deployment, container.getSecretsManager(), container.getLogger(), onAuthRequired, + telemetry, ); manager.setupTokenListener(); manager.scheduleNextRefresh(); return manager; } + private readonly authTelemetry: AuthTelemetry; + private constructor( private deployment: Deployment | null, private readonly secretsManager: SecretsManager, private readonly logger: Logger, private readonly onAuthRequired: () => Promise, - ) {} + telemetry: TelemetryReporter, + ) { + this.authTelemetry = new AuthTelemetry(telemetry); + } /** * Get current deployment, throwing if not set. @@ -218,7 +233,7 @@ export class OAuthSessionManager implements vscode.Disposable { this.refreshTimer = undefined; - this.refreshToken() + this.refreshToken("background") .then(() => { this.logger.debug("Background token refresh succeeded"); }) @@ -342,7 +357,9 @@ export class OAuthSessionManager implements vscode.Disposable { * Refresh the access token using the stored refresh token. * Uses a shared promise to handle concurrent refresh attempts. */ - public async refreshToken(): Promise { + public async refreshToken( + trigger: AuthTokenRefreshTrigger = "reactive", + ): Promise { if (this.refreshPromise) { this.logger.debug( "Token refresh already in progress, waiting for result", @@ -352,7 +369,9 @@ export class OAuthSessionManager implements vscode.Disposable { const deployment = this.requireDeployment(); // Assign synchronously before any async work to prevent race conditions - this.refreshPromise = this.executeTokenRefresh(deployment); + this.refreshPromise = this.authTelemetry.traceTokenRefresh(trigger, () => + this.executeTokenRefresh(deployment), + ); return this.refreshPromise; } diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 045ba8de8c..59184d8f83 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -195,12 +195,14 @@ export class Remote { try { // Create OAuth session manager for this remote deployment + const telemetry = this.serviceContainer.getTelemetryService(); const remoteOAuthManager = OAuthSessionManager.create( { url: baseUrl, safeHostname: parts.safeHostname }, this.serviceContainer, async () => { await this.showSessionExpiredDialog(context); }, + telemetry, ); disposables.push(remoteOAuthManager); @@ -216,7 +218,7 @@ export class Remote { baseUrl, token, this.logger, - this.serviceContainer.getTelemetryService(), + telemetry, ); disposables.push(workspaceClient); @@ -230,6 +232,7 @@ export class Remote { const result = await this.showSessionExpiredDialog(context); return result.success; }, + telemetry, ); disposables.push(authInterceptor); @@ -315,6 +318,7 @@ export class Remote { workspaceClient, this.logger, this.contextManager, + telemetry, ); disposables.push( monitor, @@ -334,6 +338,7 @@ export class Remote { featureSet, this.logger, cliAuth, + telemetry, ); disposables.push(stateMachine); @@ -642,6 +647,7 @@ export class Remote { url: context.baseUrl, message: "Your session expired...", detailPrefix: `You must log in to access ${context.workspaceName}.`, + trigger: "auth_required", }); } @@ -655,6 +661,7 @@ export class Remote { url, message, detailPrefix: `You must log in to access ${context.workspaceName}.`, + trigger: "missing_session", }); // Dispose before retrying since setup will create new disposables. diff --git a/src/remote/workspaceStateMachine.ts b/src/remote/workspaceStateMachine.ts index 0b9a299b30..4a6acefdea 100644 --- a/src/remote/workspaceStateMachine.ts +++ b/src/remote/workspaceStateMachine.ts @@ -13,7 +13,12 @@ import { streamAgentLogs, streamBuildLogs, } from "../api/workspace"; +import { WorkspaceTelemetry } from "../instrumentation/workspace"; import { maybeAskAgent } from "../promptUtils"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; import { vscodeProposed } from "../vscodeProposed"; import { TerminalOutputChannel } from "./terminalOutputChannel"; @@ -21,7 +26,10 @@ import { TerminalOutputChannel } from "./terminalOutputChannel"; import type { ProvisionerJobLog, Workspace, + WorkspaceAgent, + WorkspaceAgentLifecycle, WorkspaceAgentLog, + WorkspaceAgentStatus, } from "coder/site/src/api/typesGenerated"; import type { CoderApi } from "../api/coderApi"; @@ -35,13 +43,21 @@ import type { AuthorityParts } from "../util"; * Manages workspace and agent state transitions until ready for SSH connection. * Streams build and agent logs, and handles socket lifecycle. */ +interface ObservedAgentState { + readonly status: WorkspaceAgentStatus; + readonly lifecycleState: WorkspaceAgentLifecycle; + readonly observedAtMs: number; +} + export class WorkspaceStateMachine implements vscode.Disposable { private readonly terminal: TerminalOutputChannel; private readonly buildLogStream = new LazyStream(); private readonly agentLogStream = new LazyStream(); + private readonly telemetry: WorkspaceTelemetry; private agent: { id: string; name: string } | undefined; private workspace: Workspace | undefined; + private observedAgentState: ObservedAgentState | undefined; constructor( private readonly parts: AuthorityParts, @@ -51,8 +67,10 @@ export class WorkspaceStateMachine implements vscode.Disposable { private readonly featureSet: FeatureSet, private readonly logger: Logger, private readonly cliAuth: CliAuth, + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) { this.terminal = new TerminalOutputChannel("Coder: Workspace Build"); + this.telemetry = new WorkspaceTelemetry(telemetry); } /** @@ -77,7 +95,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { if (updated) { workspace = updated; // Agent IDs may have changed after an update. - this.agent = undefined; + this.resetAgent(); if (workspace.latest_build.status !== "running") return false; } break; @@ -106,7 +124,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { if (updated) { workspace = updated; // Agent IDs may have changed after an update. - this.agent = undefined; + this.resetAgent(); if (workspace.latest_build.status !== "running") return false; break; } @@ -119,7 +137,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { case "starting": case "stopping": { // Clear the agent since its ID could change after a restart - this.agent = undefined; + this.resetAgent(); this.agentLogStream.close(); progress.report({ message: `building ${workspaceName} (${workspace.latest_build.status})...`, @@ -164,6 +182,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { `Agent ${this.agent.name} not found in ${workspaceName} resources`, ); } + this.recordAgentState(agent); switch (agent.status) { case "connecting": @@ -286,7 +305,10 @@ export class WorkspaceStateMachine implements vscode.Disposable { status: workspace.latest_build.status, }); try { - this.workspace = await updateWorkspace(this.buildCliContext(workspace)); + this.workspace = await this.telemetry.traceUpdateTriggered(() => + updateWorkspace(this.buildCliContext(workspace)), + ); + this.logger.info(`${workspaceName} update initiated`); return this.workspace; } catch (error) { if (error instanceof WorkspaceUpdateCancelledError) { @@ -330,6 +352,36 @@ export class WorkspaceStateMachine implements vscode.Disposable { return this.workspace; } + private resetAgent(): void { + this.agent = undefined; + this.observedAgentState = undefined; + } + + private recordAgentState(agent: WorkspaceAgent): void { + const now = performance.now(); + const previous = this.observedAgentState; + if ( + previous?.status === agent.status && + previous.lifecycleState === agent.lifecycle_state + ) { + return; + } + + this.telemetry.agentStateTransition({ + agentName: agent.name, + fromStatus: previous?.status ?? "unknown", + toStatus: agent.status, + fromLifecycleState: previous?.lifecycleState ?? "unknown", + toLifecycleState: agent.lifecycle_state, + ...(previous && { observedDurationMs: now - previous.observedAtMs }), + }); + this.observedAgentState = { + status: agent.status, + lifecycleState: agent.lifecycle_state, + observedAtMs: now, + }; + } + dispose(): void { this.buildLogStream.close(); this.agentLogStream.close(); diff --git a/src/workspace/workspaceMonitor.ts b/src/workspace/workspaceMonitor.ts index 4fca7473ec..05a9793566 100644 --- a/src/workspace/workspaceMonitor.ts +++ b/src/workspace/workspaceMonitor.ts @@ -1,15 +1,21 @@ import { type ServerSentEvent, type Workspace, + type WorkspaceStatus, } from "coder/site/src/api/typesGenerated"; import { formatDistanceToNowStrict } from "date-fns"; import * as vscode from "vscode"; import { createWorkspaceIdentifier, errToStr } from "../api/api-helper"; +import { WorkspaceTelemetry } from "../instrumentation/workspace"; import { areNotificationsDisabled, areUpdateNotificationsDisabled, } from "../settings/notifications"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; import { vscodeProposed } from "../vscodeProposed"; import type { CoderApi } from "../api/coderApi"; @@ -42,16 +48,21 @@ export class WorkspaceMonitor implements vscode.Disposable { // For logging. private readonly name: string; + private readonly telemetry: WorkspaceTelemetry; private latestWorkspace: Workspace; + private lastWorkspaceStatus: WorkspaceStatus | undefined; + private lastWorkspaceStatusObservedAtMs: number | undefined; private constructor( workspace: Workspace, private readonly client: CoderApi, private readonly logger: Logger, private readonly contextManager: ContextManager, + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) { this.name = createWorkspaceIdentifier(workspace); + this.telemetry = new WorkspaceTelemetry(telemetry); this.latestWorkspace = workspace; const statusBarItem = vscode.window.createStatusBarItem( @@ -77,12 +88,14 @@ export class WorkspaceMonitor implements vscode.Disposable { client: CoderApi, logger: Logger, contextManager: ContextManager, + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ): Promise { const monitor = new WorkspaceMonitor( workspace, client, logger, contextManager, + telemetry, ); // Initialize websocket connection @@ -134,11 +147,33 @@ export class WorkspaceMonitor implements vscode.Disposable { } private update(workspace: Workspace) { + this.recordWorkspaceStatus(workspace); this.latestWorkspace = workspace; this.updateContext(workspace); this.updateStatusBar(workspace); } + private recordWorkspaceStatus(workspace: Workspace): void { + const status = workspace.latest_build.status; + const now = performance.now(); + const previous = this.lastWorkspaceStatus; + if (previous === status) { + return; + } + + this.telemetry.workspaceStateTransition({ + from: previous ?? "unknown", + to: status, + transition: workspace.latest_build.transition, + reason: workspace.latest_build.reason, + ...(this.lastWorkspaceStatusObservedAtMs !== undefined && { + observedDurationMs: now - this.lastWorkspaceStatusObservedAtMs, + }), + }); + this.lastWorkspaceStatus = status; + this.lastWorkspaceStatusObservedAtMs = now; + } + private maybeNotify(workspace: Workspace) { const cfg = vscode.workspace.getConfiguration(); if (areNotificationsDisabled(cfg)) { diff --git a/test/unit/api/authInterceptor.test.ts b/test/unit/api/authInterceptor.test.ts index e2b8ed3c71..9527b8fe82 100644 --- a/test/unit/api/authInterceptor.test.ts +++ b/test/unit/api/authInterceptor.test.ts @@ -7,11 +7,13 @@ import { } from "@/api/authInterceptor"; import { SecretsManager } from "@/core/secretsManager"; +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { createAxiosError, createMockLogger, InMemoryMemento, InMemorySecretStorage, + MockConfigurationProvider, MockOAuthSessionManager, } from "../../mocks/testHelpers"; import { @@ -22,6 +24,7 @@ import { import type { CoderApi } from "@/api/coderApi"; import type { OAuthSessionManager } from "@/oauth/sessionManager"; +import type { TelemetryReporter } from "@/telemetry/reporter"; /** * Creates a mock axios instance with controllable interceptors. @@ -84,6 +87,7 @@ const ONE_HOUR_MS = 60 * 60 * 1000; function createTestContext() { vi.resetAllMocks(); + new MockConfigurationProvider().set("coder.telemetry.level", "local"); const secretStorage = new InMemorySecretStorage(); const memento = new InMemoryMemento(); @@ -136,13 +140,17 @@ function createTestContext() { }; /** Creates interceptor with optional callback */ - const createInterceptor = (onAuthRequired?: AuthRequiredHandler) => + const createInterceptor = ( + onAuthRequired?: AuthRequiredHandler, + telemetry?: TelemetryReporter, + ) => new AuthInterceptor( mockCoderApi, logger, mockOAuthManager as unknown as OAuthSessionManager, secretsManager, onAuthRequired, + telemetry, ); return { @@ -182,7 +190,7 @@ describe("AuthInterceptor", () => { }); describe("401 handling with OAuth", () => { - it("refreshes token and retries request", async () => { + it("refreshes token, retries request, and emits telemetry", async () => { const { mockCoderApi, mockOAuthManager, @@ -190,6 +198,7 @@ describe("AuthInterceptor", () => { setupOAuthTokens, createInterceptor, } = createTestContext(); + const sink = new TestSink(); await setupOAuthTokens(); @@ -201,13 +210,19 @@ describe("AuthInterceptor", () => { const retryResponse = { data: "success", status: 200 }; vi.spyOn(axiosInstance, "request").mockResolvedValue(retryResponse); - createInterceptor(); + createInterceptor(undefined, createTestTelemetryService(sink)); const error = createAxiosError(401, "Unauthorized"); const result = await axiosInstance.triggerResponseError(error); expect(mockCoderApi.getSessionToken()).toBe("new-access-token"); expect(result).toEqual(retryResponse); + expect(sink.events).toContainEqual( + expect.objectContaining({ + eventName: "auth.intercept_401", + properties: { recovery: "refresh_success" }, + }), + ); }); it("does not retry if already retried", async () => { @@ -255,16 +270,23 @@ describe("AuthInterceptor", () => { }); describe("401 handling with callback (non-OAuth)", () => { - it("calls onAuthRequired callback on 401", async () => { + it("calls onAuthRequired callback on 401 and emits login-required recovery", async () => { const { axiosInstance, createInterceptor } = createTestContext(); + const sink = new TestSink(); const onAuthRequired = vi.fn().mockResolvedValue(false); - createInterceptor(onAuthRequired); + createInterceptor(onAuthRequired, createTestTelemetryService(sink)); const error = createAxiosError(401, "Unauthorized"); await expect(axiosInstance.triggerResponseError(error)).rejects.toThrow(); expect(onAuthRequired).toHaveBeenCalledWith(TEST_HOSTNAME); + expect(sink.events).toContainEqual( + expect.objectContaining({ + eventName: "auth.intercept_401", + properties: { recovery: "login_required" }, + }), + ); }); it("retries request when callback returns true", async () => { diff --git a/test/unit/login/loginCoordinator.test.ts b/test/unit/login/loginCoordinator.test.ts index cf376a9775..dc77cc6b4b 100644 --- a/test/unit/login/loginCoordinator.test.ts +++ b/test/unit/login/loginCoordinator.test.ts @@ -9,6 +9,7 @@ import { LoginCoordinator } from "@/login/loginCoordinator"; import { OAuthCallback } from "@/oauth/oauthCallback"; import { maybeAskAuthMethod } from "@/promptUtils"; +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { createAxiosError, createMockCliCredentialManager, @@ -21,6 +22,8 @@ import { MockUserInteraction, } from "../../mocks/testHelpers"; +import type { TelemetryReporter } from "@/telemetry/reporter"; + // Hoisted mock adapter implementation const mockAxiosAdapterImpl = vi.hoisted( () => (config: Record) => @@ -98,7 +101,7 @@ const TEST_HOSTNAME = "coder.example.com"; /** * Creates a fresh test context with all dependencies. */ -function createTestContext() { +function createTestContext(telemetry?: TelemetryReporter) { vi.resetAllMocks(); const mockAdapter = (axios as MockedAxios).__mockAdapter; @@ -127,6 +130,7 @@ function createTestContext() { mockCredentialManager, oauthCallback, "coder.coder-remote", + telemetry, ); const mockSuccessfulAuth = (user = createMockUser()) => { @@ -357,6 +361,30 @@ describe("LoginCoordinator", () => { expect(result.success).toBe(false); }); + + it("emits telemetry with trigger and aborted result when dismissed", async () => { + const sink = new TestSink(); + const { userInteraction, coordinator } = createTestContext( + createTestTelemetryService(sink), + ); + userInteraction.setResponse("Authentication Required", undefined); + + await coordinator.ensureLoggedInWithDialog({ + url: TEST_URL, + safeHostname: TEST_HOSTNAME, + trigger: "missing_session", + }); + + expect(sink.events).toContainEqual( + expect.objectContaining({ + eventName: "auth.login_prompt", + properties: expect.objectContaining({ + trigger: "missing_session", + result: "aborted", + }), + }), + ); + }); }); describe("token fallback order", () => { diff --git a/test/unit/oauth/sessionManager.test.ts b/test/unit/oauth/sessionManager.test.ts index 5cb1af2f23..dfaaeaf876 100644 --- a/test/unit/oauth/sessionManager.test.ts +++ b/test/unit/oauth/sessionManager.test.ts @@ -9,8 +9,10 @@ import { type SecretsManager, type SessionAuth } from "@/core/secretsManager"; import { DEFAULT_OAUTH_SCOPES } from "@/oauth/constants"; import { OAuthSessionManager } from "@/oauth/sessionManager"; +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { type createMockLogger, + MockConfigurationProvider, setupAxiosMockRoutes, } from "../../mocks/testHelpers"; @@ -27,6 +29,7 @@ import { import type { ServiceContainer } from "@/core/container"; import type { Deployment } from "@/deployment/types"; +import type { TelemetryReporter } from "@/telemetry/reporter"; vi.mock("axios", async () => { const actual = await vi.importActual("axios"); @@ -102,7 +105,8 @@ function createTestContext(deployment: Deployment = createTestDeployment()) { const createManager = ( d: Deployment = deployment, onAuthRequired: () => Promise = () => Promise.resolve(), - ) => OAuthSessionManager.create(d, container, onAuthRequired); + telemetry?: TelemetryReporter, + ) => OAuthSessionManager.create(d, container, onAuthRequired, telemetry); /** * Sets up a complete OAuth operation test context. @@ -191,6 +195,38 @@ describe("OAuthSessionManager", () => { ); }); + it("emits telemetry for reactive refresh", async () => { + const { createManager, setupForOAuthOperation } = createTestContext(); + const sink = new TestSink(); + new MockConfigurationProvider().set("coder.telemetry.level", "local"); + const manager = createManager( + createTestDeployment(), + () => Promise.resolve(), + createTestTelemetryService(sink), + ); + + await setupForOAuthOperation({ + "/oauth2/token": createMockTokenResponse({ + access_token: "telemetry-token", + }), + }); + + await manager.refreshToken(); + + expect(sink.events).toContainEqual( + expect.objectContaining({ + eventName: "auth.token_refresh", + properties: expect.objectContaining({ + trigger: "reactive", + result: "success", + }), + measurements: expect.objectContaining({ + durationMs: expect.any(Number), + }), + }), + ); + }); + it("refreshes token successfully", async () => { const { secretsManager, mockAdapter, manager, setupOAuthSession } = createTestContext(); @@ -290,6 +326,34 @@ describe("OAuthSessionManager", () => { expect(auth?.token).toBe("background-refreshed-token"); }); + it("emits telemetry with background trigger", async () => { + const { createManager, setupForOAuthOperation } = createTestContext(); + const sink = new TestSink(); + new MockConfigurationProvider().set("coder.telemetry.level", "local"); + const manager = createManager( + createTestDeployment(), + () => Promise.resolve(), + createTestTelemetryService(sink), + ); + + await setupForOAuthOperation({ + "/oauth2/token": createMockTokenResponse({ + access_token: "background-token", + }), + }); + await manager.refreshToken("background"); + + expect(sink.events).toContainEqual( + expect.objectContaining({ + eventName: "auth.token_refresh", + properties: expect.objectContaining({ + trigger: "background", + result: "success", + }), + }), + ); + }); + it("calls onAuthRequired when refresh fails with re-auth error", async () => { const { createManager } = await setupBackgroundRefreshTest( createOAuthAxiosError("invalid_grant"), diff --git a/test/unit/remote/workspaceStateMachine.test.ts b/test/unit/remote/workspaceStateMachine.test.ts index fb82c42b81..6a37499937 100644 --- a/test/unit/remote/workspaceStateMachine.test.ts +++ b/test/unit/remote/workspaceStateMachine.test.ts @@ -17,8 +17,10 @@ import { workspace as createWorkspace, } from "@repo/mocks"; +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { createMockLogger, + MockConfigurationProvider, MockProgress, MockTerminalOutputChannel, MockUserInteraction, @@ -32,6 +34,7 @@ import type { import type { CoderApi } from "@/api/coderApi"; import type { StartupMode } from "@/core/mementoManager"; import type { FeatureSet } from "@/featureSet"; +import type { TelemetryReporter } from "@/telemetry/reporter"; import type { AuthorityParts } from "@/util"; vi.mock("@/api/workspace", async (importActual) => { @@ -77,7 +80,11 @@ function runningWorkspace( }); } -function setup(startupMode: StartupMode = "start") { +function setup( + startupMode: StartupMode = "start", + telemetry?: TelemetryReporter, +) { + new MockConfigurationProvider().set("coder.telemetry.level", "local"); const progress = new MockProgress<{ message?: string }>(); const userInteraction = new MockUserInteraction(); const sm = new WorkspaceStateMachine( @@ -88,6 +95,7 @@ function setup(startupMode: StartupMode = "start") { {} as FeatureSet, createMockLogger(), { mode: "url", url: "https://test.coder.com" }, + telemetry, ); return { sm, progress, userInteraction }; } @@ -370,6 +378,86 @@ describe("WorkspaceStateMachine", () => { } }); + describe("telemetry", () => { + it("emits update triggered telemetry with duration", async () => { + const sink = new TestSink(); + const { sm, progress } = setup( + "update", + createTestTelemetryService(sink), + ); + + await sm.processWorkspace(runningWorkspace(), progress); + + expect(sink.events).toContainEqual( + expect.objectContaining({ + eventName: "workspace.update.triggered", + properties: expect.objectContaining({ result: "success" }), + measurements: expect.objectContaining({ + durationMs: expect.any(Number), + }), + }), + ); + }); + + it("emits error result when update fails", async () => { + const sink = new TestSink(); + const { sm, progress } = setup( + "update", + createTestTelemetryService(sink), + ); + vi.mocked(updateWorkspace).mockRejectedValueOnce( + new Error("update failed"), + ); + + // The state machine catches the failure and falls back to the + // existing template version, so processWorkspace resolves. + await sm.processWorkspace(runningWorkspace(), progress); + + expect(sink.events).toContainEqual( + expect.objectContaining({ + eventName: "workspace.update.triggered", + properties: expect.objectContaining({ result: "error" }), + error: { message: "update failed" }, + }), + ); + }); + + it("emits selected-agent state transitions with observed duration", async () => { + const sink = new TestSink(); + const { sm, progress } = setup("start", createTestTelemetryService(sink)); + + await sm.processWorkspace( + runningWorkspace({ status: "connecting", lifecycle_state: "created" }), + progress, + ); + await sm.processWorkspace(runningWorkspace(), progress); + + const agentEvents = sink.events.filter( + (event) => event.eventName === "workspace.agent.state_transitioned", + ); + expect(agentEvents).toHaveLength(2); + expect(agentEvents[0]).toMatchObject({ + properties: { + agentName: "main", + fromStatus: "unknown", + toStatus: "connecting", + fromLifecycleState: "unknown", + toLifecycleState: "created", + }, + }); + expect(agentEvents[1]).toMatchObject({ + properties: { + agentName: "main", + fromStatus: "connecting", + toStatus: "connected", + fromLifecycleState: "created", + toLifecycleState: "ready", + }, + measurements: { observedDurationMs: expect.any(Number) }, + }); + }); + }); + describe("agent selection", () => { it("throws when user declines agent selection", async () => { vi.mocked(maybeAskAgent).mockResolvedValue(undefined); diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index fb2b9cc710..7098646e4b 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -5,6 +5,7 @@ import { WorkspaceMonitor } from "@/workspace/workspaceMonitor"; import { workspace as createWorkspace } from "@repo/mocks"; +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { MockConfigurationProvider, MockContextManager, @@ -20,6 +21,7 @@ import type { import type { CoderApi } from "@/api/coderApi"; import type { ContextManager } from "@/core/contextManager"; +import type { TelemetryReporter } from "@/telemetry/reporter"; function workspaceEvent( overrides?: Parameters[0], @@ -36,7 +38,11 @@ describe("WorkspaceMonitor", () => { vi.resetAllMocks(); }); - async function setup(stream = new MockEventStream()) { + async function setup( + stream = new MockEventStream(), + telemetry?: TelemetryReporter, + initialWorkspace: Workspace = createWorkspace(), + ) { const config = new MockConfigurationProvider(); const statusBar = new MockStatusBarItem(); const contextManager = new MockContextManager(); @@ -50,14 +56,59 @@ describe("WorkspaceMonitor", () => { }), } as unknown as CoderApi; const monitor = await WorkspaceMonitor.create( - createWorkspace(), + initialWorkspace, client, createMockLogger(), contextManager as unknown as ContextManager, + telemetry, ); return { monitor, client, stream, config, statusBar, contextManager }; } + describe("telemetry", () => { + it("emits initial workspace state and observed transitions", async () => { + const stream = new MockEventStream(); + const sink = new TestSink(); + new MockConfigurationProvider().set("coder.telemetry.level", "local"); + + await setup( + stream, + createTestTelemetryService(sink), + createWorkspace({ latest_build: { status: "running" } }), + ); + stream.pushMessage( + workspaceEvent({ + latest_build: { + status: "stopping", + transition: "stop", + reason: "autostop", + }, + }), + ); + + const events = sink.events.filter( + (event) => event.eventName === "workspace.state_transitioned", + ); + expect(events).toHaveLength(2); + expect(events[0]).toMatchObject({ + properties: { + from: "unknown", + to: "running", + }, + }); + expect(events[0].measurements.observedDurationMs).toBeUndefined(); + expect(events[1]).toMatchObject({ + properties: { + from: "running", + to: "stopping", + transition: "stop", + reason: "autostop", + }, + measurements: { observedDurationMs: expect.any(Number) }, + }); + }); + }); + describe("websocket lifecycle", () => { it("fires onChange when a workspace message arrives", async () => { const { monitor, stream } = await setup(); From af7a20d537603815eeab0fe17bb726855e8b47eb Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Tue, 12 May 2026 20:47:40 +0000 Subject: [PATCH 2/9] refactor(telemetry): keep lifecycle tracking isolated --- CHANGELOG.md | 7 ++ src/api/authInterceptor.ts | 21 +++-- src/instrumentation/workspace.ts | 71 ++++++++++++++++- src/login/loginCoordinator.ts | 118 ++++++++++++++-------------- src/remote/workspaceStateMachine.ts | 39 +-------- src/workspace/workspaceMonitor.ts | 26 +----- 6 files changed, 149 insertions(+), 133 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 7edc62be09..b6d00a5a63 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -23,12 +23,19 @@ local telemetry. - Local telemetry now records `http.requests` rollups for per-route HTTP health without emitting one event per request. +<<<<<<< HEAD - Local telemetry now records connection lifecycle: SSH process discovery/loss/recovery with sampled network info, and reconnecting WebSocket open, drop, reconnect, and state transitions, so connection stability is captured alongside other local telemetry. - Local telemetry now records authentication refresh/recovery prompts plus workspace and agent state transitions for connection lifecycle diagnostics. +======= +- Local telemetry now records authentication refresh/recovery attempts for + connection debugging. +- Local telemetry now records workspace and agent state transitions with observed + durations for connection lifecycle diagnostics. +>>>>>>> c7d49c2 (refactor(telemetry): keep lifecycle tracking isolated) ### Fixed diff --git a/src/api/authInterceptor.ts b/src/api/authInterceptor.ts index f28c659647..fd0e95aac5 100644 --- a/src/api/authInterceptor.ts +++ b/src/api/authInterceptor.ts @@ -1,6 +1,9 @@ import { type AxiosError, isAxiosError } from "axios"; -import { AuthTelemetry } from "../instrumentation/auth"; +import { + AuthTelemetry, + type AuthIntercept401Recovery, +} from "../instrumentation/auth"; import { OAuthError } from "../oauth/errors"; import { NOOP_TELEMETRY_REPORTER, @@ -62,9 +65,6 @@ export class AuthInterceptor implements vscode.Disposable { if (error.config) { const config = error.config as { _retryAttempted?: boolean }; if (config._retryAttempted) { - if (error.response?.status === 401) { - this.authTelemetry.intercept401("none"); - } throw error; } } @@ -75,7 +75,6 @@ export class AuthInterceptor implements vscode.Disposable { const baseUrl = this.client.getHost(); if (!baseUrl) { - this.authTelemetry.intercept401("none"); throw error; } const hostname = toSafeHost(baseUrl); @@ -89,14 +88,15 @@ export class AuthInterceptor implements vscode.Disposable { ): Promise { this.logger.debug("Received 401 response, attempting recovery"); - let loggedRecovery = false; + let recovery: AuthIntercept401Recovery = "none"; if (await this.oauthSessionManager.isLoggedInWithOAuth(hostname)) { try { const newTokens = await this.oauthSessionManager.refreshToken(); this.client.setSessionToken(newTokens.access_token); this.logger.debug("Token refresh successful, retrying request"); - this.authTelemetry.intercept401("refresh_success"); + recovery = "refresh_success"; + this.authTelemetry.intercept401(recovery); return this.retryRequest(error, newTokens.access_token); } catch (refreshError) { if (refreshError instanceof OAuthError) { @@ -113,8 +113,7 @@ export class AuthInterceptor implements vscode.Disposable { } if (this.onAuthRequired) { - this.authTelemetry.intercept401("login_required"); - loggedRecovery = true; + recovery = "login_required"; const success = await this.executeAuthRequired(hostname); if (success) { const auth = await this.secretsManager.getSessionAuth(hostname); @@ -125,9 +124,7 @@ export class AuthInterceptor implements vscode.Disposable { } } - if (!loggedRecovery) { - this.authTelemetry.intercept401("none"); - } + this.authTelemetry.intercept401(recovery); throw error; } diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts index bfee871140..7d36001f1d 100644 --- a/src/instrumentation/workspace.ts +++ b/src/instrumentation/workspace.ts @@ -5,6 +5,8 @@ import { import type { BuildReason, + Workspace, + WorkspaceAgent, WorkspaceAgentLifecycle, WorkspaceAgentStatus, WorkspaceStatus, @@ -32,12 +34,75 @@ interface WorkspaceAgentStateTransition { readonly observedDurationMs?: number; } +interface ObservedWorkspaceState { + readonly status: WorkspaceStatus; + readonly observedAtMs: number; +} + +interface ObservedAgentState { + readonly status: WorkspaceAgentStatus; + readonly lifecycleState: WorkspaceAgentLifecycle; + readonly observedAtMs: number; +} + export class WorkspaceTelemetry { + private observedWorkspaceState: ObservedWorkspaceState | undefined; + private observedAgentState: ObservedAgentState | undefined; + public constructor( private readonly telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) {} - public workspaceStateTransition(transition: WorkspaceStateTransition): void { + public observeWorkspace(workspace: Workspace): void { + const status = workspace.latest_build.status; + const now = performance.now(); + const previous = this.observedWorkspaceState; + if (previous?.status === status) { + return; + } + + this.workspaceStateTransition({ + from: previous?.status ?? INITIAL_STATE, + to: status, + transition: workspace.latest_build.transition, + reason: workspace.latest_build.reason, + ...(previous && { + observedDurationMs: now - previous.observedAtMs, + }), + }); + this.observedWorkspaceState = { status, observedAtMs: now }; + } + + public observeAgent(agent: WorkspaceAgent): void { + const now = performance.now(); + const previous = this.observedAgentState; + if ( + previous?.status === agent.status && + previous.lifecycleState === agent.lifecycle_state + ) { + return; + } + + this.agentStateTransition({ + agentName: agent.name, + fromStatus: previous?.status ?? INITIAL_STATE, + toStatus: agent.status, + fromLifecycleState: previous?.lifecycleState ?? INITIAL_STATE, + toLifecycleState: agent.lifecycle_state, + ...(previous && { observedDurationMs: now - previous.observedAtMs }), + }); + this.observedAgentState = { + status: agent.status, + lifecycleState: agent.lifecycle_state, + observedAtMs: now, + }; + } + + public resetAgent(): void { + this.observedAgentState = undefined; + } + + private workspaceStateTransition(transition: WorkspaceStateTransition): void { this.telemetry.log( "workspace.state_transitioned", { @@ -52,7 +117,9 @@ export class WorkspaceTelemetry { ); } - public agentStateTransition(transition: WorkspaceAgentStateTransition): void { + private agentStateTransition( + transition: WorkspaceAgentStateTransition, + ): void { this.telemetry.log( "workspace.agent.state_transitioned", { diff --git a/src/login/loginCoordinator.ts b/src/login/loginCoordinator.ts index c457b6670f..96d2d4b814 100644 --- a/src/login/loginCoordinator.ts +++ b/src/login/loginCoordinator.ts @@ -97,68 +97,72 @@ export class LoginCoordinator implements vscode.Disposable { trigger?: AuthLoginPromptTrigger; }, ): Promise { - const { safeHostname, url, detailPrefix, message } = options; return this.authTelemetry.traceLoginPrompt( options.trigger ?? "auth_required", - () => - this.executeWithGuard(async () => { - // Show dialog promise - const dialogPromise = vscodeProposed.window - .showErrorMessage( - message || "Authentication Required", - { - modal: true, - useCustom: true, - detail: - (detailPrefix || - `Authentication needed for ${safeHostname}.`) + - "\n\nIf you've already logged in, you may close this dialog.", - }, - "Login", - ) - .then(async (action) => { - if (action === "Login") { - // Proceed with the login flow, handling logging in from another window - const storedAuth = - await this.secretsManager.getSessionAuth(safeHostname); - const newUrl = await maybeAskUrl( - this.mementoManager, - url, - storedAuth?.url, - ); - if (!newUrl) { - throw new Error("URL must be provided"); - } - - const result = await this.attemptLogin( - { url: newUrl, safeHostname }, - false, - options.token, - ); - - await this.persistSessionAuth(result, safeHostname, newUrl); - - return result; - } else { - // User cancelled - return { success: false } as const; - } - }); - - // Race between user clicking login and cross-window detection - const { - promise: crossWindowPromise, - dispose: disposeCrossWindowListener, - } = this.waitForCrossWindowLogin(safeHostname); - try { - return await Promise.race([dialogPromise, crossWindowPromise]); - } finally { - disposeCrossWindowListener(); - } - }), + () => this.performLoginDialog(options), ); } + private async performLoginDialog( + options: LoginOptions & { message?: string; detailPrefix?: string }, + ): Promise { + const { safeHostname, url, detailPrefix, message } = options; + return this.executeWithGuard(async () => { + // Show dialog promise + const dialogPromise = vscodeProposed.window + .showErrorMessage( + message || "Authentication Required", + { + modal: true, + useCustom: true, + detail: + (detailPrefix || `Authentication needed for ${safeHostname}.`) + + "\n\nIf you've already logged in, you may close this dialog.", + }, + "Login", + ) + .then(async (action) => { + if (action === "Login") { + // Proceed with the login flow, handling logging in from another window + const storedAuth = + await this.secretsManager.getSessionAuth(safeHostname); + const newUrl = await maybeAskUrl( + this.mementoManager, + url, + storedAuth?.url, + ); + if (!newUrl) { + throw new Error("URL must be provided"); + } + + const result = await this.attemptLogin( + { url: newUrl, safeHostname }, + false, + options.token, + ); + + await this.persistSessionAuth(result, safeHostname, newUrl); + + return result; + } else { + // User cancelled + return { success: false } as const; + } + }); + + // Race between user clicking login and cross-window detection + const { + promise: crossWindowPromise, + dispose: disposeCrossWindowListener, + } = this.waitForCrossWindowLogin(safeHostname); + try { + return await Promise.race([dialogPromise, crossWindowPromise]); + } finally { + disposeCrossWindowListener(); + } + }); + } + private async persistSessionAuth( result: LoginResult, safeHostname: string, diff --git a/src/remote/workspaceStateMachine.ts b/src/remote/workspaceStateMachine.ts index 4a6acefdea..1189b37563 100644 --- a/src/remote/workspaceStateMachine.ts +++ b/src/remote/workspaceStateMachine.ts @@ -26,10 +26,7 @@ import { TerminalOutputChannel } from "./terminalOutputChannel"; import type { ProvisionerJobLog, Workspace, - WorkspaceAgent, - WorkspaceAgentLifecycle, WorkspaceAgentLog, - WorkspaceAgentStatus, } from "coder/site/src/api/typesGenerated"; import type { CoderApi } from "../api/coderApi"; @@ -43,12 +40,6 @@ import type { AuthorityParts } from "../util"; * Manages workspace and agent state transitions until ready for SSH connection. * Streams build and agent logs, and handles socket lifecycle. */ -interface ObservedAgentState { - readonly status: WorkspaceAgentStatus; - readonly lifecycleState: WorkspaceAgentLifecycle; - readonly observedAtMs: number; -} - export class WorkspaceStateMachine implements vscode.Disposable { private readonly terminal: TerminalOutputChannel; private readonly buildLogStream = new LazyStream(); @@ -57,7 +48,6 @@ export class WorkspaceStateMachine implements vscode.Disposable { private agent: { id: string; name: string } | undefined; private workspace: Workspace | undefined; - private observedAgentState: ObservedAgentState | undefined; constructor( private readonly parts: AuthorityParts, @@ -182,7 +172,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { `Agent ${this.agent.name} not found in ${workspaceName} resources`, ); } - this.recordAgentState(agent); + this.telemetry.observeAgent(agent); switch (agent.status) { case "connecting": @@ -354,32 +344,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { private resetAgent(): void { this.agent = undefined; - this.observedAgentState = undefined; - } - - private recordAgentState(agent: WorkspaceAgent): void { - const now = performance.now(); - const previous = this.observedAgentState; - if ( - previous?.status === agent.status && - previous.lifecycleState === agent.lifecycle_state - ) { - return; - } - - this.telemetry.agentStateTransition({ - agentName: agent.name, - fromStatus: previous?.status ?? "unknown", - toStatus: agent.status, - fromLifecycleState: previous?.lifecycleState ?? "unknown", - toLifecycleState: agent.lifecycle_state, - ...(previous && { observedDurationMs: now - previous.observedAtMs }), - }); - this.observedAgentState = { - status: agent.status, - lifecycleState: agent.lifecycle_state, - observedAtMs: now, - }; + this.telemetry.resetAgent(); } dispose(): void { diff --git a/src/workspace/workspaceMonitor.ts b/src/workspace/workspaceMonitor.ts index 05a9793566..57a16766c4 100644 --- a/src/workspace/workspaceMonitor.ts +++ b/src/workspace/workspaceMonitor.ts @@ -1,7 +1,6 @@ import { type ServerSentEvent, type Workspace, - type WorkspaceStatus, } from "coder/site/src/api/typesGenerated"; import { formatDistanceToNowStrict } from "date-fns"; import * as vscode from "vscode"; @@ -51,8 +50,6 @@ export class WorkspaceMonitor implements vscode.Disposable { private readonly telemetry: WorkspaceTelemetry; private latestWorkspace: Workspace; - private lastWorkspaceStatus: WorkspaceStatus | undefined; - private lastWorkspaceStatusObservedAtMs: number | undefined; private constructor( workspace: Workspace, @@ -147,33 +144,12 @@ export class WorkspaceMonitor implements vscode.Disposable { } private update(workspace: Workspace) { - this.recordWorkspaceStatus(workspace); + this.telemetry.observeWorkspace(workspace); this.latestWorkspace = workspace; this.updateContext(workspace); this.updateStatusBar(workspace); } - private recordWorkspaceStatus(workspace: Workspace): void { - const status = workspace.latest_build.status; - const now = performance.now(); - const previous = this.lastWorkspaceStatus; - if (previous === status) { - return; - } - - this.telemetry.workspaceStateTransition({ - from: previous ?? "unknown", - to: status, - transition: workspace.latest_build.transition, - reason: workspace.latest_build.reason, - ...(this.lastWorkspaceStatusObservedAtMs !== undefined && { - observedDurationMs: now - this.lastWorkspaceStatusObservedAtMs, - }), - }); - this.lastWorkspaceStatus = status; - this.lastWorkspaceStatusObservedAtMs = now; - } - private maybeNotify(workspace: Workspace) { const cfg = vscode.workspace.getConfiguration(); if (areNotificationsDisabled(cfg)) { From ad17282d8a54b5121aa84e67278cbfb9a2293fe8 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Wed, 13 May 2026 13:27:47 +0300 Subject: [PATCH 3/9] refactor(telemetry): simplify auth/workspace instrumentation - workspace.ts: inline single-use transition helpers, unify on the spread idiom for optional `observedDurationMs`, move `performance.now()` below the dedup early-return, drop the no-op `() => fn()` wrapper in `traceUpdateTriggered`, and make `INITIAL_STATE` private. - auth.ts: replace the `T extends LoginPromptResult` constraint with a `LoginPromptTracer` exposing `markAborted()`, matching the `RemoteSetupTracer` pattern. Callers now drive abort signaling, so telemetry no longer depends on `LoginResult`'s shape. - loginCoordinator: call `tracer.markAborted()` on `!result.success`. --- src/instrumentation/auth.ts | 17 ++--- src/instrumentation/workspace.ts | 104 +++++++++---------------------- src/login/loginCoordinator.ts | 8 ++- 3 files changed, 42 insertions(+), 87 deletions(-) diff --git a/src/instrumentation/auth.ts b/src/instrumentation/auth.ts index 6d033d2b50..9fdcb3a8a4 100644 --- a/src/instrumentation/auth.ts +++ b/src/instrumentation/auth.ts @@ -10,8 +10,9 @@ export type AuthIntercept401Recovery = | "none"; export type AuthLoginPromptTrigger = "auth_required" | "missing_session"; -interface LoginPromptResult { - readonly success: boolean; +/** Helpers scoped to the auth.login_prompt trace's lifetime. */ +export interface LoginPromptTracer { + markAborted(): void; } export class AuthTelemetry { @@ -30,19 +31,13 @@ export class AuthTelemetry { this.telemetry.log("auth.intercept_401", { recovery }); } - public traceLoginPrompt( + public traceLoginPrompt( trigger: AuthLoginPromptTrigger, - fn: () => Promise, + fn: (tracer: LoginPromptTracer) => Promise, ): Promise { return this.telemetry.trace( "auth.login_prompt", - async (span) => { - const result = await fn(); - if (!result.success) { - span.markAborted(); - } - return result; - }, + (span) => fn({ markAborted: () => span.markAborted() }), { trigger }, ); } diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts index 7d36001f1d..77676ae74f 100644 --- a/src/instrumentation/workspace.ts +++ b/src/instrumentation/workspace.ts @@ -4,35 +4,14 @@ import { } from "../telemetry/reporter"; import type { - BuildReason, Workspace, WorkspaceAgent, WorkspaceAgentLifecycle, WorkspaceAgentStatus, WorkspaceStatus, - WorkspaceTransition, } from "coder/site/src/api/typesGenerated"; -export const INITIAL_STATE = "unknown"; - -type InitialState = typeof INITIAL_STATE; - -interface WorkspaceStateTransition { - readonly from: WorkspaceStatus | InitialState; - readonly to: WorkspaceStatus; - readonly transition?: WorkspaceTransition; - readonly reason?: BuildReason; - readonly observedDurationMs?: number; -} - -interface WorkspaceAgentStateTransition { - readonly agentName: string; - readonly fromStatus: WorkspaceAgentStatus | InitialState; - readonly toStatus: WorkspaceAgentStatus; - readonly fromLifecycleState: WorkspaceAgentLifecycle | InitialState; - readonly toLifecycleState: WorkspaceAgentLifecycle; - readonly observedDurationMs?: number; -} +const INITIAL_STATE = "unknown"; interface ObservedWorkspaceState { readonly status: WorkspaceStatus; @@ -55,26 +34,30 @@ export class WorkspaceTelemetry { public observeWorkspace(workspace: Workspace): void { const status = workspace.latest_build.status; - const now = performance.now(); const previous = this.observedWorkspaceState; if (previous?.status === status) { return; } + const now = performance.now(); - this.workspaceStateTransition({ - from: previous?.status ?? INITIAL_STATE, - to: status, - transition: workspace.latest_build.transition, - reason: workspace.latest_build.reason, - ...(previous && { - observedDurationMs: now - previous.observedAtMs, - }), - }); + this.telemetry.log( + "workspace.state_transitioned", + { + from: previous?.status ?? INITIAL_STATE, + to: status, + ...(workspace.latest_build.transition && { + transition: workspace.latest_build.transition, + }), + ...(workspace.latest_build.reason && { + reason: workspace.latest_build.reason, + }), + }, + previous ? { observedDurationMs: now - previous.observedAtMs } : {}, + ); this.observedWorkspaceState = { status, observedAtMs: now }; } public observeAgent(agent: WorkspaceAgent): void { - const now = performance.now(); const previous = this.observedAgentState; if ( previous?.status === agent.status && @@ -82,15 +65,19 @@ export class WorkspaceTelemetry { ) { return; } + const now = performance.now(); - this.agentStateTransition({ - agentName: agent.name, - fromStatus: previous?.status ?? INITIAL_STATE, - toStatus: agent.status, - fromLifecycleState: previous?.lifecycleState ?? INITIAL_STATE, - toLifecycleState: agent.lifecycle_state, - ...(previous && { observedDurationMs: now - previous.observedAtMs }), - }); + this.telemetry.log( + "workspace.agent.state_transitioned", + { + agentName: agent.name, + fromStatus: previous?.status ?? INITIAL_STATE, + toStatus: agent.status, + fromLifecycleState: previous?.lifecycleState ?? INITIAL_STATE, + toLifecycleState: agent.lifecycle_state, + }, + previous ? { observedDurationMs: now - previous.observedAtMs } : {}, + ); this.observedAgentState = { status: agent.status, lifecycleState: agent.lifecycle_state, @@ -102,40 +89,7 @@ export class WorkspaceTelemetry { this.observedAgentState = undefined; } - private workspaceStateTransition(transition: WorkspaceStateTransition): void { - this.telemetry.log( - "workspace.state_transitioned", - { - from: transition.from, - to: transition.to, - ...(transition.transition && { transition: transition.transition }), - ...(transition.reason && { reason: transition.reason }), - }, - transition.observedDurationMs === undefined - ? {} - : { observedDurationMs: transition.observedDurationMs }, - ); - } - - private agentStateTransition( - transition: WorkspaceAgentStateTransition, - ): void { - this.telemetry.log( - "workspace.agent.state_transitioned", - { - agentName: transition.agentName, - fromStatus: transition.fromStatus, - toStatus: transition.toStatus, - fromLifecycleState: transition.fromLifecycleState, - toLifecycleState: transition.toLifecycleState, - }, - transition.observedDurationMs === undefined - ? {} - : { observedDurationMs: transition.observedDurationMs }, - ); - } - public traceUpdateTriggered(fn: () => Promise): Promise { - return this.telemetry.trace("workspace.update.triggered", () => fn()); + return this.telemetry.trace("workspace.update.triggered", fn); } } diff --git a/src/login/loginCoordinator.ts b/src/login/loginCoordinator.ts index 96d2d4b814..fa032dcb09 100644 --- a/src/login/loginCoordinator.ts +++ b/src/login/loginCoordinator.ts @@ -99,7 +99,13 @@ export class LoginCoordinator implements vscode.Disposable { ): Promise { return this.authTelemetry.traceLoginPrompt( options.trigger ?? "auth_required", - () => this.performLoginDialog(options), + async (tracer) => { + const result = await this.performLoginDialog(options); + if (!result.success) { + tracer.markAborted(); + } + return result; + }, ); } From 32ce9d7da61f0f94d8e23af6bfc2a207fe56c212 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Wed, 13 May 2026 14:39:15 +0300 Subject: [PATCH 4/9] fix changelog --- CHANGELOG.md | 31 +++++++++++-------------------- 1 file changed, 11 insertions(+), 20 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b6d00a5a63..49957df077 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,29 +13,20 @@ machine only and never sent anywhere. Configure via the new `coder.telemetry.level` setting (`local` by default, `off` to disable); see `coder.telemetry.local` for tunables. -- Every `coder.*` command now records a `command.invoked` telemetry event with - its duration and outcome, so command latency and failures are captured - alongside other local telemetry. -- Extension activation, remote workspace setup phases (auth retrieval, - workspace lookup, workspace and agent readiness, SSH config write), and CLI - binary download/verify now emit local telemetry events with their duration - and outcome, so startup latency and failures are captured alongside other - local telemetry. +- Local telemetry now records `command.invoked` for each `coder.*` command + with duration and outcome. +- Local telemetry now records extension activation, remote workspace setup + phases (auth retrieval, workspace lookup, workspace and agent readiness, + SSH config write), and CLI binary download/verify with their durations + and outcomes. - Local telemetry now records `http.requests` rollups for per-route HTTP - health without emitting one event per request. -<<<<<<< HEAD + health, without emitting one event per request. - Local telemetry now records connection lifecycle: SSH process discovery/loss/recovery with sampled network info, and reconnecting - WebSocket open, drop, reconnect, and state transitions, so connection - stability is captured alongside other local telemetry. -- Local telemetry now records authentication refresh/recovery prompts plus - workspace and agent state transitions for connection lifecycle diagnostics. -======= -- Local telemetry now records authentication refresh/recovery attempts for - connection debugging. -- Local telemetry now records workspace and agent state transitions with observed - durations for connection lifecycle diagnostics. ->>>>>>> c7d49c2 (refactor(telemetry): keep lifecycle tracking isolated) + WebSocket open/drop/reconnect/state transitions. +- Local telemetry now records authentication refresh and recovery prompts. +- Local telemetry now records workspace and agent state transitions with + observed durations. ### Fixed From 978c6854264f776092d674ca7abc9dd12f57dbac Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Wed, 13 May 2026 16:49:14 +0300 Subject: [PATCH 5/9] refactor(telemetry): decouple auth/workspace instrumentation - Add Span.markFailure() so non-thrown failures can record result=error without throwing. The emitted event omits the error block, matching OTel's "Status: Error + optional exception event" convention. - Move login-prompt outcome classification (success/auth_failed/aborted) from LoginCoordinator into AuthTelemetry.traceLoginPrompt. The coordinator just returns its natural LoginResult; telemetry maps it. - Promote auth.intercept_401 from a log to a span so durationMs covers the full 401 recovery + retry. TODO marker points at #925 for a correlated received-marker once Span.log() lands. - Add workspace.start.triggered span (mirrors update.triggered) and buildDurationMs measurement on workspace.state_transitioned. - Dedupe workspace transitions on (status, transition, reason). - Switch LoginCoordinator/WorkspaceMonitor/WorkspaceStateMachine/ AuthInterceptor/OAuthSessionManager to take ServiceContainer instead of TelemetryReporter (+ individual services). Drops NOOP telemetry defaults; injection is now explicit. - Make ensureLoggedInWithDialog trigger required. Tests: 1601 passing, 1 skipped. Adds direct Span.markFailure unit tests in service.test.ts and telemetry describe blocks per affected unit. --- src/api/authInterceptor.ts | 101 ++++++------ src/core/container.ts | 6 +- src/extension.ts | 5 +- src/instrumentation/auth.ts | 60 +++++-- src/instrumentation/workspace.ts | 81 +++++++--- src/login/loginCoordinator.ts | 66 ++++---- src/oauth/sessionManager.ts | 15 +- src/remote/remote.ts | 12 +- src/remote/workspaceStateMachine.ts | 22 +-- src/telemetry/service.ts | 30 +++- src/telemetry/span.ts | 13 ++ src/workspace/workspaceMonitor.ts | 29 ++-- test/mocks/testHelpers.ts | 34 ++++ test/unit/api/authInterceptor.test.ts | 85 +++++++--- test/unit/login/loginCoordinator.test.ts | 151 ++++++++++++------ test/unit/oauth/sessionManager.test.ts | 131 ++++++--------- .../unit/remote/workspaceStateMachine.test.ts | 118 ++++++++------ test/unit/telemetry/service.test.ts | 39 +++++ test/unit/workspace/workspaceMonitor.test.ts | 109 +++++++++++-- 19 files changed, 706 insertions(+), 401 deletions(-) diff --git a/src/api/authInterceptor.ts b/src/api/authInterceptor.ts index fd0e95aac5..08e0e55ef7 100644 --- a/src/api/authInterceptor.ts +++ b/src/api/authInterceptor.ts @@ -1,18 +1,12 @@ import { type AxiosError, isAxiosError } from "axios"; -import { - AuthTelemetry, - type AuthIntercept401Recovery, -} from "../instrumentation/auth"; +import { AuthTelemetry } from "../instrumentation/auth"; import { OAuthError } from "../oauth/errors"; -import { - NOOP_TELEMETRY_REPORTER, - type TelemetryReporter, -} from "../telemetry/reporter"; import { toSafeHost } from "../util"; import type * as vscode from "vscode"; +import type { ServiceContainer } from "../core/container"; import type { SecretsManager } from "../core/secretsManager"; import type { Logger } from "../logging/logger"; import type { RequestConfigWithMeta } from "../logging/types"; @@ -37,17 +31,19 @@ export type AuthRequiredHandler = (hostname: string) => Promise; export class AuthInterceptor implements vscode.Disposable { private readonly interceptorId: number; private readonly authTelemetry: AuthTelemetry; + private readonly logger: Logger; + private readonly secretsManager: SecretsManager; private authRequiredPromise: Promise | null = null; constructor( private readonly client: CoderApi, - private readonly logger: Logger, private readonly oauthSessionManager: OAuthSessionManager, - private readonly secretsManager: SecretsManager, + container: ServiceContainer, private readonly onAuthRequired?: AuthRequiredHandler, - telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) { - this.authTelemetry = new AuthTelemetry(telemetry); + this.logger = container.getLogger(); + this.secretsManager = container.getSecretsManager(); + this.authTelemetry = new AuthTelemetry(container.getTelemetryService()); this.interceptorId = this.client .getAxiosInstance() .interceptors.response.use( @@ -82,50 +78,63 @@ export class AuthInterceptor implements vscode.Disposable { return this.handle401Error(error, hostname); } - private async handle401Error( + /** + * `auth.intercept_401` wraps recovery + retry, so the span emits after the + * retry resolves; the receive-time is `timestamp - durationMs`. + * + * TODO(#925): once `Span.log()` lands, emit a correlated `auth.intercept_401.received` + * log here at decision time so analytics can see the receive moment + * directly without back-computing. + */ + private handle401Error( error: AxiosError, hostname: string, ): Promise { this.logger.debug("Received 401 response, attempting recovery"); - - let recovery: AuthIntercept401Recovery = "none"; - - if (await this.oauthSessionManager.isLoggedInWithOAuth(hostname)) { - try { - const newTokens = await this.oauthSessionManager.refreshToken(); - this.client.setSessionToken(newTokens.access_token); - this.logger.debug("Token refresh successful, retrying request"); - recovery = "refresh_success"; - this.authTelemetry.intercept401(recovery); - return this.retryRequest(error, newTokens.access_token); - } catch (refreshError) { - if (refreshError instanceof OAuthError) { - const msg = `Token refresh failed: ${refreshError.message}`; - if (refreshError.requiresReAuth) { - this.logger.warn(msg); - } else { - this.logger.error(msg); - } - } else { - this.logger.error("Token refresh failed:", refreshError); - } - } - } - - if (this.onAuthRequired) { - recovery = "login_required"; - const success = await this.executeAuthRequired(hostname); - if (success) { - const auth = await this.secretsManager.getSessionAuth(hostname); + return this.authTelemetry.traceIntercept401(async (setRecovery) => { + const newToken = (await this.oauthSessionManager.isLoggedInWithOAuth( + hostname, + )) + ? await this.tryOAuthRefresh() + : undefined; + if (newToken) { + setRecovery("refresh_success"); + return this.retryRequest(error, newToken); + } else if (this.onAuthRequired) { + setRecovery("login_required"); + const success = await this.executeAuthRequired(hostname); + const auth = success + ? await this.secretsManager.getSessionAuth(hostname) + : undefined; if (auth) { this.logger.debug("Re-authentication successful, retrying request"); return this.retryRequest(error, auth.token); } + throw error; + } else { + setRecovery("none"); + throw error; } - } + }); + } - this.authTelemetry.intercept401(recovery); - throw error; + /** Returns the new access token on success, or undefined when refresh fails. */ + private async tryOAuthRefresh(): Promise { + try { + const newTokens = await this.oauthSessionManager.refreshToken(); + this.client.setSessionToken(newTokens.access_token); + this.logger.debug("Token refresh successful, retrying request"); + return newTokens.access_token; + } catch (refreshError) { + if (!(refreshError instanceof OAuthError)) { + this.logger.error("Token refresh failed:", refreshError); + } else if (refreshError.requiresReAuth) { + this.logger.warn(`Token refresh failed: ${refreshError.message}`); + } else { + this.logger.error(`Token refresh failed: ${refreshError.message}`); + } + return undefined; + } } /** diff --git a/src/core/container.ts b/src/core/container.ts index 9a0f5a27a2..cc781a2b58 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -99,13 +99,9 @@ export class ServiceContainer implements vscode.Disposable { this.contextManager = new ContextManager(context); this.oauthCallback = new OAuthCallback(context.secrets, this.logger); this.loginCoordinator = new LoginCoordinator( - this.secretsManager, - this.mementoManager, - this.logger, - this.cliCredentialManager, + this, this.oauthCallback, context.extension.id, - this.telemetryService, ); this.duplicateWorkspaceIpc = new DuplicateWorkspaceIpc( context.secrets, diff --git a/src/extension.ts b/src/extension.ts index ba79017314..6e4554ec38 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -128,7 +128,6 @@ async function doActivate( deployment, serviceContainer, handleAuthFailure, - telemetryService, ); ctx.subscriptions.push(oauthSessionManager); @@ -146,14 +145,12 @@ async function doActivate( // Handles 401 responses (OAuth and otherwise) const authInterceptor = new AuthInterceptor( client, - output, oauthSessionManager, - secretsManager, + serviceContainer, async () => { await handleAuthFailure(); return false; }, - telemetryService, ); ctx.subscriptions.push(authInterceptor); diff --git a/src/instrumentation/auth.ts b/src/instrumentation/auth.ts index 9fdcb3a8a4..a5053f2df7 100644 --- a/src/instrumentation/auth.ts +++ b/src/instrumentation/auth.ts @@ -1,7 +1,4 @@ -import { - NOOP_TELEMETRY_REPORTER, - type TelemetryReporter, -} from "../telemetry/reporter"; +import type { TelemetryReporter } from "../telemetry/reporter"; export type AuthTokenRefreshTrigger = "background" | "reactive"; export type AuthIntercept401Recovery = @@ -10,15 +7,21 @@ export type AuthIntercept401Recovery = | "none"; export type AuthLoginPromptTrigger = "auth_required" | "missing_session"; -/** Helpers scoped to the auth.login_prompt trace's lifetime. */ -export interface LoginPromptTracer { - markAborted(): void; -} +/** User-initiated reasons a login prompt ended without success. */ +export type LoginPromptAbortReason = "user_dismissed" | "no_url_provided"; +/** Non-user-initiated reasons a login prompt ended without success. */ +export type LoginPromptFailureReason = "auth_failed"; + +/** Minimum shape `traceLoginPrompt` needs to classify a prompt outcome. */ +export type LoginPromptOutcome = + | { success: true } + | { + success: false; + reason: LoginPromptAbortReason | LoginPromptFailureReason; + }; export class AuthTelemetry { - public constructor( - private readonly telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, - ) {} + public constructor(private readonly telemetry: TelemetryReporter) {} public traceTokenRefresh( trigger: AuthTokenRefreshTrigger, @@ -27,17 +30,42 @@ export class AuthTelemetry { return this.telemetry.trace("auth.token_refresh", fn, { trigger }); } - public intercept401(recovery: AuthIntercept401Recovery): void { - this.telemetry.log("auth.intercept_401", { recovery }); + /** Wrap a 401 recovery; `setRecovery` records the outcome on the span. */ + public traceIntercept401( + fn: ( + setRecovery: (recovery: AuthIntercept401Recovery) => void, + ) => Promise, + ): Promise { + return this.telemetry.trace("auth.intercept_401", (span) => + fn((recovery) => span.setProperty("recovery", recovery)), + ); } - public traceLoginPrompt( + /** + * Record `auth.login_prompt`. The returned `LoginPromptOutcome` drives + * the span: success stays `success`, `auth_failed` maps to `markFailure`, + * any other reason maps to `markAborted`. The reason is always copied to + * the `outcome` property. + */ + public traceLoginPrompt( trigger: AuthLoginPromptTrigger, - fn: (tracer: LoginPromptTracer) => Promise, + fn: () => Promise, ): Promise { return this.telemetry.trace( "auth.login_prompt", - (span) => fn({ markAborted: () => span.markAborted() }), + async (span) => { + const result = await fn(); + if (result.success) { + span.setProperty("outcome", "success"); + } else if (result.reason === "auth_failed") { + span.setProperty("outcome", result.reason); + span.markFailure(); + } else { + span.setProperty("outcome", result.reason); + span.markAborted(); + } + return result; + }, { trigger }, ); } diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts index 77676ae74f..6e8e7f1909 100644 --- a/src/instrumentation/workspace.ts +++ b/src/instrumentation/workspace.ts @@ -1,20 +1,26 @@ -import { - NOOP_TELEMETRY_REPORTER, - type TelemetryReporter, -} from "../telemetry/reporter"; - import type { Workspace, WorkspaceAgent, WorkspaceAgentLifecycle, WorkspaceAgentStatus, + WorkspaceBuild, WorkspaceStatus, } from "coder/site/src/api/typesGenerated"; +import type { TelemetryReporter } from "../telemetry/reporter"; + const INITIAL_STATE = "unknown"; +const BUILDING_STATUSES = new Set([ + "pending", + "starting", + "stopping", +]); + interface ObservedWorkspaceState { readonly status: WorkspaceStatus; + readonly transition: WorkspaceBuild["transition"] | undefined; + readonly reason: WorkspaceBuild["reason"] | undefined; readonly observedAtMs: number; } @@ -27,34 +33,57 @@ interface ObservedAgentState { export class WorkspaceTelemetry { private observedWorkspaceState: ObservedWorkspaceState | undefined; private observedAgentState: ObservedAgentState | undefined; + /** Set on first observation of a building status; cleared when the build resolves. */ + private buildStartedAtMs: number | undefined; - public constructor( - private readonly telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, - ) {} + public constructor(private readonly telemetry: TelemetryReporter) {} public observeWorkspace(workspace: Workspace): void { const status = workspace.latest_build.status; + const transition = workspace.latest_build.transition ?? undefined; + const reason = workspace.latest_build.reason ?? undefined; const previous = this.observedWorkspaceState; - if (previous?.status === status) { + if ( + previous?.status === status && + previous.transition === transition && + previous.reason === reason + ) { return; } const now = performance.now(); + const wasBuilding = previous && BUILDING_STATUSES.has(previous.status); + const isBuilding = BUILDING_STATUSES.has(status); + + const measurements: Record = {}; + if (previous) { + measurements.observedDurationMs = now - previous.observedAtMs; + } + if (wasBuilding && !isBuilding && this.buildStartedAtMs !== undefined) { + measurements.buildDurationMs = now - this.buildStartedAtMs; + } + this.telemetry.log( "workspace.state_transitioned", { from: previous?.status ?? INITIAL_STATE, to: status, - ...(workspace.latest_build.transition && { - transition: workspace.latest_build.transition, - }), - ...(workspace.latest_build.reason && { - reason: workspace.latest_build.reason, - }), + ...(transition && { transition }), + ...(reason && { reason }), }, - previous ? { observedDurationMs: now - previous.observedAtMs } : {}, + measurements, ); - this.observedWorkspaceState = { status, observedAtMs: now }; + this.observedWorkspaceState = { + status, + transition, + reason, + observedAtMs: now, + }; + if (isBuilding) { + this.buildStartedAtMs ??= now; + } else { + this.buildStartedAtMs = undefined; + } } public observeAgent(agent: WorkspaceAgent): void { @@ -89,7 +118,21 @@ export class WorkspaceTelemetry { this.observedAgentState = undefined; } - public traceUpdateTriggered(fn: () => Promise): Promise { - return this.telemetry.trace("workspace.update.triggered", fn); + public traceUpdateTriggered( + workspaceName: string, + fn: () => Promise, + ): Promise { + return this.telemetry.trace("workspace.update.triggered", fn, { + workspaceName, + }); + } + + public traceStartTriggered( + workspaceName: string, + fn: () => Promise, + ): Promise { + return this.telemetry.trace("workspace.start.triggered", fn, { + workspaceName, + }); } } diff --git a/src/login/loginCoordinator.ts b/src/login/loginCoordinator.ts index fa032dcb09..0dadb3de9e 100644 --- a/src/login/loginCoordinator.ts +++ b/src/login/loginCoordinator.ts @@ -8,21 +8,20 @@ import { CertificateError } from "../error/certificateError"; import { AuthTelemetry, type AuthLoginPromptTrigger, + type LoginPromptAbortReason, + type LoginPromptFailureReason, } from "../instrumentation/auth"; import { OAuthAuthorizer } from "../oauth/authorizer"; import { buildOAuthTokenData } from "../oauth/utils"; import { withOptionalProgress } from "../progress"; import { maybeAskAuthMethod, maybeAskUrl } from "../promptUtils"; import { isKeyringEnabled } from "../settings/cli"; -import { - NOOP_TELEMETRY_REPORTER, - type TelemetryReporter, -} from "../telemetry/reporter"; import { vscodeProposed } from "../vscodeProposed"; import type { User } from "coder/site/src/api/typesGenerated"; import type { CliCredentialManager } from "../core/cliCredentialManager"; +import type { ServiceContainer } from "../core/container"; import type { MementoManager } from "../core/mementoManager"; import type { OAuthTokenData, SecretsManager } from "../core/secretsManager"; import type { Deployment } from "../deployment/types"; @@ -30,7 +29,10 @@ import type { Logger } from "../logging/logger"; import type { OAuthCallback } from "../oauth/oauthCallback"; type LoginResult = - | { success: false } + | { + success: false; + reason: LoginPromptAbortReason | LoginPromptFailureReason; + } | { success: true; user: User; token: string; oauth?: OAuthTokenData }; export interface LoginOptions { @@ -47,21 +49,25 @@ export class LoginCoordinator implements vscode.Disposable { private loginQueue: Promise = Promise.resolve(); private readonly oauthAuthorizer: OAuthAuthorizer; private readonly authTelemetry: AuthTelemetry; + private readonly secretsManager: SecretsManager; + private readonly mementoManager: MementoManager; + private readonly logger: Logger; + private readonly cliCredentialManager: CliCredentialManager; constructor( - private readonly secretsManager: SecretsManager, - private readonly mementoManager: MementoManager, - private readonly logger: Logger, - private readonly cliCredentialManager: CliCredentialManager, + container: ServiceContainer, oauthCallback: OAuthCallback, extensionId: string, - telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) { - this.authTelemetry = new AuthTelemetry(telemetry); + this.secretsManager = container.getSecretsManager(); + this.mementoManager = container.getMementoManager(); + this.logger = container.getLogger(); + this.cliCredentialManager = container.getCliCredentialManager(); + this.authTelemetry = new AuthTelemetry(container.getTelemetryService()); this.oauthAuthorizer = new OAuthAuthorizer( - secretsManager, + this.secretsManager, oauthCallback, - logger, + this.logger, extensionId, ); } @@ -90,22 +96,15 @@ export class LoginCoordinator implements vscode.Disposable { /** * Shows dialog then login - for system-initiated auth (remote, OAuth refresh). */ - public async ensureLoggedInWithDialog( + public ensureLoggedInWithDialog( options: LoginOptions & { message?: string; detailPrefix?: string; - trigger?: AuthLoginPromptTrigger; + trigger: AuthLoginPromptTrigger; }, ): Promise { - return this.authTelemetry.traceLoginPrompt( - options.trigger ?? "auth_required", - async (tracer) => { - const result = await this.performLoginDialog(options); - if (!result.success) { - tracer.markAborted(); - } - return result; - }, + return this.authTelemetry.traceLoginPrompt(options.trigger, () => + this.performLoginDialog(options), ); } @@ -127,7 +126,7 @@ export class LoginCoordinator implements vscode.Disposable { }, "Login", ) - .then(async (action) => { + .then(async (action): Promise => { if (action === "Login") { // Proceed with the login flow, handling logging in from another window const storedAuth = @@ -138,7 +137,7 @@ export class LoginCoordinator implements vscode.Disposable { storedAuth?.url, ); if (!newUrl) { - throw new Error("URL must be provided"); + return { success: false, reason: "no_url_provided" }; } const result = await this.attemptLogin( @@ -150,10 +149,9 @@ export class LoginCoordinator implements vscode.Disposable { await this.persistSessionAuth(result, safeHostname, newUrl); return result; - } else { - // User cancelled - return { success: false } as const; } + // User cancelled + return { success: false, reason: "user_dismissed" }; }); // Race between user clicking login and cross-window detection @@ -320,7 +318,7 @@ export class LoginCoordinator implements vscode.Disposable { case "legacy": return this.loginWithToken(client); case undefined: - return { success: false }; // User aborted + return { success: false, reason: "user_dismissed" }; } } @@ -333,7 +331,7 @@ export class LoginCoordinator implements vscode.Disposable { return { success: true, token: "", user }; } catch (err) { this.showAuthError(err, isAutoLogin); - return { success: false }; + return { success: false, reason: "auth_failed" }; } } @@ -354,7 +352,7 @@ export class LoginCoordinator implements vscode.Disposable { return "unauthorized"; } this.showAuthError(err, isAutoLogin); - return { success: false }; + return { success: false, reason: "auth_failed" }; } } @@ -436,7 +434,7 @@ export class LoginCoordinator implements vscode.Disposable { return { success: true, user, token: validatedToken ?? "" }; } - return { success: false }; + return { success: false, reason: "user_dismissed" }; } /** @@ -476,7 +474,7 @@ export class LoginCoordinator implements vscode.Disposable { `${title}: ${getErrorMessage(error, "Unknown error")}`, ); } - return { success: false }; + return { success: false, reason: "auth_failed" }; } } diff --git a/src/oauth/sessionManager.ts b/src/oauth/sessionManager.ts index 3360d79fc7..609e71ed87 100644 --- a/src/oauth/sessionManager.ts +++ b/src/oauth/sessionManager.ts @@ -3,10 +3,6 @@ import { AuthTelemetry, type AuthTokenRefreshTrigger, } from "../instrumentation/auth"; -import { - NOOP_TELEMETRY_REPORTER, - type TelemetryReporter, -} from "../telemetry/reporter"; import { DEFAULT_OAUTH_SCOPES, REFRESH_GRANT_TYPE } from "./constants"; import { OAuthError, parseOAuthError } from "./errors"; @@ -66,31 +62,26 @@ export class OAuthSessionManager implements vscode.Disposable { deployment: Deployment | null, container: ServiceContainer, onAuthRequired: () => Promise = () => Promise.resolve(), - telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ): OAuthSessionManager { const manager = new OAuthSessionManager( deployment, container.getSecretsManager(), container.getLogger(), onAuthRequired, - telemetry, + new AuthTelemetry(container.getTelemetryService()), ); manager.setupTokenListener(); manager.scheduleNextRefresh(); return manager; } - private readonly authTelemetry: AuthTelemetry; - private constructor( private deployment: Deployment | null, private readonly secretsManager: SecretsManager, private readonly logger: Logger, private readonly onAuthRequired: () => Promise, - telemetry: TelemetryReporter, - ) { - this.authTelemetry = new AuthTelemetry(telemetry); - } + private readonly authTelemetry: AuthTelemetry, + ) {} /** * Get current deployment, throwing if not set. diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 59184d8f83..61cbb38937 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -202,7 +202,6 @@ export class Remote { async () => { await this.showSessionExpiredDialog(context); }, - telemetry, ); disposables.push(remoteOAuthManager); @@ -225,14 +224,12 @@ export class Remote { // Create 401 interceptor - handles auth failures with re-login dialog const authInterceptor = new AuthInterceptor( workspaceClient, - this.logger, remoteOAuthManager, - this.secretsManager, + this.serviceContainer, async () => { const result = await this.showSessionExpiredDialog(context); return result.success; }, - telemetry, ); disposables.push(authInterceptor); @@ -316,9 +313,7 @@ export class Remote { const monitor = await WorkspaceMonitor.create( workspace, workspaceClient, - this.logger, - this.contextManager, - telemetry, + this.serviceContainer, ); disposables.push( monitor, @@ -336,9 +331,8 @@ export class Remote { args.startupMode, binaryPath, featureSet, - this.logger, cliAuth, - telemetry, + this.serviceContainer, ); disposables.push(stateMachine); diff --git a/src/remote/workspaceStateMachine.ts b/src/remote/workspaceStateMachine.ts index 1189b37563..a1987e67c3 100644 --- a/src/remote/workspaceStateMachine.ts +++ b/src/remote/workspaceStateMachine.ts @@ -15,10 +15,6 @@ import { } from "../api/workspace"; import { WorkspaceTelemetry } from "../instrumentation/workspace"; import { maybeAskAgent } from "../promptUtils"; -import { - NOOP_TELEMETRY_REPORTER, - type TelemetryReporter, -} from "../telemetry/reporter"; import { vscodeProposed } from "../vscodeProposed"; import { TerminalOutputChannel } from "./terminalOutputChannel"; @@ -30,6 +26,7 @@ import type { } from "coder/site/src/api/typesGenerated"; import type { CoderApi } from "../api/coderApi"; +import type { ServiceContainer } from "../core/container"; import type { StartupMode } from "../core/mementoManager"; import type { FeatureSet } from "../featureSet"; import type { Logger } from "../logging/logger"; @@ -49,18 +46,20 @@ export class WorkspaceStateMachine implements vscode.Disposable { private agent: { id: string; name: string } | undefined; private workspace: Workspace | undefined; + private readonly logger: Logger; + constructor( private readonly parts: AuthorityParts, private readonly workspaceClient: CoderApi, private startupMode: StartupMode, private readonly binaryPath: string, private readonly featureSet: FeatureSet, - private readonly logger: Logger, private readonly cliAuth: CliAuth, - telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, + container: ServiceContainer, ) { + this.logger = container.getLogger(); this.terminal = new TerminalOutputChannel("Coder: Workspace Build"); - this.telemetry = new WorkspaceTelemetry(telemetry); + this.telemetry = new WorkspaceTelemetry(container.getTelemetryService()); } /** @@ -277,7 +276,9 @@ export class WorkspaceStateMachine implements vscode.Disposable { mode: this.startupMode, status: workspace.latest_build.status, }); - await startWorkspace(this.buildCliContext(workspace)); + await this.telemetry.traceStartTriggered(workspaceName, () => + startWorkspace(this.buildCliContext(workspace)), + ); this.logger.info(`${workspaceName} start initiated`); } @@ -295,8 +296,9 @@ export class WorkspaceStateMachine implements vscode.Disposable { status: workspace.latest_build.status, }); try { - this.workspace = await this.telemetry.traceUpdateTriggered(() => - updateWorkspace(this.buildCliContext(workspace)), + this.workspace = await this.telemetry.traceUpdateTriggered( + workspaceName, + () => updateWorkspace(this.buildCliContext(workspace)), ); this.logger.info(`${workspaceName} update initiated`); return this.workspace; diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index 05ac148267..86a95749b1 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -17,7 +17,7 @@ import { type TelemetrySink, } from "./event"; import { newSpanId, newTraceId } from "./ids"; -import { NOOP_SPAN, type Span } from "./span"; +import { NOOP_SPAN, type Span, type SpanResult } from "./span"; import type { TelemetryReporter } from "./reporter"; @@ -149,6 +149,7 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { const { traceId, traceLevel } = spanOpts; let completed = false; let aborted = false; + let failed = false; const warnPostEmit = (op: string, name: string): void => { this.logger.warn( `Telemetry span '${eventName}' ${op}('${name}') called after emit; mutation dropped`, @@ -194,6 +195,22 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { } aborted = true; }, + markFailure(): void { + if (completed) { + warnPostEmit("markFailure", ""); + return; + } + failed = true; + }, + }; + const resolveResult = (): SpanResult => { + if (failed) { + return "error"; + } else if (aborted) { + return "aborted"; + } else { + return "success"; + } }; return this.#emitTimed( eventId, @@ -202,7 +219,7 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { spanProperties, spanMeasurements, spanOpts, - () => aborted, + resolveResult, ).finally(() => { completed = true; }); @@ -226,13 +243,10 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { properties: Record, measurements: Record, spanOpts: SpanOptions, - isAborted: () => boolean, + resolveResult: () => SpanResult, ): Promise { const start = performance.now(); - const send = ( - result: "success" | "error" | "aborted", - error?: unknown, - ): void => + const send = (result: SpanResult, error?: unknown): void => this.#safeEmit( eventId, eventName, @@ -242,7 +256,7 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { ); try { const value = await fn(); - send(isAborted() ? "aborted" : "success"); + send(resolveResult()); return value; } catch (err) { send("error", err); diff --git a/src/telemetry/span.ts b/src/telemetry/span.ts index a3e5973a46..a50329570c 100644 --- a/src/telemetry/span.ts +++ b/src/telemetry/span.ts @@ -1,5 +1,15 @@ import type { CallerMeasurements, CallerProperties } from "./event"; +/** + * Final disposition recorded on a traced event's `result` property. + * - `success`: ran to completion as intended. + * - `aborted`: ended early by a user-initiated cancel. + * - `error`: the operation failed. Thrown exceptions populate the event's + * `error` block; `markFailure()` does not. This matches + * OpenTelemetry's "Status: Error + optional exception event". + */ +export type SpanResult = "success" | "aborted" | "error"; + /** * Parent span handle. Children's `eventName` composes as `${parent.eventName}.${phaseName}`. * Phase names should not contain `.`; if they do, dots are replaced with `_` and a warning is logged. @@ -22,6 +32,8 @@ export interface Span { setMeasurement(name: string, value: number): void; /** Flip this span's `result` from `success` to `aborted` on normal return. */ markAborted(): void; + /** Flip `result` to `error` for a failure captured in the return value. See `SpanResult`. */ + markFailure(): void; } /** No-op `Span` used when telemetry is off. Runs phase fns but emits nothing. */ @@ -33,6 +45,7 @@ export const NOOP_SPAN: Span = { return fn(NOOP_SPAN); }, markAborted: () => undefined, + markFailure: () => undefined, setProperty: () => undefined, setMeasurement: () => undefined, }; diff --git a/src/workspace/workspaceMonitor.ts b/src/workspace/workspaceMonitor.ts index 57a16766c4..4f154453ab 100644 --- a/src/workspace/workspaceMonitor.ts +++ b/src/workspace/workspaceMonitor.ts @@ -11,13 +11,10 @@ import { areNotificationsDisabled, areUpdateNotificationsDisabled, } from "../settings/notifications"; -import { - NOOP_TELEMETRY_REPORTER, - type TelemetryReporter, -} from "../telemetry/reporter"; import { vscodeProposed } from "../vscodeProposed"; import type { CoderApi } from "../api/coderApi"; +import type { ServiceContainer } from "../core/container"; import type { ContextManager } from "../core/contextManager"; import type { Logger } from "../logging/logger"; import type { UnidirectionalStream } from "../websocket/eventStreamConnection"; @@ -48,18 +45,20 @@ export class WorkspaceMonitor implements vscode.Disposable { // For logging. private readonly name: string; private readonly telemetry: WorkspaceTelemetry; + private readonly logger: Logger; + private readonly contextManager: ContextManager; private latestWorkspace: Workspace; private constructor( workspace: Workspace, private readonly client: CoderApi, - private readonly logger: Logger, - private readonly contextManager: ContextManager, - telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, + container: ServiceContainer, ) { + this.logger = container.getLogger(); + this.contextManager = container.getContextManager(); this.name = createWorkspaceIdentifier(workspace); - this.telemetry = new WorkspaceTelemetry(telemetry); + this.telemetry = new WorkspaceTelemetry(container.getTelemetryService()); this.latestWorkspace = workspace; const statusBarItem = vscode.window.createStatusBarItem( @@ -83,23 +82,15 @@ export class WorkspaceMonitor implements vscode.Disposable { static async create( workspace: Workspace, client: CoderApi, - logger: Logger, - contextManager: ContextManager, - telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, + container: ServiceContainer, ): Promise { - const monitor = new WorkspaceMonitor( - workspace, - client, - logger, - contextManager, - telemetry, - ); + const monitor = new WorkspaceMonitor(workspace, client, container); // Initialize websocket connection const socket = await client.watchWorkspace(workspace); socket.addEventListener("open", () => { - logger.info(`Monitoring ${monitor.name}...`); + monitor.logger.info(`Monitoring ${monitor.name}...`); }); socket.addEventListener("message", (event) => { diff --git a/test/mocks/testHelpers.ts b/test/mocks/testHelpers.ts index 91f919dbfc..e85667fdc9 100644 --- a/test/mocks/testHelpers.ts +++ b/test/mocks/testHelpers.ts @@ -8,6 +8,7 @@ import axios, { import { vi } from "vitest"; import * as vscode from "vscode"; +import { createTestTelemetryService } from "./telemetry"; import { window as vscodeWindow } from "./vscode.runtime"; import type { Experiment, User } from "coder/site/src/api/typesGenerated"; @@ -16,8 +17,12 @@ import type { IncomingMessage } from "node:http"; import type { CoderApi } from "@/api/coderApi"; import type { CliCredentialManager } from "@/core/cliCredentialManager"; +import type { ServiceContainer } from "@/core/container"; +import type { MementoManager } from "@/core/mementoManager"; +import type { SecretsManager } from "@/core/secretsManager"; import type { Logger } from "@/logging/logger"; import type { NetworkInfo } from "@/remote/sshProcess"; +import type { TelemetryService } from "@/telemetry/service"; import type { EventHandler, EventPayloadMap, @@ -443,6 +448,35 @@ export function createMockLogger(): Logger { }; } +/** + * Minimal `ServiceContainer` stub for tests. Pass only the services the unit + * under test reads; unset services fail loudly on access. + */ +export function createMockServiceContainer( + overrides: { + telemetry?: TelemetryService; + logger?: Logger; + secretsManager?: SecretsManager; + mementoManager?: MementoManager; + cliCredentialManager?: CliCredentialManager; + contextManager?: unknown; + } = {}, +): ServiceContainer { + const telemetry = overrides.telemetry ?? createTestTelemetryService(); + const logger = overrides.logger ?? createMockLogger(); + return { + getTelemetryService: () => telemetry, + getLogger: () => logger, + getSecretsManager: () => overrides.secretsManager!, + getMementoManager: () => overrides.mementoManager!, + getCliCredentialManager: () => overrides.cliCredentialManager!, + getContextManager: () => + overrides.contextManager as ReturnType< + ServiceContainer["getContextManager"] + >, + } as ServiceContainer; +} + /** Update the mocked active color theme and fire onDidChangeActiveColorTheme. */ export function setActiveColorTheme(kind: vscode.ColorThemeKind): void { vscodeWindow.__setActiveColorThemeKind(kind); diff --git a/test/unit/api/authInterceptor.test.ts b/test/unit/api/authInterceptor.test.ts index 9527b8fe82..b4bec302ad 100644 --- a/test/unit/api/authInterceptor.test.ts +++ b/test/unit/api/authInterceptor.test.ts @@ -11,6 +11,7 @@ import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { createAxiosError, createMockLogger, + createMockServiceContainer, InMemoryMemento, InMemorySecretStorage, MockConfigurationProvider, @@ -24,7 +25,7 @@ import { import type { CoderApi } from "@/api/coderApi"; import type { OAuthSessionManager } from "@/oauth/sessionManager"; -import type { TelemetryReporter } from "@/telemetry/reporter"; +import type { TelemetryService } from "@/telemetry/service"; /** * Creates a mock axios instance with controllable interceptors. @@ -142,15 +143,13 @@ function createTestContext() { /** Creates interceptor with optional callback */ const createInterceptor = ( onAuthRequired?: AuthRequiredHandler, - telemetry?: TelemetryReporter, + telemetry?: TelemetryService, ) => new AuthInterceptor( mockCoderApi, - logger, mockOAuthManager as unknown as OAuthSessionManager, - secretsManager, + createMockServiceContainer({ telemetry, logger, secretsManager }), onAuthRequired, - telemetry, ); return { @@ -190,7 +189,7 @@ describe("AuthInterceptor", () => { }); describe("401 handling with OAuth", () => { - it("refreshes token, retries request, and emits telemetry", async () => { + it("refreshes token and retries the request", async () => { const { mockCoderApi, mockOAuthManager, @@ -198,7 +197,6 @@ describe("AuthInterceptor", () => { setupOAuthTokens, createInterceptor, } = createTestContext(); - const sink = new TestSink(); await setupOAuthTokens(); @@ -210,19 +208,13 @@ describe("AuthInterceptor", () => { const retryResponse = { data: "success", status: 200 }; vi.spyOn(axiosInstance, "request").mockResolvedValue(retryResponse); - createInterceptor(undefined, createTestTelemetryService(sink)); + createInterceptor(); const error = createAxiosError(401, "Unauthorized"); const result = await axiosInstance.triggerResponseError(error); expect(mockCoderApi.getSessionToken()).toBe("new-access-token"); expect(result).toEqual(retryResponse); - expect(sink.events).toContainEqual( - expect.objectContaining({ - eventName: "auth.intercept_401", - properties: { recovery: "refresh_success" }, - }), - ); }); it("does not retry if already retried", async () => { @@ -270,23 +262,16 @@ describe("AuthInterceptor", () => { }); describe("401 handling with callback (non-OAuth)", () => { - it("calls onAuthRequired callback on 401 and emits login-required recovery", async () => { + it("calls onAuthRequired callback on 401", async () => { const { axiosInstance, createInterceptor } = createTestContext(); - const sink = new TestSink(); const onAuthRequired = vi.fn().mockResolvedValue(false); - createInterceptor(onAuthRequired, createTestTelemetryService(sink)); + createInterceptor(onAuthRequired); const error = createAxiosError(401, "Unauthorized"); await expect(axiosInstance.triggerResponseError(error)).rejects.toThrow(); expect(onAuthRequired).toHaveBeenCalledWith(TEST_HOSTNAME); - expect(sink.events).toContainEqual( - expect.objectContaining({ - eventName: "auth.intercept_401", - properties: { recovery: "login_required" }, - }), - ); }); it("retries request when callback returns true", async () => { @@ -446,4 +431,58 @@ describe("AuthInterceptor", () => { expect(axiosInstance.getInterceptorCount()).toBe(0); }); }); + + describe("telemetry", () => { + it("emits span with recovery=refresh_success and result=success when OAuth refresh succeeds", async () => { + const sink = new TestSink(); + const { + mockOAuthManager, + axiosInstance, + setupOAuthTokens, + createInterceptor, + } = createTestContext(); + await setupOAuthTokens(); + mockOAuthManager.refreshToken.mockResolvedValue( + createMockTokenResponse({ access_token: "new" }), + ); + vi.spyOn(axiosInstance, "request").mockResolvedValue({ status: 200 }); + + createInterceptor(undefined, createTestTelemetryService(sink)); + await axiosInstance.triggerResponseError( + createAxiosError(401, "Unauthorized"), + ); + + expect(sink.eventsNamed("auth.intercept_401")).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + recovery: "refresh_success", + result: "success", + }), + measurements: expect.objectContaining({ + durationMs: expect.any(Number), + }), + }), + ]); + }); + + it("emits span with recovery=login_required and result=error when falling through to callback", async () => { + const sink = new TestSink(); + const { axiosInstance, createInterceptor } = createTestContext(); + const onAuthRequired = vi.fn().mockResolvedValue(false); + + createInterceptor(onAuthRequired, createTestTelemetryService(sink)); + await expect( + axiosInstance.triggerResponseError(createAxiosError(401, "denied")), + ).rejects.toThrow(); + + expect(sink.eventsNamed("auth.intercept_401")).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + recovery: "login_required", + result: "error", + }), + }), + ]); + }); + }); }); diff --git a/test/unit/login/loginCoordinator.test.ts b/test/unit/login/loginCoordinator.test.ts index dc77cc6b4b..8db03ccfc4 100644 --- a/test/unit/login/loginCoordinator.test.ts +++ b/test/unit/login/loginCoordinator.test.ts @@ -7,13 +7,14 @@ import { SecretsManager } from "@/core/secretsManager"; import { getHeaders } from "@/headers"; import { LoginCoordinator } from "@/login/loginCoordinator"; import { OAuthCallback } from "@/oauth/oauthCallback"; -import { maybeAskAuthMethod } from "@/promptUtils"; +import { maybeAskAuthMethod, maybeAskUrl } from "@/promptUtils"; import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { createAxiosError, createMockCliCredentialManager, createMockLogger, + createMockServiceContainer, createMockUser, InMemoryMemento, InMemorySecretStorage, @@ -22,7 +23,7 @@ import { MockUserInteraction, } from "../../mocks/testHelpers"; -import type { TelemetryReporter } from "@/telemetry/reporter"; +import type { TelemetryService } from "@/telemetry/service"; // Hoisted mock adapter implementation const mockAxiosAdapterImpl = vi.hoisted( @@ -101,7 +102,7 @@ const TEST_HOSTNAME = "coder.example.com"; /** * Creates a fresh test context with all dependencies. */ -function createTestContext(telemetry?: TelemetryReporter) { +function createTestContext(telemetry?: TelemetryService) { vi.resetAllMocks(); const mockAdapter = (axios as MockedAxios).__mockAdapter; @@ -124,13 +125,15 @@ function createTestContext(telemetry?: TelemetryReporter) { const mockCredentialManager = createMockCliCredentialManager(); const coordinator = new LoginCoordinator( - secretsManager, - mementoManager, - logger, - mockCredentialManager, + createMockServiceContainer({ + telemetry, + logger, + secretsManager, + mementoManager, + cliCredentialManager: mockCredentialManager, + }), oauthCallback, "coder.coder-remote", - telemetry, ); const mockSuccessfulAuth = (user = createMockUser()) => { @@ -157,6 +160,7 @@ function createTestContext(telemetry?: TelemetryReporter) { mockGetAuthenticatedUser, mockConfig, userInteraction, + logger, secretsManager, oauthCallback, mementoManager, @@ -310,26 +314,10 @@ describe("LoginCoordinator", () => { }); it("logs warning instead of showing dialog for autoLogin", async () => { - const { - mockConfig, - secretsManager, - oauthCallback, - mementoManager, - mockAuthFailure, - } = createTestContext(); + const { mockConfig, logger, coordinator, mockAuthFailure } = + createTestContext(); mockConfig.set("coder.tlsCertFile", "/path/to/cert.pem"); mockConfig.set("coder.tlsKeyFile", "/path/to/key.pem"); - - const logger = createMockLogger(); - const coordinator = new LoginCoordinator( - secretsManager, - mementoManager, - logger, - createMockCliCredentialManager(), - oauthCallback, - "coder.coder-remote", - ); - mockAuthFailure("Certificate error"); const result = await coordinator.ensureLoggedIn({ @@ -357,34 +345,11 @@ describe("LoginCoordinator", () => { const result = await coordinator.ensureLoggedInWithDialog({ url: TEST_URL, safeHostname: TEST_HOSTNAME, + trigger: "auth_required", }); expect(result.success).toBe(false); }); - - it("emits telemetry with trigger and aborted result when dismissed", async () => { - const sink = new TestSink(); - const { userInteraction, coordinator } = createTestContext( - createTestTelemetryService(sink), - ); - userInteraction.setResponse("Authentication Required", undefined); - - await coordinator.ensureLoggedInWithDialog({ - url: TEST_URL, - safeHostname: TEST_HOSTNAME, - trigger: "missing_session", - }); - - expect(sink.events).toContainEqual( - expect.objectContaining({ - eventName: "auth.login_prompt", - properties: expect.objectContaining({ - trigger: "missing_session", - result: "aborted", - }), - }), - ); - }); }); describe("token fallback order", () => { @@ -572,4 +537,90 @@ describe("LoginCoordinator", () => { expect(result).toEqual({ success: true, user, token: "stored-token" }); }); }); + + describe("telemetry", () => { + const dialogOptions = (trigger: "auth_required" | "missing_session") => ({ + url: TEST_URL, + safeHostname: TEST_HOSTNAME, + trigger, + }); + + it("emits aborted + outcome when the user dismisses the dialog", async () => { + const sink = new TestSink(); + const { userInteraction, coordinator } = createTestContext( + createTestTelemetryService(sink), + ); + userInteraction.setResponse("Authentication Required", undefined); + + await coordinator.ensureLoggedInWithDialog( + dialogOptions("missing_session"), + ); + + expect(sink.eventsNamed("auth.login_prompt")).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + trigger: "missing_session", + result: "aborted", + outcome: "user_dismissed", + }), + measurements: expect.objectContaining({ + durationMs: expect.any(Number), + }), + }), + ]); + }); + + it("emits result=error (no error block) + outcome when authentication itself fails", async () => { + const sink = new TestSink(); + const { mockConfig, userInteraction, coordinator, mockAuthFailure } = + createTestContext(createTestTelemetryService(sink)); + mockConfig.set("coder.tlsCertFile", "/path/to/cert.pem"); + mockConfig.set("coder.tlsKeyFile", "/path/to/key.pem"); + mockAuthFailure("Certificate error"); + vi.mocked(maybeAskUrl).mockResolvedValue(TEST_URL); + userInteraction.setResponse("Authentication Required", "Login"); + + const result = await coordinator.ensureLoggedInWithDialog( + dialogOptions("auth_required"), + ); + + expect(result).toEqual({ success: false, reason: "auth_failed" }); + const events = sink.eventsNamed("auth.login_prompt"); + expect(events).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + trigger: "auth_required", + result: "error", + outcome: "auth_failed", + }), + }), + ]); + expect(events[0].error).toBeUndefined(); + }); + + it("emits success + outcome on the happy path", async () => { + const sink = new TestSink(); + const { mockConfig, userInteraction, coordinator, mockSuccessfulAuth } = + createTestContext(createTestTelemetryService(sink)); + mockConfig.set("coder.tlsCertFile", "/path/to/cert.pem"); + mockConfig.set("coder.tlsKeyFile", "/path/to/key.pem"); + mockSuccessfulAuth(); + vi.mocked(maybeAskUrl).mockResolvedValue(TEST_URL); + userInteraction.setResponse("Authentication Required", "Login"); + + await coordinator.ensureLoggedInWithDialog( + dialogOptions("auth_required"), + ); + + expect(sink.eventsNamed("auth.login_prompt")).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + trigger: "auth_required", + result: "success", + outcome: "success", + }), + }), + ]); + }); + }); }); diff --git a/test/unit/oauth/sessionManager.test.ts b/test/unit/oauth/sessionManager.test.ts index dfaaeaf876..9f4785a05f 100644 --- a/test/unit/oauth/sessionManager.test.ts +++ b/test/unit/oauth/sessionManager.test.ts @@ -5,13 +5,13 @@ import { } from "axios"; import { describe, expect, it, vi } from "vitest"; -import { type SecretsManager, type SessionAuth } from "@/core/secretsManager"; +import { type SessionAuth } from "@/core/secretsManager"; import { DEFAULT_OAUTH_SCOPES } from "@/oauth/constants"; import { OAuthSessionManager } from "@/oauth/sessionManager"; import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { - type createMockLogger, + createMockServiceContainer, MockConfigurationProvider, setupAxiosMockRoutes, } from "../../mocks/testHelpers"; @@ -27,9 +27,8 @@ import { TEST_URL, } from "./testUtils"; -import type { ServiceContainer } from "@/core/container"; import type { Deployment } from "@/deployment/types"; -import type { TelemetryReporter } from "@/telemetry/reporter"; +import type { TelemetryService } from "@/telemetry/service"; vi.mock("axios", async () => { const actual = await vi.importActual("axios"); @@ -61,25 +60,17 @@ const REFRESH_BUFFER_MS = 5 * 60 * 1000; // Tokens refresh 5 minutes before expi const ONE_HOUR_MS = 60 * 60 * 1000; const BACKGROUND_REFRESH_INTERVAL_MS = 5 * 60 * 1000; -function createMockServiceContainer( - secretsManager: SecretsManager, - logger: ReturnType, -): ServiceContainer { - return { - getSecretsManager: () => secretsManager, - getLogger: () => logger, - } as ServiceContainer; -} - function createTestContext(deployment: Deployment = createTestDeployment()) { vi.resetAllMocks(); const base = createBaseTestContext(); - const container = createMockServiceContainer( - base.secretsManager, - base.logger, - ); - const manager = OAuthSessionManager.create(deployment, container); + const buildContainer = (telemetry?: TelemetryService) => + createMockServiceContainer({ + secretsManager: base.secretsManager, + logger: base.logger, + telemetry, + }); + const manager = OAuthSessionManager.create(deployment, buildContainer()); /** Sets up OAuth session auth */ const setupOAuthSession = async ( @@ -105,8 +96,8 @@ function createTestContext(deployment: Deployment = createTestDeployment()) { const createManager = ( d: Deployment = deployment, onAuthRequired: () => Promise = () => Promise.resolve(), - telemetry?: TelemetryReporter, - ) => OAuthSessionManager.create(d, container, onAuthRequired, telemetry); + telemetry?: TelemetryService, + ) => OAuthSessionManager.create(d, buildContainer(telemetry), onAuthRequired); /** * Sets up a complete OAuth operation test context. @@ -195,38 +186,6 @@ describe("OAuthSessionManager", () => { ); }); - it("emits telemetry for reactive refresh", async () => { - const { createManager, setupForOAuthOperation } = createTestContext(); - const sink = new TestSink(); - new MockConfigurationProvider().set("coder.telemetry.level", "local"); - const manager = createManager( - createTestDeployment(), - () => Promise.resolve(), - createTestTelemetryService(sink), - ); - - await setupForOAuthOperation({ - "/oauth2/token": createMockTokenResponse({ - access_token: "telemetry-token", - }), - }); - - await manager.refreshToken(); - - expect(sink.events).toContainEqual( - expect.objectContaining({ - eventName: "auth.token_refresh", - properties: expect.objectContaining({ - trigger: "reactive", - result: "success", - }), - measurements: expect.objectContaining({ - durationMs: expect.any(Number), - }), - }), - ); - }); - it("refreshes token successfully", async () => { const { secretsManager, mockAdapter, manager, setupOAuthSession } = createTestContext(); @@ -326,34 +285,6 @@ describe("OAuthSessionManager", () => { expect(auth?.token).toBe("background-refreshed-token"); }); - it("emits telemetry with background trigger", async () => { - const { createManager, setupForOAuthOperation } = createTestContext(); - const sink = new TestSink(); - new MockConfigurationProvider().set("coder.telemetry.level", "local"); - const manager = createManager( - createTestDeployment(), - () => Promise.resolve(), - createTestTelemetryService(sink), - ); - - await setupForOAuthOperation({ - "/oauth2/token": createMockTokenResponse({ - access_token: "background-token", - }), - }); - await manager.refreshToken("background"); - - expect(sink.events).toContainEqual( - expect.objectContaining({ - eventName: "auth.token_refresh", - properties: expect.objectContaining({ - trigger: "background", - result: "success", - }), - }), - ); - }); - it("calls onAuthRequired when refresh fails with re-auth error", async () => { const { createManager } = await setupBackgroundRefreshTest( createOAuthAxiosError("invalid_grant"), @@ -545,4 +476,42 @@ describe("OAuthSessionManager", () => { expect(result).toBe(true); }); }); + + describe("telemetry", () => { + const setupWithSink = async () => { + const sink = new TestSink(); + new MockConfigurationProvider().set("coder.telemetry.level", "local"); + const ctx = createTestContext(); + const manager = ctx.createManager( + createTestDeployment(), + () => Promise.resolve(), + createTestTelemetryService(sink), + ); + await ctx.setupForOAuthOperation({ + "/oauth2/token": createMockTokenResponse({ access_token: "new" }), + }); + return { manager, sink }; + }; + + it.each(["reactive", "background"] as const)( + "emits auth.token_refresh with trigger=%s", + async (trigger) => { + const { manager, sink } = await setupWithSink(); + + await manager.refreshToken(trigger); + + expect(sink.eventsNamed("auth.token_refresh")).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + trigger, + result: "success", + }), + measurements: expect.objectContaining({ + durationMs: expect.any(Number), + }), + }), + ]); + }, + ); + }); }); diff --git a/test/unit/remote/workspaceStateMachine.test.ts b/test/unit/remote/workspaceStateMachine.test.ts index 6a37499937..e59364137c 100644 --- a/test/unit/remote/workspaceStateMachine.test.ts +++ b/test/unit/remote/workspaceStateMachine.test.ts @@ -20,6 +20,7 @@ import { import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { createMockLogger, + createMockServiceContainer, MockConfigurationProvider, MockProgress, MockTerminalOutputChannel, @@ -34,7 +35,7 @@ import type { import type { CoderApi } from "@/api/coderApi"; import type { StartupMode } from "@/core/mementoManager"; import type { FeatureSet } from "@/featureSet"; -import type { TelemetryReporter } from "@/telemetry/reporter"; +import type { TelemetryService } from "@/telemetry/service"; import type { AuthorityParts } from "@/util"; vi.mock("@/api/workspace", async (importActual) => { @@ -82,7 +83,7 @@ function runningWorkspace( function setup( startupMode: StartupMode = "start", - telemetry?: TelemetryReporter, + telemetry?: TelemetryService, ) { new MockConfigurationProvider().set("coder.telemetry.level", "local"); const progress = new MockProgress<{ message?: string }>(); @@ -93,9 +94,8 @@ function setup( startupMode, "/usr/bin/coder", {} as FeatureSet, - createMockLogger(), { mode: "url", url: "https://test.coder.com" }, - telemetry, + createMockServiceContainer({ telemetry, logger: createMockLogger() }), ); return { sm, progress, userInteraction }; } @@ -379,27 +379,50 @@ describe("WorkspaceStateMachine", () => { }); describe("telemetry", () => { - it("emits update triggered telemetry with duration", async () => { - const sink = new TestSink(); - const { sm, progress } = setup( - "update", - createTestTelemetryService(sink), - ); - - await sm.processWorkspace(runningWorkspace(), progress); - - expect(sink.events).toContainEqual( - expect.objectContaining({ - eventName: "workspace.update.triggered", - properties: expect.objectContaining({ result: "success" }), - measurements: expect.objectContaining({ - durationMs: expect.any(Number), + const stoppedWorkspace = () => + createWorkspace({ latest_build: { status: "stopped" } }); + + it.each<{ + name: string; + eventName: "workspace.start.triggered" | "workspace.update.triggered"; + mode: StartupMode; + workspace: () => Workspace; + mock: typeof startWorkspace | typeof updateWorkspace; + }>([ + { + name: "workspace.start.triggered on stopped workspace", + eventName: "workspace.start.triggered", + mode: "start", + workspace: stoppedWorkspace, + mock: startWorkspace, + }, + { + name: "workspace.update.triggered on running workspace in update mode", + eventName: "workspace.update.triggered", + mode: "update", + workspace: runningWorkspace, + mock: updateWorkspace, + }, + ])( + "emits $name with duration on success", + async ({ eventName, mode, workspace }) => { + const sink = new TestSink(); + const { sm, progress } = setup(mode, createTestTelemetryService(sink)); + + await sm.processWorkspace(workspace(), progress); + + expect(sink.eventsNamed(eventName)).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ result: "success" }), + measurements: expect.objectContaining({ + durationMs: expect.any(Number), + }), }), - }), - ); - }); + ]); + }, + ); - it("emits error result when update fails", async () => { + it("emits result=error when the triggered action throws", async () => { const sink = new TestSink(); const { sm, progress } = setup( "update", @@ -413,16 +436,15 @@ describe("WorkspaceStateMachine", () => { // existing template version, so processWorkspace resolves. await sm.processWorkspace(runningWorkspace(), progress); - expect(sink.events).toContainEqual( + expect(sink.eventsNamed("workspace.update.triggered")).toEqual([ expect.objectContaining({ - eventName: "workspace.update.triggered", properties: expect.objectContaining({ result: "error" }), error: { message: "update failed" }, }), - ); + ]); }); - it("emits selected-agent state transitions with observed duration", async () => { + it("emits agent state transitions with observed duration", async () => { const sink = new TestSink(); const { sm, progress } = setup("start", createTestTelemetryService(sink)); @@ -432,29 +454,25 @@ describe("WorkspaceStateMachine", () => { ); await sm.processWorkspace(runningWorkspace(), progress); - const agentEvents = sink.events.filter( - (event) => event.eventName === "workspace.agent.state_transitioned", - ); - expect(agentEvents).toHaveLength(2); - expect(agentEvents[0]).toMatchObject({ - properties: { - agentName: "main", - fromStatus: "unknown", - toStatus: "connecting", - fromLifecycleState: "unknown", - toLifecycleState: "created", - }, - }); - expect(agentEvents[1]).toMatchObject({ - properties: { - agentName: "main", - fromStatus: "connecting", - toStatus: "connected", - fromLifecycleState: "created", - toLifecycleState: "ready", - }, - measurements: { observedDurationMs: expect.any(Number) }, - }); + expect(sink.eventsNamed("workspace.agent.state_transitioned")).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + fromStatus: "unknown", + toStatus: "connecting", + fromLifecycleState: "unknown", + toLifecycleState: "created", + }), + }), + expect.objectContaining({ + properties: expect.objectContaining({ + fromStatus: "connecting", + toStatus: "connected", + fromLifecycleState: "created", + toLifecycleState: "ready", + }), + measurements: { observedDurationMs: expect.any(Number) }, + }), + ]); }); }); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index 97a030777f..7e14210f6f 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -352,6 +352,45 @@ describe("TelemetryService", () => { }); }); + it("markFailure flips result to 'error' on normal return without an error block", async () => { + await h.service.trace("op", (span) => { + span.markFailure(); + return Promise.resolve(); + }); + + expect(h.sink.events[0]).toMatchObject({ + eventName: "op", + properties: { result: "error" }, + }); + expect(h.sink.events[0].error).toBeUndefined(); + }); + + it("markFailure overrides markAborted (failure wins over abort)", async () => { + await h.service.trace("op", (span) => { + span.markAborted(); + span.markFailure(); + return Promise.resolve(); + }); + + expect(h.sink.events[0].properties.result).toBe("error"); + }); + + it("thrown errors take precedence over markFailure (error block is preserved)", async () => { + const boom = new Error("kaboom"); + await expect( + h.service.trace("op", (span) => { + span.markFailure(); + return Promise.reject(boom); + }), + ).rejects.toBe(boom); + + expect(h.sink.events[0]).toMatchObject({ + eventName: "op", + properties: { result: "error" }, + error: { message: "kaboom" }, + }); + }); + it("on phase failure: completed phases emit success, parent emits an error summary, error rethrown, later phases never run", async () => { const boom = new Error("phase-2-broke"); diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index 7098646e4b..f8417f0f97 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -7,6 +7,7 @@ import { workspace as createWorkspace } from "@repo/mocks"; import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { + createMockServiceContainer, MockConfigurationProvider, MockContextManager, MockEventStream, @@ -20,8 +21,7 @@ import type { } from "coder/site/src/api/typesGenerated"; import type { CoderApi } from "@/api/coderApi"; -import type { ContextManager } from "@/core/contextManager"; -import type { TelemetryReporter } from "@/telemetry/reporter"; +import type { TelemetryService } from "@/telemetry/service"; function workspaceEvent( overrides?: Parameters[0], @@ -40,7 +40,7 @@ describe("WorkspaceMonitor", () => { async function setup( stream = new MockEventStream(), - telemetry?: TelemetryReporter, + telemetry?: TelemetryService, initialWorkspace: Workspace = createWorkspace(), ) { const config = new MockConfigurationProvider(); @@ -58,18 +58,25 @@ describe("WorkspaceMonitor", () => { const monitor = await WorkspaceMonitor.create( initialWorkspace, client, - createMockLogger(), - contextManager as unknown as ContextManager, - telemetry, + createMockServiceContainer({ + telemetry, + logger: createMockLogger(), + contextManager, + }), ); return { monitor, client, stream, config, statusBar, contextManager }; } describe("telemetry", () => { - it("emits initial workspace state and observed transitions", async () => { + const buildSinkContext = () => { const stream = new MockEventStream(); const sink = new TestSink(); new MockConfigurationProvider().set("coder.telemetry.level", "local"); + return { stream, sink }; + }; + + it("emits initial state plus subsequent transitions with duration", async () => { + const { stream, sink } = buildSinkContext(); await setup( stream, @@ -86,15 +93,11 @@ describe("WorkspaceMonitor", () => { }), ); - const events = sink.events.filter( - (event) => event.eventName === "workspace.state_transitioned", - ); + const events = sink.eventsNamed("workspace.state_transitioned"); expect(events).toHaveLength(2); - expect(events[0]).toMatchObject({ - properties: { - from: "unknown", - to: "running", - }, + expect(events[0].properties).toMatchObject({ + from: "unknown", + to: "running", }); expect(events[0].measurements.observedDurationMs).toBeUndefined(); expect(events[1]).toMatchObject({ @@ -107,6 +110,82 @@ describe("WorkspaceMonitor", () => { measurements: { observedDurationMs: expect.any(Number) }, }); }); + + it("dedupes on (status, transition, reason); re-emits when only reason changes", async () => { + const { stream, sink } = buildSinkContext(); + + await setup( + stream, + createTestTelemetryService(sink), + createWorkspace({ + latest_build: { + status: "stopping", + transition: "stop", + reason: "autostop", + }, + }), + ); + // Same status with a different reason: must not dedupe. + stream.pushMessage( + workspaceEvent({ + latest_build: { + status: "stopping", + transition: "stop", + reason: "initiator", + }, + }), + ); + // Identical to the previous: deduped. + stream.pushMessage( + workspaceEvent({ + latest_build: { + status: "stopping", + transition: "stop", + reason: "initiator", + }, + }), + ); + + const reasons = sink + .eventsNamed("workspace.state_transitioned") + .map((e) => e.properties.reason); + expect(reasons).toEqual(["autostop", "initiator"]); + }); + + it("emits buildDurationMs on the event that resolves a build run", async () => { + const { stream, sink } = buildSinkContext(); + + await setup( + stream, + createTestTelemetryService(sink), + createWorkspace({ latest_build: { status: "pending" } }), + ); + stream.pushMessage( + workspaceEvent({ latest_build: { status: "starting" } }), + ); + stream.pushMessage( + workspaceEvent({ latest_build: { status: "running" } }), + ); + stream.pushMessage( + workspaceEvent({ latest_build: { status: "stopping" } }), + ); + + const events = sink.eventsNamed("workspace.state_transitioned"); + // pending and starting are intermediate; only running carries buildDurationMs. + expect(events.map((e) => e.properties.to)).toEqual([ + "pending", + "starting", + "running", + "stopping", + ]); + expect(events[0].measurements.buildDurationMs).toBeUndefined(); + expect(events[1].measurements.buildDurationMs).toBeUndefined(); + expect(events[2].measurements.buildDurationMs).toEqual( + expect.any(Number), + ); + // Next build cycle resets; stopping doesn't carry the previous duration. + expect(events[3].measurements.buildDurationMs).toBeUndefined(); + }); }); describe("websocket lifecycle", () => { From 1393c0864b75ac9358c8fda7aa04fdc4ae2fa57f Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Wed, 13 May 2026 17:44:44 +0300 Subject: [PATCH 6/9] refactor(telemetry): self-review polish - Align auth event names with the past-tense convention used by the rest of the codebase: auth.token_refresh -> auth.token_refreshed, auth.intercept_401 -> auth.unauthorized_intercepted, auth.login_prompt -> auth.login_prompted. - Replace the redundant `outcome` property on auth.login_prompted with `reason`, only emitted on non-success (`result` already covers the success/aborted/error axis). - Collapse LoginPromptAbortReason + LoginPromptFailureReason into a single LoginPromptReason; tighten ObservedWorkspaceState now that transition/reason are non-nullable in the API types. - Drop the dead `?? undefined` and conditional spreads in observeWorkspace; fold buildStartedAtMs updates into the same branch that produces buildDurationMs. - Type BUILDING_STATUSES as ReadonlySet. - Reuse createMockServiceContainer in deploymentManager.test.ts and drop a non-deterministic 30ms sleep in sshProcess.test.ts. --- src/api/authInterceptor.ts | 12 ++--- src/instrumentation/auth.ts | 48 +++++++++---------- src/instrumentation/workspace.ts | 37 +++++++------- src/login/loginCoordinator.ts | 8 +--- test/unit/api/authInterceptor.test.ts | 4 +- .../unit/deployment/deploymentManager.test.ts | 19 ++++---- test/unit/login/loginCoordinator.test.ts | 29 +++++------ test/unit/oauth/sessionManager.test.ts | 4 +- test/unit/remote/sshProcess.test.ts | 9 ++-- test/unit/telemetry/service.test.ts | 2 +- 10 files changed, 75 insertions(+), 97 deletions(-) diff --git a/src/api/authInterceptor.ts b/src/api/authInterceptor.ts index 08e0e55ef7..abc6c8befb 100644 --- a/src/api/authInterceptor.ts +++ b/src/api/authInterceptor.ts @@ -78,19 +78,15 @@ export class AuthInterceptor implements vscode.Disposable { return this.handle401Error(error, hostname); } - /** - * `auth.intercept_401` wraps recovery + retry, so the span emits after the - * retry resolves; the receive-time is `timestamp - durationMs`. - * - * TODO(#925): once `Span.log()` lands, emit a correlated `auth.intercept_401.received` - * log here at decision time so analytics can see the receive moment - * directly without back-computing. - */ private handle401Error( error: AxiosError, hostname: string, ): Promise { this.logger.debug("Received 401 response, attempting recovery"); + // TODO(#925): when Span.log() lands, emit a correlated + // `auth.unauthorized_intercepted.received` log at decision time so + // analytics can see the receive moment without back-computing from + // `timestamp - durationMs`. return this.authTelemetry.traceIntercept401(async (setRecovery) => { const newToken = (await this.oauthSessionManager.isLoggedInWithOAuth( hostname, diff --git a/src/instrumentation/auth.ts b/src/instrumentation/auth.ts index a5053f2df7..a0a7217005 100644 --- a/src/instrumentation/auth.ts +++ b/src/instrumentation/auth.ts @@ -7,18 +7,18 @@ export type AuthIntercept401Recovery = | "none"; export type AuthLoginPromptTrigger = "auth_required" | "missing_session"; -/** User-initiated reasons a login prompt ended without success. */ -export type LoginPromptAbortReason = "user_dismissed" | "no_url_provided"; -/** Non-user-initiated reasons a login prompt ended without success. */ -export type LoginPromptFailureReason = "auth_failed"; +/** + * Why a login prompt ended without a session. `auth_failed` indicates + * authentication itself failed; the others are user-driven aborts. + */ +export type LoginPromptReason = + | "user_dismissed" + | "no_url_provided" + | "auth_failed"; -/** Minimum shape `traceLoginPrompt` needs to classify a prompt outcome. */ export type LoginPromptOutcome = | { success: true } - | { - success: false; - reason: LoginPromptAbortReason | LoginPromptFailureReason; - }; + | { success: false; reason: LoginPromptReason }; export class AuthTelemetry { public constructor(private readonly telemetry: TelemetryReporter) {} @@ -27,42 +27,40 @@ export class AuthTelemetry { trigger: AuthTokenRefreshTrigger, fn: () => Promise, ): Promise { - return this.telemetry.trace("auth.token_refresh", fn, { trigger }); + return this.telemetry.trace("auth.token_refreshed", fn, { trigger }); } - /** Wrap a 401 recovery; `setRecovery` records the outcome on the span. */ + /** Wraps the recovery+retry path for a 401; `setRecovery` records how it was handled. */ public traceIntercept401( fn: ( setRecovery: (recovery: AuthIntercept401Recovery) => void, ) => Promise, ): Promise { - return this.telemetry.trace("auth.intercept_401", (span) => + return this.telemetry.trace("auth.unauthorized_intercepted", (span) => fn((recovery) => span.setProperty("recovery", recovery)), ); } /** - * Record `auth.login_prompt`. The returned `LoginPromptOutcome` drives - * the span: success stays `success`, `auth_failed` maps to `markFailure`, - * any other reason maps to `markAborted`. The reason is always copied to - * the `outcome` property. + * Records `auth.login_prompted`. `auth_failed` marks the span as failure; + * other non-success reasons mark it as aborted. The reason is copied to the + * span's `reason` property on failure/abort only. */ public traceLoginPrompt( trigger: AuthLoginPromptTrigger, fn: () => Promise, ): Promise { return this.telemetry.trace( - "auth.login_prompt", + "auth.login_prompted", async (span) => { const result = await fn(); - if (result.success) { - span.setProperty("outcome", "success"); - } else if (result.reason === "auth_failed") { - span.setProperty("outcome", result.reason); - span.markFailure(); - } else { - span.setProperty("outcome", result.reason); - span.markAborted(); + if (!result.success) { + span.setProperty("reason", result.reason); + if (result.reason === "auth_failed") { + span.markFailure(); + } else { + span.markAborted(); + } } return result; }, diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts index 6e8e7f1909..bb100902fd 100644 --- a/src/instrumentation/workspace.ts +++ b/src/instrumentation/workspace.ts @@ -11,7 +11,7 @@ import type { TelemetryReporter } from "../telemetry/reporter"; const INITIAL_STATE = "unknown"; -const BUILDING_STATUSES = new Set([ +const BUILDING_STATUSES: ReadonlySet = new Set([ "pending", "starting", "stopping", @@ -19,8 +19,8 @@ const BUILDING_STATUSES = new Set([ interface ObservedWorkspaceState { readonly status: WorkspaceStatus; - readonly transition: WorkspaceBuild["transition"] | undefined; - readonly reason: WorkspaceBuild["reason"] | undefined; + readonly transition: WorkspaceBuild["transition"]; + readonly reason: WorkspaceBuild["reason"]; readonly observedAtMs: number; } @@ -39,9 +39,7 @@ export class WorkspaceTelemetry { public constructor(private readonly telemetry: TelemetryReporter) {} public observeWorkspace(workspace: Workspace): void { - const status = workspace.latest_build.status; - const transition = workspace.latest_build.transition ?? undefined; - const reason = workspace.latest_build.reason ?? undefined; + const { status, transition, reason } = workspace.latest_build; const previous = this.observedWorkspaceState; if ( previous?.status === status && @@ -50,17 +48,21 @@ export class WorkspaceTelemetry { ) { return; } + const now = performance.now(); + const measurements: Record = previous + ? { observedDurationMs: now - previous.observedAtMs } + : {}; const wasBuilding = previous && BUILDING_STATUSES.has(previous.status); const isBuilding = BUILDING_STATUSES.has(status); - - const measurements: Record = {}; - if (previous) { - measurements.observedDurationMs = now - previous.observedAtMs; - } - if (wasBuilding && !isBuilding && this.buildStartedAtMs !== undefined) { - measurements.buildDurationMs = now - this.buildStartedAtMs; + if (isBuilding) { + this.buildStartedAtMs ??= now; + } else { + if (wasBuilding && this.buildStartedAtMs !== undefined) { + measurements.buildDurationMs = now - this.buildStartedAtMs; + } + this.buildStartedAtMs = undefined; } this.telemetry.log( @@ -68,8 +70,8 @@ export class WorkspaceTelemetry { { from: previous?.status ?? INITIAL_STATE, to: status, - ...(transition && { transition }), - ...(reason && { reason }), + transition, + reason, }, measurements, ); @@ -79,11 +81,6 @@ export class WorkspaceTelemetry { reason, observedAtMs: now, }; - if (isBuilding) { - this.buildStartedAtMs ??= now; - } else { - this.buildStartedAtMs = undefined; - } } public observeAgent(agent: WorkspaceAgent): void { diff --git a/src/login/loginCoordinator.ts b/src/login/loginCoordinator.ts index 0dadb3de9e..c36c6f6938 100644 --- a/src/login/loginCoordinator.ts +++ b/src/login/loginCoordinator.ts @@ -8,8 +8,7 @@ import { CertificateError } from "../error/certificateError"; import { AuthTelemetry, type AuthLoginPromptTrigger, - type LoginPromptAbortReason, - type LoginPromptFailureReason, + type LoginPromptReason, } from "../instrumentation/auth"; import { OAuthAuthorizer } from "../oauth/authorizer"; import { buildOAuthTokenData } from "../oauth/utils"; @@ -29,10 +28,7 @@ import type { Logger } from "../logging/logger"; import type { OAuthCallback } from "../oauth/oauthCallback"; type LoginResult = - | { - success: false; - reason: LoginPromptAbortReason | LoginPromptFailureReason; - } + | { success: false; reason: LoginPromptReason } | { success: true; user: User; token: string; oauth?: OAuthTokenData }; export interface LoginOptions { diff --git a/test/unit/api/authInterceptor.test.ts b/test/unit/api/authInterceptor.test.ts index b4bec302ad..42fdcb2b44 100644 --- a/test/unit/api/authInterceptor.test.ts +++ b/test/unit/api/authInterceptor.test.ts @@ -452,7 +452,7 @@ describe("AuthInterceptor", () => { createAxiosError(401, "Unauthorized"), ); - expect(sink.eventsNamed("auth.intercept_401")).toEqual([ + expect(sink.eventsNamed("auth.unauthorized_intercepted")).toEqual([ expect.objectContaining({ properties: expect.objectContaining({ recovery: "refresh_success", @@ -475,7 +475,7 @@ describe("AuthInterceptor", () => { axiosInstance.triggerResponseError(createAxiosError(401, "denied")), ).rejects.toThrow(); - expect(sink.eventsNamed("auth.intercept_401")).toEqual([ + expect(sink.eventsNamed("auth.unauthorized_intercepted")).toEqual([ expect.objectContaining({ properties: expect.objectContaining({ recovery: "login_required", diff --git a/test/unit/deployment/deploymentManager.test.ts b/test/unit/deployment/deploymentManager.test.ts index 87b4872e2e..5ece0f365f 100644 --- a/test/unit/deployment/deploymentManager.test.ts +++ b/test/unit/deployment/deploymentManager.test.ts @@ -7,6 +7,7 @@ import { DeploymentManager } from "@/deployment/deploymentManager"; import { createMockLogger, + createMockServiceContainer, createMockUser, InMemoryMemento, InMemorySecretStorage, @@ -15,8 +16,6 @@ import { MockOAuthSessionManager, } from "../../mocks/testHelpers"; -import type { ServiceContainer } from "@/core/container"; -import type { ContextManager } from "@/core/contextManager"; import type { OAuthSessionManager } from "@/oauth/sessionManager"; import type { WorkspaceProvider } from "@/workspace/workspacesProvider"; @@ -70,16 +69,14 @@ function createTestContext() { setDeploymentUrl: vi.fn(), }; - const container = { - getSecretsManager: () => secretsManager, - getMementoManager: () => mementoManager, - getContextManager: () => contextManager as unknown as ContextManager, - getLogger: () => logger, - getTelemetryService: () => telemetryService, - }; - const manager = DeploymentManager.create( - container as unknown as ServiceContainer, + createMockServiceContainer({ + telemetry: telemetryService as unknown as TelemetryService, + logger, + secretsManager, + mementoManager, + contextManager, + }), mockClient as unknown as CoderApi, mockOAuthSessionManager as unknown as OAuthSessionManager, [mockWorkspaceProvider as unknown as WorkspaceProvider], diff --git a/test/unit/login/loginCoordinator.test.ts b/test/unit/login/loginCoordinator.test.ts index 8db03ccfc4..1d827a75a7 100644 --- a/test/unit/login/loginCoordinator.test.ts +++ b/test/unit/login/loginCoordinator.test.ts @@ -545,7 +545,7 @@ describe("LoginCoordinator", () => { trigger, }); - it("emits aborted + outcome when the user dismisses the dialog", async () => { + it("emits result=aborted with reason when the user dismisses the dialog", async () => { const sink = new TestSink(); const { userInteraction, coordinator } = createTestContext( createTestTelemetryService(sink), @@ -556,12 +556,12 @@ describe("LoginCoordinator", () => { dialogOptions("missing_session"), ); - expect(sink.eventsNamed("auth.login_prompt")).toEqual([ + expect(sink.eventsNamed("auth.login_prompted")).toEqual([ expect.objectContaining({ properties: expect.objectContaining({ trigger: "missing_session", result: "aborted", - outcome: "user_dismissed", + reason: "user_dismissed", }), measurements: expect.objectContaining({ durationMs: expect.any(Number), @@ -570,7 +570,7 @@ describe("LoginCoordinator", () => { ]); }); - it("emits result=error (no error block) + outcome when authentication itself fails", async () => { + it("emits result=error with reason (and no error block) when authentication fails", async () => { const sink = new TestSink(); const { mockConfig, userInteraction, coordinator, mockAuthFailure } = createTestContext(createTestTelemetryService(sink)); @@ -585,20 +585,20 @@ describe("LoginCoordinator", () => { ); expect(result).toEqual({ success: false, reason: "auth_failed" }); - const events = sink.eventsNamed("auth.login_prompt"); + const events = sink.eventsNamed("auth.login_prompted"); expect(events).toEqual([ expect.objectContaining({ properties: expect.objectContaining({ trigger: "auth_required", result: "error", - outcome: "auth_failed", + reason: "auth_failed", }), }), ]); expect(events[0].error).toBeUndefined(); }); - it("emits success + outcome on the happy path", async () => { + it("emits result=success without a reason on the happy path", async () => { const sink = new TestSink(); const { mockConfig, userInteraction, coordinator, mockSuccessfulAuth } = createTestContext(createTestTelemetryService(sink)); @@ -612,15 +612,12 @@ describe("LoginCoordinator", () => { dialogOptions("auth_required"), ); - expect(sink.eventsNamed("auth.login_prompt")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - trigger: "auth_required", - result: "success", - outcome: "success", - }), - }), - ]); + const [event] = sink.eventsNamed("auth.login_prompted"); + expect(event.properties).toMatchObject({ + trigger: "auth_required", + result: "success", + }); + expect(event.properties.reason).toBeUndefined(); }); }); }); diff --git a/test/unit/oauth/sessionManager.test.ts b/test/unit/oauth/sessionManager.test.ts index 9f4785a05f..492263c55c 100644 --- a/test/unit/oauth/sessionManager.test.ts +++ b/test/unit/oauth/sessionManager.test.ts @@ -494,13 +494,13 @@ describe("OAuthSessionManager", () => { }; it.each(["reactive", "background"] as const)( - "emits auth.token_refresh with trigger=%s", + "emits auth.token_refreshed with trigger=%s", async (trigger) => { const { manager, sink } = await setupWithSink(); await manager.refreshToken(trigger); - expect(sink.eventsNamed("auth.token_refresh")).toEqual([ + expect(sink.eventsNamed("auth.token_refreshed")).toEqual([ expect.objectContaining({ properties: expect.objectContaining({ trigger, diff --git a/test/unit/remote/sshProcess.test.ts b/test/unit/remote/sshProcess.test.ts index 5c33612d6a..293b7e3d7a 100644 --- a/test/unit/remote/sshProcess.test.ts +++ b/test/unit/remote/sshProcess.test.ts @@ -346,15 +346,12 @@ describe("SshProcessMonitor", () => { it("emits found=false when discovery is abandoned by dispose", async () => { const sink = new TestSink(); const telemetry = createTestTelemetryService(sink); - vol.fromJSON({ - "/logs/ms-vscode-remote.remote-ssh/1-Remote - SSH.log": - "-> socksPort 12345 ->", - }); + vol.fromJSON(sshLog); vi.mocked(find).mockResolvedValue([]); const monitor = createMonitor({ telemetry }); - // Allow at least one discovery iteration to start, then abandon it. - await new Promise((r) => setTimeout(r, 30)); + // `find` always returns []; dispose ends the polling loop and + // finalises the span with `found: false`. monitor.dispose(); await waitFor( diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index 7e14210f6f..eb027f65c5 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -125,7 +125,7 @@ describe("TelemetryService", () => { it("forwards caller measurements alongside the framework-set durationMs", async () => { await h.service.trace( - "auth.token_refresh", + "auth.token_refreshed", () => Promise.resolve(), {}, { attempts: 2 }, From f3b287c8c9cc7770d80cae0b1960e641a804e898 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Thu, 14 May 2026 00:15:29 +0300 Subject: [PATCH 7/9] refactor(telemetry): address PR review - workspace.ts: split WorkspaceTelemetry into three single-purpose classes in the same file so each call site only holds the surface it uses, eliminating the duplicate-event trap by construction: - WorkspaceStateTelemetry (observe) for WorkspaceMonitor - WorkspaceAgentTelemetry (observe/reset) for WorkspaceStateMachine - WorkspaceOperationTelemetry (traceStartTriggered/traceUpdateTriggered) for WorkspaceStateMachine - workspace.ts: add canceling/deleting to the provisioner-active set (renamed BUILDING_STATUSES -> PROVISIONING_STATUSES). Take workspaceName via constructors and stamp it on every emission. - workspace.ts: unify workspace and agent state events on fromStatus/toStatus (agent additionally carries fromLifecycleState/toLifecycleState for its second dimension). - auth.ts: drop the "401" baggage from API names. traceIntercept401 -> traceAuthRecovery, Intercept401Recorder -> AuthRecoveryRecorder, AuthIntercept401Recovery -> AuthRecoveryOutcome, handle401Error -> recoverFromUnauthorized. The 401 stays in the event name `auth.unauthorized_intercepted` and at the call site. - auth.ts: traceAuthRecovery sets recovery="none" and refreshAttempted="false" as initial properties so a pre-callback throw still emits values; AuthInterceptor records refreshAttempted before tryOAuthRefresh. - auth.ts + sessionManager.ts: add auth.token_refresh.deduped so reactive refreshes that join an in-flight background refresh stay countable. - testHelpers: type contextManager via a local ContextManagerLike shape and replace non-null assertions with a require() helper so missing services throw a named error. - Add a recovery=none telemetry test; assert on the previously unused mock field in the workspaceStateMachine it.each. --- src/api/authInterceptor.ts | 26 +++-- src/instrumentation/auth.ts | 38 +++++--- src/instrumentation/workspace.ts | 95 ++++++++++++------- src/oauth/sessionManager.ts | 1 + src/remote/workspaceStateMachine.ts | 25 +++-- src/workspace/workspaceMonitor.ts | 11 ++- test/mocks/testHelpers.ts | 36 +++++-- test/unit/api/authInterceptor.test.ts | 21 ++++ .../unit/deployment/deploymentManager.test.ts | 1 + .../unit/remote/workspaceStateMachine.test.ts | 3 +- 10 files changed, 177 insertions(+), 80 deletions(-) diff --git a/src/api/authInterceptor.ts b/src/api/authInterceptor.ts index abc6c8befb..aef5753a7a 100644 --- a/src/api/authInterceptor.ts +++ b/src/api/authInterceptor.ts @@ -75,29 +75,25 @@ export class AuthInterceptor implements vscode.Disposable { } const hostname = toSafeHost(baseUrl); - return this.handle401Error(error, hostname); + return this.recoverFromUnauthorized(error, hostname); } - private handle401Error( + private recoverFromUnauthorized( error: AxiosError, hostname: string, ): Promise { this.logger.debug("Received 401 response, attempting recovery"); - // TODO(#925): when Span.log() lands, emit a correlated - // `auth.unauthorized_intercepted.received` log at decision time so - // analytics can see the receive moment without back-computing from - // `timestamp - durationMs`. - return this.authTelemetry.traceIntercept401(async (setRecovery) => { - const newToken = (await this.oauthSessionManager.isLoggedInWithOAuth( - hostname, - )) - ? await this.tryOAuthRefresh() - : undefined; + // TODO(#925): emit a correlated received-log here once Span.log() lands. + return this.authTelemetry.traceAuthRecovery(async (recorder) => { + const isOAuth = + await this.oauthSessionManager.isLoggedInWithOAuth(hostname); + recorder.setRefreshAttempted(isOAuth); + const newToken = isOAuth ? await this.tryOAuthRefresh() : undefined; if (newToken) { - setRecovery("refresh_success"); + recorder.setRecovery("refresh_success"); return this.retryRequest(error, newToken); } else if (this.onAuthRequired) { - setRecovery("login_required"); + recorder.setRecovery("login_required"); const success = await this.executeAuthRequired(hostname); const auth = success ? await this.secretsManager.getSessionAuth(hostname) @@ -108,7 +104,7 @@ export class AuthInterceptor implements vscode.Disposable { } throw error; } else { - setRecovery("none"); + recorder.setRecovery("none"); throw error; } }); diff --git a/src/instrumentation/auth.ts b/src/instrumentation/auth.ts index a0a7217005..7a053b792b 100644 --- a/src/instrumentation/auth.ts +++ b/src/instrumentation/auth.ts @@ -1,10 +1,7 @@ import type { TelemetryReporter } from "../telemetry/reporter"; export type AuthTokenRefreshTrigger = "background" | "reactive"; -export type AuthIntercept401Recovery = - | "refresh_success" - | "login_required" - | "none"; +export type AuthRecoveryOutcome = "refresh_success" | "login_required" | "none"; export type AuthLoginPromptTrigger = "auth_required" | "missing_session"; /** @@ -20,6 +17,12 @@ export type LoginPromptOutcome = | { success: true } | { success: false; reason: LoginPromptReason }; +/** Span annotator for the auth-recovery flow. Defaults to safe values. */ +export interface AuthRecoveryRecorder { + setRecovery(recovery: AuthRecoveryOutcome): void; + setRefreshAttempted(attempted: boolean): void; +} + export class AuthTelemetry { public constructor(private readonly telemetry: TelemetryReporter) {} @@ -30,14 +33,27 @@ export class AuthTelemetry { return this.telemetry.trace("auth.token_refreshed", fn, { trigger }); } - /** Wraps the recovery+retry path for a 401; `setRecovery` records how it was handled. */ - public traceIntercept401( - fn: ( - setRecovery: (recovery: AuthIntercept401Recovery) => void, - ) => Promise, + /** Logged when a refresh call joins an in-flight refresh and emits no span of its own. */ + public tokenRefreshDeduped(trigger: AuthTokenRefreshTrigger): void { + this.telemetry.log("auth.token_refresh.deduped", { trigger }); + } + + /** + * Wraps the auth-recovery path triggered by a 401. Initial properties + * cover the throw-before-callback case. + */ + public traceAuthRecovery( + fn: (recorder: AuthRecoveryRecorder) => Promise, ): Promise { - return this.telemetry.trace("auth.unauthorized_intercepted", (span) => - fn((recovery) => span.setProperty("recovery", recovery)), + return this.telemetry.trace( + "auth.unauthorized_intercepted", + (span) => + fn({ + setRecovery: (recovery) => span.setProperty("recovery", recovery), + setRefreshAttempted: (attempted) => + span.setProperty("refreshAttempted", String(attempted)), + }), + { recovery: "none", refreshAttempted: "false" }, ); } diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts index bb100902fd..ae68393d55 100644 --- a/src/instrumentation/workspace.ts +++ b/src/instrumentation/workspace.ts @@ -11,10 +11,13 @@ import type { TelemetryReporter } from "../telemetry/reporter"; const INITIAL_STATE = "unknown"; -const BUILDING_STATUSES: ReadonlySet = new Set([ +/** Statuses where a provisioner job is actively running. */ +const PROVISIONING_STATUSES: ReadonlySet = new Set([ "pending", "starting", "stopping", + "canceling", + "deleting", ]); interface ObservedWorkspaceState { @@ -30,17 +33,24 @@ interface ObservedAgentState { readonly observedAtMs: number; } -export class WorkspaceTelemetry { - private observedWorkspaceState: ObservedWorkspaceState | undefined; - private observedAgentState: ObservedAgentState | undefined; - /** Set on first observation of a building status; cleared when the build resolves. */ +/** + * Emits `workspace.state_transitioned` as a workspace progresses through + * statuses, plus `buildDurationMs` when a provisioner run resolves. + * Construct one per workspace; `WorkspaceMonitor` is the sole call site. + */ +export class WorkspaceStateTelemetry { + private observed: ObservedWorkspaceState | undefined; + /** Set on first observation of a provisioning status; cleared when the build resolves. */ private buildStartedAtMs: number | undefined; - public constructor(private readonly telemetry: TelemetryReporter) {} + public constructor( + private readonly telemetry: TelemetryReporter, + private readonly workspaceName: string, + ) {} - public observeWorkspace(workspace: Workspace): void { + public observe(workspace: Workspace): void { const { status, transition, reason } = workspace.latest_build; - const previous = this.observedWorkspaceState; + const previous = this.observed; if ( previous?.status === status && previous.transition === transition && @@ -54,12 +64,13 @@ export class WorkspaceTelemetry { ? { observedDurationMs: now - previous.observedAtMs } : {}; - const wasBuilding = previous && BUILDING_STATUSES.has(previous.status); - const isBuilding = BUILDING_STATUSES.has(status); - if (isBuilding) { + const wasProvisioning = + previous && PROVISIONING_STATUSES.has(previous.status); + const isProvisioning = PROVISIONING_STATUSES.has(status); + if (isProvisioning) { this.buildStartedAtMs ??= now; } else { - if (wasBuilding && this.buildStartedAtMs !== undefined) { + if (wasProvisioning && this.buildStartedAtMs !== undefined) { measurements.buildDurationMs = now - this.buildStartedAtMs; } this.buildStartedAtMs = undefined; @@ -68,6 +79,7 @@ export class WorkspaceTelemetry { this.telemetry.log( "workspace.state_transitioned", { + workspaceName: this.workspaceName, from: previous?.status ?? INITIAL_STATE, to: status, transition, @@ -75,16 +87,26 @@ export class WorkspaceTelemetry { }, measurements, ); - this.observedWorkspaceState = { - status, - transition, - reason, - observedAtMs: now, - }; + this.observed = { status, transition, reason, observedAtMs: now }; } +} - public observeAgent(agent: WorkspaceAgent): void { - const previous = this.observedAgentState; +/** + * Emits `workspace.agent.state_transitioned` as the agent's `status` and + * `lifecycle_state` change. The agent has two state dimensions so the event + * carries qualified `fromStatus`/`toStatus` and `fromLifecycleState`/ + * `toLifecycleState` properties. Construct one per workspace. + */ +export class WorkspaceAgentTelemetry { + private observed: ObservedAgentState | undefined; + + public constructor( + private readonly telemetry: TelemetryReporter, + private readonly workspaceName: string, + ) {} + + public observe(agent: WorkspaceAgent): void { + const previous = this.observed; if ( previous?.status === agent.status && previous.lifecycleState === agent.lifecycle_state @@ -93,9 +115,11 @@ export class WorkspaceTelemetry { } const now = performance.now(); + // Flat camelCase matches the codebase; switch to dot-namespaced grouping (from.status, from.lifecycleState, ...) if a third state dimension lands. this.telemetry.log( "workspace.agent.state_transitioned", { + workspaceName: this.workspaceName, agentName: agent.name, fromStatus: previous?.status ?? INITIAL_STATE, toStatus: agent.status, @@ -104,32 +128,37 @@ export class WorkspaceTelemetry { }, previous ? { observedDurationMs: now - previous.observedAtMs } : {}, ); - this.observedAgentState = { + this.observed = { status: agent.status, lifecycleState: agent.lifecycle_state, observedAtMs: now, }; } - public resetAgent(): void { - this.observedAgentState = undefined; + public reset(): void { + this.observed = undefined; } +} - public traceUpdateTriggered( - workspaceName: string, - fn: () => Promise, - ): Promise { +/** + * Wraps user-initiated workspace operations (start, update) as traced spans. + * Stateless; safe to construct per call site. + */ +export class WorkspaceOperationTelemetry { + public constructor( + private readonly telemetry: TelemetryReporter, + private readonly workspaceName: string, + ) {} + + public traceUpdateTriggered(fn: () => Promise): Promise { return this.telemetry.trace("workspace.update.triggered", fn, { - workspaceName, + workspaceName: this.workspaceName, }); } - public traceStartTriggered( - workspaceName: string, - fn: () => Promise, - ): Promise { + public traceStartTriggered(fn: () => Promise): Promise { return this.telemetry.trace("workspace.start.triggered", fn, { - workspaceName, + workspaceName: this.workspaceName, }); } } diff --git a/src/oauth/sessionManager.ts b/src/oauth/sessionManager.ts index 609e71ed87..a0968915f4 100644 --- a/src/oauth/sessionManager.ts +++ b/src/oauth/sessionManager.ts @@ -355,6 +355,7 @@ export class OAuthSessionManager implements vscode.Disposable { this.logger.debug( "Token refresh already in progress, waiting for result", ); + this.authTelemetry.tokenRefreshDeduped(trigger); return this.refreshPromise; } diff --git a/src/remote/workspaceStateMachine.ts b/src/remote/workspaceStateMachine.ts index a1987e67c3..62c537bdab 100644 --- a/src/remote/workspaceStateMachine.ts +++ b/src/remote/workspaceStateMachine.ts @@ -13,7 +13,10 @@ import { streamAgentLogs, streamBuildLogs, } from "../api/workspace"; -import { WorkspaceTelemetry } from "../instrumentation/workspace"; +import { + WorkspaceAgentTelemetry, + WorkspaceOperationTelemetry, +} from "../instrumentation/workspace"; import { maybeAskAgent } from "../promptUtils"; import { vscodeProposed } from "../vscodeProposed"; @@ -41,7 +44,8 @@ export class WorkspaceStateMachine implements vscode.Disposable { private readonly terminal: TerminalOutputChannel; private readonly buildLogStream = new LazyStream(); private readonly agentLogStream = new LazyStream(); - private readonly telemetry: WorkspaceTelemetry; + private readonly agentTelemetry: WorkspaceAgentTelemetry; + private readonly operationTelemetry: WorkspaceOperationTelemetry; private agent: { id: string; name: string } | undefined; private workspace: Workspace | undefined; @@ -59,7 +63,13 @@ export class WorkspaceStateMachine implements vscode.Disposable { ) { this.logger = container.getLogger(); this.terminal = new TerminalOutputChannel("Coder: Workspace Build"); - this.telemetry = new WorkspaceTelemetry(container.getTelemetryService()); + const telemetry = container.getTelemetryService(); + const workspaceName = `${parts.username}/${parts.workspace}`; + this.agentTelemetry = new WorkspaceAgentTelemetry(telemetry, workspaceName); + this.operationTelemetry = new WorkspaceOperationTelemetry( + telemetry, + workspaceName, + ); } /** @@ -171,7 +181,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { `Agent ${this.agent.name} not found in ${workspaceName} resources`, ); } - this.telemetry.observeAgent(agent); + this.agentTelemetry.observe(agent); switch (agent.status) { case "connecting": @@ -276,7 +286,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { mode: this.startupMode, status: workspace.latest_build.status, }); - await this.telemetry.traceStartTriggered(workspaceName, () => + await this.operationTelemetry.traceStartTriggered(() => startWorkspace(this.buildCliContext(workspace)), ); this.logger.info(`${workspaceName} start initiated`); @@ -296,8 +306,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { status: workspace.latest_build.status, }); try { - this.workspace = await this.telemetry.traceUpdateTriggered( - workspaceName, + this.workspace = await this.operationTelemetry.traceUpdateTriggered( () => updateWorkspace(this.buildCliContext(workspace)), ); this.logger.info(`${workspaceName} update initiated`); @@ -346,7 +355,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { private resetAgent(): void { this.agent = undefined; - this.telemetry.resetAgent(); + this.agentTelemetry.reset(); } dispose(): void { diff --git a/src/workspace/workspaceMonitor.ts b/src/workspace/workspaceMonitor.ts index 4f154453ab..150fac1e9b 100644 --- a/src/workspace/workspaceMonitor.ts +++ b/src/workspace/workspaceMonitor.ts @@ -6,7 +6,7 @@ import { formatDistanceToNowStrict } from "date-fns"; import * as vscode from "vscode"; import { createWorkspaceIdentifier, errToStr } from "../api/api-helper"; -import { WorkspaceTelemetry } from "../instrumentation/workspace"; +import { WorkspaceStateTelemetry } from "../instrumentation/workspace"; import { areNotificationsDisabled, areUpdateNotificationsDisabled, @@ -44,7 +44,7 @@ export class WorkspaceMonitor implements vscode.Disposable { // For logging. private readonly name: string; - private readonly telemetry: WorkspaceTelemetry; + private readonly telemetry: WorkspaceStateTelemetry; private readonly logger: Logger; private readonly contextManager: ContextManager; @@ -58,7 +58,10 @@ export class WorkspaceMonitor implements vscode.Disposable { this.logger = container.getLogger(); this.contextManager = container.getContextManager(); this.name = createWorkspaceIdentifier(workspace); - this.telemetry = new WorkspaceTelemetry(container.getTelemetryService()); + this.telemetry = new WorkspaceStateTelemetry( + container.getTelemetryService(), + this.name, + ); this.latestWorkspace = workspace; const statusBarItem = vscode.window.createStatusBarItem( @@ -135,7 +138,7 @@ export class WorkspaceMonitor implements vscode.Disposable { } private update(workspace: Workspace) { - this.telemetry.observeWorkspace(workspace); + this.telemetry.observe(workspace); this.latestWorkspace = workspace; this.updateContext(workspace); this.updateStatusBar(workspace); diff --git a/test/mocks/testHelpers.ts b/test/mocks/testHelpers.ts index e85667fdc9..b9a8aa9399 100644 --- a/test/mocks/testHelpers.ts +++ b/test/mocks/testHelpers.ts @@ -18,6 +18,7 @@ import type { IncomingMessage } from "node:http"; import type { CoderApi } from "@/api/coderApi"; import type { CliCredentialManager } from "@/core/cliCredentialManager"; import type { ServiceContainer } from "@/core/container"; +import type { ContextManager } from "@/core/contextManager"; import type { MementoManager } from "@/core/mementoManager"; import type { SecretsManager } from "@/core/secretsManager"; import type { Logger } from "@/logging/logger"; @@ -30,6 +31,17 @@ import type { UnidirectionalStream, } from "@/websocket/eventStreamConnection"; +/** + * Subset of `ContextManager`'s public API that mocks (e.g. `MockContextManager`) + * implement. Used by `createMockServiceContainer` so tests can pass either the + * real class or a mock without resorting to `unknown`. + */ +interface ContextManagerLike { + set(key: string, value: boolean): void; + get(key: string): boolean; + dispose(): void; +} + export function makeNetworkInfo( overrides: Partial = {}, ): NetworkInfo { @@ -450,7 +462,8 @@ export function createMockLogger(): Logger { /** * Minimal `ServiceContainer` stub for tests. Pass only the services the unit - * under test reads; unset services fail loudly on access. + * under test reads; unset services throw on access so a missing dependency + * surfaces as a clear error rather than a downstream `undefined` deref. */ export function createMockServiceContainer( overrides: { @@ -459,21 +472,28 @@ export function createMockServiceContainer( secretsManager?: SecretsManager; mementoManager?: MementoManager; cliCredentialManager?: CliCredentialManager; - contextManager?: unknown; + contextManager?: ContextManagerLike; } = {}, ): ServiceContainer { const telemetry = overrides.telemetry ?? createTestTelemetryService(); const logger = overrides.logger ?? createMockLogger(); + const require = (name: string, value: T | undefined): T => { + if (value === undefined) { + throw new Error(`createMockServiceContainer: '${name}' was not provided`); + } + return value; + }; return { getTelemetryService: () => telemetry, getLogger: () => logger, - getSecretsManager: () => overrides.secretsManager!, - getMementoManager: () => overrides.mementoManager!, - getCliCredentialManager: () => overrides.cliCredentialManager!, + getSecretsManager: () => + require("secretsManager", overrides.secretsManager), + getMementoManager: () => + require("mementoManager", overrides.mementoManager), + getCliCredentialManager: () => + require("cliCredentialManager", overrides.cliCredentialManager), getContextManager: () => - overrides.contextManager as ReturnType< - ServiceContainer["getContextManager"] - >, + require("contextManager", overrides.contextManager) as ContextManager, } as ServiceContainer; } diff --git a/test/unit/api/authInterceptor.test.ts b/test/unit/api/authInterceptor.test.ts index 42fdcb2b44..8bd39ac6ce 100644 --- a/test/unit/api/authInterceptor.test.ts +++ b/test/unit/api/authInterceptor.test.ts @@ -479,6 +479,27 @@ describe("AuthInterceptor", () => { expect.objectContaining({ properties: expect.objectContaining({ recovery: "login_required", + refreshAttempted: "false", + result: "error", + }), + }), + ]); + }); + + it("emits span with recovery=none when no callback is registered", async () => { + const sink = new TestSink(); + const { axiosInstance, createInterceptor } = createTestContext(); + + createInterceptor(undefined, createTestTelemetryService(sink)); + await expect( + axiosInstance.triggerResponseError(createAxiosError(401, "denied")), + ).rejects.toThrow(); + + expect(sink.eventsNamed("auth.unauthorized_intercepted")).toEqual([ + expect.objectContaining({ + properties: expect.objectContaining({ + recovery: "none", + refreshAttempted: "false", result: "error", }), }), diff --git a/test/unit/deployment/deploymentManager.test.ts b/test/unit/deployment/deploymentManager.test.ts index 5ece0f365f..eeef697ee3 100644 --- a/test/unit/deployment/deploymentManager.test.ts +++ b/test/unit/deployment/deploymentManager.test.ts @@ -17,6 +17,7 @@ import { } from "../../mocks/testHelpers"; import type { OAuthSessionManager } from "@/oauth/sessionManager"; +import type { TelemetryService } from "@/telemetry/service"; import type { WorkspaceProvider } from "@/workspace/workspacesProvider"; // Mock CoderApi.create to return our mock client for validation diff --git a/test/unit/remote/workspaceStateMachine.test.ts b/test/unit/remote/workspaceStateMachine.test.ts index e59364137c..e325d999fe 100644 --- a/test/unit/remote/workspaceStateMachine.test.ts +++ b/test/unit/remote/workspaceStateMachine.test.ts @@ -405,12 +405,13 @@ describe("WorkspaceStateMachine", () => { }, ])( "emits $name with duration on success", - async ({ eventName, mode, workspace }) => { + async ({ eventName, mode, workspace, mock }) => { const sink = new TestSink(); const { sm, progress } = setup(mode, createTestTelemetryService(sink)); await sm.processWorkspace(workspace(), progress); + expect(mock).toHaveBeenCalledOnce(); expect(sink.eventsNamed(eventName)).toEqual([ expect.objectContaining({ properties: expect.objectContaining({ result: "success" }), From 5523f859c9810e3b43e30622cccce7a27f640200 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Thu, 14 May 2026 01:34:36 +0300 Subject: [PATCH 8/9] refactor(telemetry): address PR review (round 2) - Rename AuthRecoveryOutcome -> AuthRecoveryAction (DEREM-23). Values encode the path taken (refresh_success / login_required / none), not the final outcome; the outcome lives in the span's `result` property. - Rename buildDurationMs -> observedBuildDurationMs on the workspace.state_transitioned event (DEREM-24). Matches the observedDurationMs sibling and signals that this is a client-side performance.now() delta (includes SSE delivery latency), not the actual provisioner job duration. - Trim "Token refresh successful, retrying request" to "Token refresh successful" (DEREM-22). The retry moved to the caller when recoverFromUnauthorized was extracted. - Add a telemetry test for the OAuth-refresh-fails-then-callback path (DEREM-19): asserts refreshAttempted=true with recovery=login_required and result=error. - Add a telemetry test for auth.token_refresh.deduped (DEREM-20): two concurrent refreshToken calls produce one auth.token_refreshed span and one deduped log with the dropped trigger. --- src/api/authInterceptor.ts | 2 +- src/instrumentation/auth.ts | 4 +- src/instrumentation/ssh.ts | 3 +- src/instrumentation/websocket.ts | 14 +- src/instrumentation/workspace.ts | 4 +- src/remote/workspaceStateMachine.ts | 4 +- test/mocks/telemetry.ts | 28 ++- test/unit/api/authInterceptor.test.ts | 191 ++++++++++++------ test/unit/instrumentation/ssh.test.ts | 34 ++-- test/unit/instrumentation/websocket.test.ts | 8 +- test/unit/login/loginCoordinator.test.ts | 135 +++++++------ test/unit/oauth/sessionManager.test.ts | 40 ++-- test/unit/remote/sshProcess.test.ts | 105 +++++----- .../unit/remote/workspaceStateMachine.test.ts | 65 +++--- test/unit/telemetry/service.test.ts | 6 +- .../websocket/reconnectingWebSocket.test.ts | 15 +- test/unit/workspace/workspaceMonitor.test.ts | 27 ++- 17 files changed, 394 insertions(+), 291 deletions(-) diff --git a/src/api/authInterceptor.ts b/src/api/authInterceptor.ts index aef5753a7a..ac76733627 100644 --- a/src/api/authInterceptor.ts +++ b/src/api/authInterceptor.ts @@ -115,7 +115,7 @@ export class AuthInterceptor implements vscode.Disposable { try { const newTokens = await this.oauthSessionManager.refreshToken(); this.client.setSessionToken(newTokens.access_token); - this.logger.debug("Token refresh successful, retrying request"); + this.logger.debug("Token refresh successful"); return newTokens.access_token; } catch (refreshError) { if (!(refreshError instanceof OAuthError)) { diff --git a/src/instrumentation/auth.ts b/src/instrumentation/auth.ts index 7a053b792b..0e2a7d0055 100644 --- a/src/instrumentation/auth.ts +++ b/src/instrumentation/auth.ts @@ -1,7 +1,7 @@ import type { TelemetryReporter } from "../telemetry/reporter"; export type AuthTokenRefreshTrigger = "background" | "reactive"; -export type AuthRecoveryOutcome = "refresh_success" | "login_required" | "none"; +export type AuthRecoveryAction = "refresh_success" | "login_required" | "none"; export type AuthLoginPromptTrigger = "auth_required" | "missing_session"; /** @@ -19,7 +19,7 @@ export type LoginPromptOutcome = /** Span annotator for the auth-recovery flow. Defaults to safe values. */ export interface AuthRecoveryRecorder { - setRecovery(recovery: AuthRecoveryOutcome): void; + setRecovery(recovery: AuthRecoveryAction): void; setRefreshAttempted(attempted: boolean): void; } diff --git a/src/instrumentation/ssh.ts b/src/instrumentation/ssh.ts index 2031fed9c7..4f0daedbb3 100644 --- a/src/instrumentation/ssh.ts +++ b/src/instrumentation/ssh.ts @@ -79,7 +79,6 @@ export class SshTelemetry { public processReplaced(): void { const now = performance.now(); if (this.#processStartedAtMs !== undefined) { - const wasLost = this.#processLostAtMs !== undefined; const measurements: Record = { previousUptimeMs: now - this.#processStartedAtMs, }; @@ -88,7 +87,7 @@ export class SshTelemetry { } this.#telemetry.log( "ssh.process.replaced", - { wasLost: String(wasLost) }, + { wasLost: String(this.#processLostAtMs !== undefined) }, measurements, ); } diff --git a/src/instrumentation/websocket.ts b/src/instrumentation/websocket.ts index 9d52ecddae..f111c7eba0 100644 --- a/src/instrumentation/websocket.ts +++ b/src/instrumentation/websocket.ts @@ -49,7 +49,6 @@ export class WebSocketTelemetry { readonly #telemetry: TelemetryReporter; #connectStartedAtMs: number | undefined; #connectionOpenedAtMs: number | undefined; - #connectionDropEmitted = false; #reconnectCycle: ReconnectCycle | undefined; public constructor(telemetry: TelemetryReporter) { @@ -80,7 +79,6 @@ export class WebSocketTelemetry { const now = performance.now(); const start = this.#connectStartedAtMs ?? now; this.#connectionOpenedAtMs = now; - this.#connectionDropEmitted = false; this.#connectStartedAtMs = undefined; this.#telemetry.log( "connection.opened", @@ -95,19 +93,19 @@ export class WebSocketTelemetry { closeCode?: number, error?: unknown, ): void { - if ( - this.#connectionOpenedAtMs === undefined || - this.#connectionDropEmitted - ) { + // Capture-and-clear up-front so a throw, future await, or re-entry can't re-emit. + const openedAtMs = this.#connectionOpenedAtMs; + if (openedAtMs === undefined) { return; } + this.#connectionOpenedAtMs = undefined; const properties: CallerProperties = { cause }; if (closeCode !== undefined) { properties.closeCode = String(closeCode); } const measurements = { - connectionDurationMs: performance.now() - this.#connectionOpenedAtMs, + connectionDurationMs: performance.now() - openedAtMs, }; if (error === undefined) { this.#telemetry.log("connection.dropped", properties, measurements); @@ -119,13 +117,11 @@ export class WebSocketTelemetry { measurements, ); } - this.#connectionDropEmitted = true; } public reset(): void { this.#connectStartedAtMs = undefined; this.#connectionOpenedAtMs = undefined; - this.#connectionDropEmitted = false; this.#reconnectCycle = undefined; } diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts index ae68393d55..dcdb1439a2 100644 --- a/src/instrumentation/workspace.ts +++ b/src/instrumentation/workspace.ts @@ -35,7 +35,7 @@ interface ObservedAgentState { /** * Emits `workspace.state_transitioned` as a workspace progresses through - * statuses, plus `buildDurationMs` when a provisioner run resolves. + * statuses, plus `observedBuildDurationMs` when a provisioner run resolves. * Construct one per workspace; `WorkspaceMonitor` is the sole call site. */ export class WorkspaceStateTelemetry { @@ -71,7 +71,7 @@ export class WorkspaceStateTelemetry { this.buildStartedAtMs ??= now; } else { if (wasProvisioning && this.buildStartedAtMs !== undefined) { - measurements.buildDurationMs = now - this.buildStartedAtMs; + measurements.observedBuildDurationMs = now - this.buildStartedAtMs; } this.buildStartedAtMs = undefined; } diff --git a/src/remote/workspaceStateMachine.ts b/src/remote/workspaceStateMachine.ts index 62c537bdab..b9ebb991cf 100644 --- a/src/remote/workspaceStateMachine.ts +++ b/src/remote/workspaceStateMachine.ts @@ -306,8 +306,8 @@ export class WorkspaceStateMachine implements vscode.Disposable { status: workspace.latest_build.status, }); try { - this.workspace = await this.operationTelemetry.traceUpdateTriggered( - () => updateWorkspace(this.buildCliContext(workspace)), + this.workspace = await this.operationTelemetry.traceUpdateTriggered(() => + updateWorkspace(this.buildCliContext(workspace)), ); this.logger.info(`${workspaceName} update initiated`); return this.workspace; diff --git a/test/mocks/telemetry.ts b/test/mocks/telemetry.ts index 619c119e87..3d954d32c5 100644 --- a/test/mocks/telemetry.ts +++ b/test/mocks/telemetry.ts @@ -8,7 +8,7 @@ import { } from "@/telemetry/event"; import { TelemetryService } from "@/telemetry/service"; -import { createMockLogger } from "./testHelpers"; +import { createMockLogger, MockConfigurationProvider } from "./testHelpers"; /** * In-memory `TelemetrySink` for tests. Captures every written event and @@ -33,6 +33,17 @@ export class TestSink implements TelemetrySink { eventsNamed(name: string): TelemetryEvent[] { return this.events.filter((e) => e.eventName === name); } + + /** Returns the single event with `name`, throwing if not exactly one. */ + expectOne(name: string): TelemetryEvent { + const matches = this.eventsNamed(name); + if (matches.length !== 1) { + throw new Error( + `Expected exactly 1 '${name}' event, got ${matches.length}`, + ); + } + return matches[0]; + } } export function createTestTelemetryService( @@ -44,3 +55,18 @@ export function createTestTelemetryService( createMockLogger(), ); } + +/** Sets `coder.telemetry.level=local` so emissions reach the sink. */ +export function enableLocalTelemetry(): void { + new MockConfigurationProvider().set("coder.telemetry.level", "local"); +} + +/** Bundles `enableLocalTelemetry` + a fresh sink + service. */ +export function createTelemetryHarness(): { + sink: TestSink; + service: TelemetryService; +} { + enableLocalTelemetry(); + const sink = new TestSink(); + return { sink, service: createTestTelemetryService(sink) }; +} diff --git a/test/unit/api/authInterceptor.test.ts b/test/unit/api/authInterceptor.test.ts index 8bd39ac6ce..b744030dd8 100644 --- a/test/unit/api/authInterceptor.test.ts +++ b/test/unit/api/authInterceptor.test.ts @@ -7,14 +7,17 @@ import { } from "@/api/authInterceptor"; import { SecretsManager } from "@/core/secretsManager"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { + createTestTelemetryService, + enableLocalTelemetry, + TestSink, +} from "../../mocks/telemetry"; import { createAxiosError, createMockLogger, createMockServiceContainer, InMemoryMemento, InMemorySecretStorage, - MockConfigurationProvider, MockOAuthSessionManager, } from "../../mocks/testHelpers"; import { @@ -24,6 +27,7 @@ import { } from "../oauth/testUtils"; import type { CoderApi } from "@/api/coderApi"; +import type { AuthRecoveryAction } from "@/instrumentation/auth"; import type { OAuthSessionManager } from "@/oauth/sessionManager"; import type { TelemetryService } from "@/telemetry/service"; @@ -88,7 +92,7 @@ const ONE_HOUR_MS = 60 * 60 * 1000; function createTestContext() { vi.resetAllMocks(); - new MockConfigurationProvider().set("coder.telemetry.level", "local"); + enableLocalTelemetry(); const secretStorage = new InMemorySecretStorage(); const memento = new InMemoryMemento(); @@ -433,77 +437,130 @@ describe("AuthInterceptor", () => { }); describe("telemetry", () => { - it("emits span with recovery=refresh_success and result=success when OAuth refresh succeeds", async () => { + interface RecoveryCase { + name: string; + arrange: (ctx: ReturnType) => Promise; + withCallback: boolean; + callbackResult?: boolean; + expectThrow: boolean; + expected: { + recovery: AuthRecoveryAction; + refreshAttempted: "true" | "false"; + result: "success" | "error"; + }; + } + + it.each([ + { + name: "OAuth refresh succeeds: recovery=refresh_success", + arrange: async (ctx) => { + await ctx.setupOAuthTokens(); + ctx.mockOAuthManager.refreshToken.mockResolvedValue( + createMockTokenResponse({ access_token: "new" }), + ); + vi.spyOn(ctx.axiosInstance, "request").mockResolvedValue({ + status: 200, + }); + }, + withCallback: false, + expectThrow: false, + expected: { + recovery: "refresh_success", + refreshAttempted: "true", + result: "success", + }, + }, + { + name: "no OAuth + callback declines: recovery=login_required", + arrange: () => Promise.resolve(), + withCallback: true, + callbackResult: false, + expectThrow: true, + expected: { + recovery: "login_required", + refreshAttempted: "false", + result: "error", + }, + }, + { + name: "no OAuth + no callback: recovery=none", + arrange: () => Promise.resolve(), + withCallback: false, + expectThrow: true, + expected: { + recovery: "none", + refreshAttempted: "false", + result: "error", + }, + }, + { + name: "OAuth refresh fails + callback declines: refreshAttempted=true, recovery=login_required", + arrange: async (ctx) => { + await ctx.setupOAuthTokens(); + ctx.mockOAuthManager.refreshToken.mockRejectedValue( + new Error("refresh failed"), + ); + }, + withCallback: true, + callbackResult: false, + expectThrow: true, + expected: { + recovery: "login_required", + refreshAttempted: "true", + result: "error", + }, + }, + ])( + "$name", + async ({ + arrange, + withCallback, + callbackResult, + expectThrow, + expected, + }) => { + const sink = new TestSink(); + const ctx = createTestContext(); + await arrange(ctx); + const onAuthRequired = withCallback + ? vi.fn().mockResolvedValue(callbackResult) + : undefined; + ctx.createInterceptor(onAuthRequired, createTestTelemetryService(sink)); + + const trigger = ctx.axiosInstance.triggerResponseError( + createAxiosError(401, "Unauthorized"), + ); + if (expectThrow) { + await expect(trigger).rejects.toThrow(); + } else { + await trigger; + } + + expect( + sink.expectOne("auth.unauthorized_intercepted").properties, + ).toMatchObject(expected); + }, + ); + + it("includes durationMs on the recovery span", async () => { const sink = new TestSink(); - const { - mockOAuthManager, - axiosInstance, - setupOAuthTokens, - createInterceptor, - } = createTestContext(); - await setupOAuthTokens(); - mockOAuthManager.refreshToken.mockResolvedValue( + const ctx = createTestContext(); + await ctx.setupOAuthTokens(); + ctx.mockOAuthManager.refreshToken.mockResolvedValue( createMockTokenResponse({ access_token: "new" }), ); - vi.spyOn(axiosInstance, "request").mockResolvedValue({ status: 200 }); + vi.spyOn(ctx.axiosInstance, "request").mockResolvedValue({ + status: 200, + }); + ctx.createInterceptor(undefined, createTestTelemetryService(sink)); - createInterceptor(undefined, createTestTelemetryService(sink)); - await axiosInstance.triggerResponseError( + await ctx.axiosInstance.triggerResponseError( createAxiosError(401, "Unauthorized"), ); - expect(sink.eventsNamed("auth.unauthorized_intercepted")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - recovery: "refresh_success", - result: "success", - }), - measurements: expect.objectContaining({ - durationMs: expect.any(Number), - }), - }), - ]); - }); - - it("emits span with recovery=login_required and result=error when falling through to callback", async () => { - const sink = new TestSink(); - const { axiosInstance, createInterceptor } = createTestContext(); - const onAuthRequired = vi.fn().mockResolvedValue(false); - - createInterceptor(onAuthRequired, createTestTelemetryService(sink)); - await expect( - axiosInstance.triggerResponseError(createAxiosError(401, "denied")), - ).rejects.toThrow(); - - expect(sink.eventsNamed("auth.unauthorized_intercepted")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - recovery: "login_required", - refreshAttempted: "false", - result: "error", - }), - }), - ]); - }); - - it("emits span with recovery=none when no callback is registered", async () => { - const sink = new TestSink(); - const { axiosInstance, createInterceptor } = createTestContext(); - - createInterceptor(undefined, createTestTelemetryService(sink)); - await expect( - axiosInstance.triggerResponseError(createAxiosError(401, "denied")), - ).rejects.toThrow(); - - expect(sink.eventsNamed("auth.unauthorized_intercepted")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - recovery: "none", - refreshAttempted: "false", - result: "error", - }), - }), - ]); + expect( + sink.expectOne("auth.unauthorized_intercepted").measurements.durationMs, + ).toEqual(expect.any(Number)); }); }); }); diff --git a/test/unit/instrumentation/ssh.test.ts b/test/unit/instrumentation/ssh.test.ts index 423a3ba9fa..a49912d166 100644 --- a/test/unit/instrumentation/ssh.test.ts +++ b/test/unit/instrumentation/ssh.test.ts @@ -2,25 +2,28 @@ import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; import { SshTelemetry } from "@/instrumentation/ssh"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; -import { - makeNetworkInfo, - MockConfigurationProvider, -} from "../../mocks/testHelpers"; +import { createTelemetryHarness } from "../../mocks/telemetry"; +import { makeNetworkInfo } from "../../mocks/testHelpers"; function setup() { - new MockConfigurationProvider().set("coder.telemetry.level", "local"); - const sink = new TestSink(); - return { ssh: new SshTelemetry(createTestTelemetryService(sink)), sink }; + const { sink, service } = createTelemetryHarness(); + return { ssh: new SshTelemetry(service), sink }; +} + +interface DiscoveryCase { + pid: number | undefined; + attempts: number; + found: string; +} + +interface DisposedCase { + name: string; + lose: boolean; + wasLost: string; } describe("SshTelemetry", () => { describe("traceProcessDiscovery", () => { - interface DiscoveryCase { - pid: number | undefined; - attempts: number; - found: string; - } it.each([ { pid: 123, attempts: 2, found: "true" }, { pid: undefined, attempts: 5, found: "false" }, @@ -148,11 +151,6 @@ describe("SshTelemetry", () => { expect(sink.events).toHaveLength(0); }); - interface DisposedCase { - name: string; - lose: boolean; - wasLost: string; - } it.each([ { name: "from a healthy state", lose: false, wasLost: "false" }, { name: "after the process was lost", lose: true, wasLost: "true" }, diff --git a/test/unit/instrumentation/websocket.test.ts b/test/unit/instrumentation/websocket.test.ts index 01374fc856..0af7a2a7be 100644 --- a/test/unit/instrumentation/websocket.test.ts +++ b/test/unit/instrumentation/websocket.test.ts @@ -3,13 +3,11 @@ import { describe, expect, it } from "vitest"; import { WebSocketTelemetry } from "@/instrumentation/websocket"; import { ConnectionState } from "@/websocket/reconnectingWebSocket"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; -import { MockConfigurationProvider } from "../../mocks/testHelpers"; +import { createTelemetryHarness } from "../../mocks/telemetry"; function setup() { - new MockConfigurationProvider().set("coder.telemetry.level", "local"); - const sink = new TestSink(); - return { ws: new WebSocketTelemetry(createTestTelemetryService(sink)), sink }; + const { sink, service } = createTelemetryHarness(); + return { ws: new WebSocketTelemetry(service), sink }; } describe("WebSocketTelemetry", () => { diff --git a/test/unit/login/loginCoordinator.test.ts b/test/unit/login/loginCoordinator.test.ts index 1d827a75a7..69e9c594df 100644 --- a/test/unit/login/loginCoordinator.test.ts +++ b/test/unit/login/loginCoordinator.test.ts @@ -545,79 +545,90 @@ describe("LoginCoordinator", () => { trigger, }); - it("emits result=aborted with reason when the user dismisses the dialog", async () => { - const sink = new TestSink(); - const { userInteraction, coordinator } = createTestContext( - createTestTelemetryService(sink), - ); - userInteraction.setResponse("Authentication Required", undefined); - - await coordinator.ensureLoggedInWithDialog( - dialogOptions("missing_session"), - ); - - expect(sink.eventsNamed("auth.login_prompted")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - trigger: "missing_session", - result: "aborted", - reason: "user_dismissed", - }), - measurements: expect.objectContaining({ - durationMs: expect.any(Number), - }), - }), - ]); - }); - - it("emits result=error with reason (and no error block) when authentication fails", async () => { - const sink = new TestSink(); - const { mockConfig, userInteraction, coordinator, mockAuthFailure } = - createTestContext(createTestTelemetryService(sink)); + const enableMTLS = (mockConfig: MockConfigurationProvider) => { mockConfig.set("coder.tlsCertFile", "/path/to/cert.pem"); mockConfig.set("coder.tlsKeyFile", "/path/to/key.pem"); - mockAuthFailure("Certificate error"); - vi.mocked(maybeAskUrl).mockResolvedValue(TEST_URL); - userInteraction.setResponse("Authentication Required", "Login"); + }; + + interface PromptCase { + name: string; + arrange: (ctx: ReturnType) => void; + trigger: "auth_required" | "missing_session"; + expected: { + result: "success" | "aborted" | "error"; + reason?: "user_dismissed" | "no_url_provided" | "auth_failed"; + }; + } - const result = await coordinator.ensureLoggedInWithDialog( - dialogOptions("auth_required"), - ); + it.each([ + { + name: "user dismisses the dialog: aborted + user_dismissed", + arrange: (ctx) => + ctx.userInteraction.setResponse("Authentication Required", undefined), + trigger: "missing_session", + expected: { result: "aborted", reason: "user_dismissed" }, + }, + { + name: "authentication fails: error + auth_failed", + arrange: (ctx) => { + enableMTLS(ctx.mockConfig); + ctx.mockAuthFailure("Certificate error"); + vi.mocked(maybeAskUrl).mockResolvedValue(TEST_URL); + ctx.userInteraction.setResponse("Authentication Required", "Login"); + }, + trigger: "auth_required", + expected: { result: "error", reason: "auth_failed" }, + }, + { + name: "user cancels URL prompt: aborted + no_url_provided", + arrange: (ctx) => { + enableMTLS(ctx.mockConfig); + vi.mocked(maybeAskUrl).mockResolvedValue(undefined); + ctx.userInteraction.setResponse("Authentication Required", "Login"); + }, + trigger: "auth_required", + expected: { result: "aborted", reason: "no_url_provided" }, + }, + { + name: "happy path: success and no reason", + arrange: (ctx) => { + enableMTLS(ctx.mockConfig); + ctx.mockSuccessfulAuth(); + vi.mocked(maybeAskUrl).mockResolvedValue(TEST_URL); + ctx.userInteraction.setResponse("Authentication Required", "Login"); + }, + trigger: "auth_required", + expected: { result: "success" }, + }, + ])("$name", async ({ arrange, trigger, expected }) => { + const sink = new TestSink(); + const ctx = createTestContext(createTestTelemetryService(sink)); + arrange(ctx); - expect(result).toEqual({ success: false, reason: "auth_failed" }); - const events = sink.eventsNamed("auth.login_prompted"); - expect(events).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - trigger: "auth_required", - result: "error", - reason: "auth_failed", - }), - }), - ]); - expect(events[0].error).toBeUndefined(); + await ctx.coordinator.ensureLoggedInWithDialog(dialogOptions(trigger)); + + const event = sink.expectOne("auth.login_prompted"); + expect(event.properties).toMatchObject({ trigger, ...expected }); + if (expected.reason === undefined) { + expect(event.properties.reason).toBeUndefined(); + } + expect(event.error).toBeUndefined(); }); - it("emits result=success without a reason on the happy path", async () => { + it("includes durationMs on the prompt span", async () => { const sink = new TestSink(); - const { mockConfig, userInteraction, coordinator, mockSuccessfulAuth } = - createTestContext(createTestTelemetryService(sink)); - mockConfig.set("coder.tlsCertFile", "/path/to/cert.pem"); - mockConfig.set("coder.tlsKeyFile", "/path/to/key.pem"); - mockSuccessfulAuth(); - vi.mocked(maybeAskUrl).mockResolvedValue(TEST_URL); - userInteraction.setResponse("Authentication Required", "Login"); + const { userInteraction, coordinator } = createTestContext( + createTestTelemetryService(sink), + ); + userInteraction.setResponse("Authentication Required", undefined); await coordinator.ensureLoggedInWithDialog( - dialogOptions("auth_required"), + dialogOptions("missing_session"), ); - const [event] = sink.eventsNamed("auth.login_prompted"); - expect(event.properties).toMatchObject({ - trigger: "auth_required", - result: "success", - }); - expect(event.properties.reason).toBeUndefined(); + expect( + sink.expectOne("auth.login_prompted").measurements.durationMs, + ).toEqual(expect.any(Number)); }); }); }); diff --git a/test/unit/oauth/sessionManager.test.ts b/test/unit/oauth/sessionManager.test.ts index 492263c55c..0ccf5b239b 100644 --- a/test/unit/oauth/sessionManager.test.ts +++ b/test/unit/oauth/sessionManager.test.ts @@ -9,10 +9,13 @@ import { type SessionAuth } from "@/core/secretsManager"; import { DEFAULT_OAUTH_SCOPES } from "@/oauth/constants"; import { OAuthSessionManager } from "@/oauth/sessionManager"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { + createTestTelemetryService, + enableLocalTelemetry, + TestSink, +} from "../../mocks/telemetry"; import { createMockServiceContainer, - MockConfigurationProvider, setupAxiosMockRoutes, } from "../../mocks/testHelpers"; @@ -479,8 +482,8 @@ describe("OAuthSessionManager", () => { describe("telemetry", () => { const setupWithSink = async () => { + enableLocalTelemetry(); const sink = new TestSink(); - new MockConfigurationProvider().set("coder.telemetry.level", "local"); const ctx = createTestContext(); const manager = ctx.createManager( createTestDeployment(), @@ -500,18 +503,27 @@ describe("OAuthSessionManager", () => { await manager.refreshToken(trigger); - expect(sink.eventsNamed("auth.token_refreshed")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - trigger, - result: "success", - }), - measurements: expect.objectContaining({ - durationMs: expect.any(Number), - }), - }), - ]); + const event = sink.expectOne("auth.token_refreshed"); + expect(event.properties).toMatchObject({ trigger, result: "success" }); + expect(event.measurements.durationMs).toEqual(expect.any(Number)); }, ); + + it("emits auth.token_refresh.deduped for callers that join an in-flight refresh", async () => { + const { manager, sink } = await setupWithSink(); + + const [first, second] = await Promise.all([ + manager.refreshToken("background"), + manager.refreshToken("reactive"), + ]); + + expect(first).toBe(second); + expect(sink.eventsNamed("auth.token_refreshed")).toHaveLength(1); + expect( + sink.expectOne("auth.token_refresh.deduped").properties, + ).toMatchObject({ + trigger: "reactive", + }); + }); }); }); diff --git a/test/unit/remote/sshProcess.test.ts b/test/unit/remote/sshProcess.test.ts index 293b7e3d7a..4525f997c9 100644 --- a/test/unit/remote/sshProcess.test.ts +++ b/test/unit/remote/sshProcess.test.ts @@ -12,7 +12,11 @@ import { } from "@/remote/sshProcess"; import { NOOP_TELEMETRY_REPORTER } from "@/telemetry/reporter"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { + createTestTelemetryService, + enableLocalTelemetry, + TestSink, +} from "../../mocks/telemetry"; import { createMockLogger, makeNetworkInfo, @@ -44,7 +48,7 @@ describe("SshProcessMonitor", () => { statusBar = new MockStatusBarItem(); // Provide default threshold config so getThresholdConfig() works, // and enable telemetry so traces are emitted to the test sink. - new MockConfigurationProvider().set("coder.telemetry.level", "local"); + enableLocalTelemetry(); // Default: process found immediately vi.mocked(find).mockResolvedValue([ @@ -216,7 +220,7 @@ describe("SshProcessMonitor", () => { monitor.onPidChange((pid) => pids.push(pid)); // Wait for reconnection to find new PID - await waitFor(() => pids.includes(888), 200); + await waitUntil(() => pids.includes(888), { timeout: 200 }); // Should NOT fire undefined - we keep showing last status while searching expect(pids).toContain(888); @@ -354,7 +358,7 @@ describe("SshProcessMonitor", () => { // finalises the span with `found: false`. monitor.dispose(); - await waitFor( + await waitUntil( () => sink.eventsNamed("ssh.process.discovered").length > 0, ); expect(sink.eventsNamed("ssh.process.discovered")[0]).toMatchObject({ @@ -395,7 +399,7 @@ describe("SshProcessMonitor", () => { telemetry, }); await waitForEvent(monitor.onPidChange); - await waitFor(() => sink.eventsNamed("ssh.process.lost").length > 0); + await waitUntil(() => sink.eventsNamed("ssh.process.lost").length > 0); monitor.dispose(); const disposed = sink.eventsNamed("ssh.process.disposed"); @@ -405,30 +409,31 @@ describe("SshProcessMonitor", () => { it("emits missing_network_info as the loss cause when reads fail repeatedly", async () => { vi.useFakeTimers(); - const sink = new TestSink(); - const telemetry = createTestTelemetryService(sink); - vol.fromJSON(sshLog); - // No /network/999.json. Every read fails until threshold is reached. - vi.mocked(find).mockResolvedValue([ - { pid: 999, ppid: 1, name: "ssh", cmd: "ssh" }, - ]); - - const monitor = createMonitor({ - networkInfoPath: "/network", - networkPollInterval: 10, - telemetry, - }); + try { + const sink = new TestSink(); + const telemetry = createTestTelemetryService(sink); + vol.fromJSON(sshLog); + // No /network/999.json. Every read fails until threshold is reached. + vi.mocked(find).mockResolvedValue([ + { pid: 999, ppid: 1, name: "ssh", cmd: "ssh" }, + ]); - await vi.advanceTimersByTimeAsync(500); - await vi.waitFor(() => - expect(sink.eventsNamed("ssh.process.lost").length).toBeGreaterThan(0), - ); + const monitor = createMonitor({ + networkInfoPath: "/network", + networkPollInterval: 10, + telemetry, + }); - expect(sink.eventsNamed("ssh.process.lost")[0].properties).toMatchObject({ - cause: "missing_network_info", - }); + await vi.advanceTimersByTimeAsync(500); + expect(sink.eventsNamed("ssh.process.lost").length).toBeGreaterThan(0); + expect( + sink.eventsNamed("ssh.process.lost")[0].properties, + ).toMatchObject({ cause: "missing_network_info" }); - monitor.dispose(); + monitor.dispose(); + } finally { + vi.useRealTimers(); + } }); it("emits ssh.process.replaced (not recovered) when a different PID takes over", async () => { @@ -448,7 +453,9 @@ describe("SshProcessMonitor", () => { telemetry, }); await waitForEvent(monitor.onPidChange); - await waitFor(() => sink.eventsNamed("ssh.process.replaced").length > 0); + await waitUntil( + () => sink.eventsNamed("ssh.process.replaced").length > 0, + ); // Halt monitoring before the negative assertion so the 888 loop // can't race ahead and emit its own lost/recovered cycle. monitor.dispose(); @@ -479,7 +486,7 @@ describe("SshProcessMonitor", () => { telemetry, }); await waitForEvent(monitor.onPidChange); - await waitFor( + await waitUntil( () => sink.eventsNamed("ssh.process.lost").length > 0 && sink.eventsNamed("ssh.process.recovered").length > 0, @@ -508,7 +515,7 @@ describe("SshProcessMonitor", () => { networkPollInterval: 10, telemetry, }); - await waitFor(() => sink.eventsNamed("ssh.network.sampled").length > 0); + await waitUntil(() => sink.eventsNamed("ssh.network.sampled").length > 0); expect(sink.eventsNamed("ssh.network.sampled")[0]).toMatchObject({ properties: { p2p: "true", preferredDerp: "NYC" }, @@ -640,7 +647,7 @@ describe("SshProcessMonitor", () => { codeLogDir: "/logs/window1", networkInfoPath: "/network", }); - await waitFor(() => statusBar.text.includes("Direct")); + await waitUntil(() => statusBar.text.includes("Direct")); expect(statusBar.text).toContain("Direct"); expect(statusBar.text).toContain("25.50ms"); @@ -662,7 +669,7 @@ describe("SshProcessMonitor", () => { codeLogDir: "/logs/window1", networkInfoPath: "/network", }); - await waitFor(() => statusBar.text.includes("SFO")); + await waitUntil(() => statusBar.text.includes("SFO")); expect(statusBar.text).toContain("SFO"); expect(tooltipText()).toContain("relay"); @@ -679,7 +686,7 @@ describe("SshProcessMonitor", () => { codeLogDir: "/logs/window1", networkInfoPath: "/network", }); - await waitFor(() => statusBar.text.includes("Coder Connect")); + await waitUntil(() => statusBar.text.includes("Coder Connect")); expect(statusBar.text).toContain("Coder Connect"); }); @@ -999,10 +1006,9 @@ describe("SshProcessMonitor", () => { ); startWithNetwork({ latency: 200 }); - await waitFor( - () => statusBar.backgroundColor instanceof ThemeColor, - 2000, - ); + await waitUntil(() => statusBar.backgroundColor instanceof ThemeColor, { + timeout: 2000, + }); expect(statusBar.command).toBe("coder.pingWorkspace"); }); }); @@ -1043,6 +1049,18 @@ function mockReaddirOrder(dirPath: string, files: string[]): void { ); } +/** Poll `cond` via `vi.waitFor` until it returns truthy. */ +async function waitUntil( + cond: () => boolean, + options?: { timeout?: number }, +): Promise { + await vi.waitFor(() => { + if (!cond()) { + throw new Error("waitUntil: condition not met"); + } + }, options); +} + /** Wait for a VS Code event to fire once */ function waitForEvent( event: (listener: (e: T) => void) => { dispose(): void }, @@ -1061,18 +1079,3 @@ function waitForEvent( }); }); } - -/** Poll for a condition to become true */ -async function waitFor( - condition: () => boolean, - timeout = 1000, - interval = 5, -): Promise { - const start = Date.now(); - while (!condition()) { - if (Date.now() - start > timeout) { - throw new Error(`waitFor timed out after ${timeout}ms`); - } - await new Promise((r) => setTimeout(r, interval)); - } -} diff --git a/test/unit/remote/workspaceStateMachine.test.ts b/test/unit/remote/workspaceStateMachine.test.ts index e325d999fe..b8c82d6d23 100644 --- a/test/unit/remote/workspaceStateMachine.test.ts +++ b/test/unit/remote/workspaceStateMachine.test.ts @@ -17,11 +17,14 @@ import { workspace as createWorkspace, } from "@repo/mocks"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { + createTestTelemetryService, + enableLocalTelemetry, + TestSink, +} from "../../mocks/telemetry"; import { createMockLogger, createMockServiceContainer, - MockConfigurationProvider, MockProgress, MockTerminalOutputChannel, MockUserInteraction, @@ -85,7 +88,7 @@ function setup( startupMode: StartupMode = "start", telemetry?: TelemetryService, ) { - new MockConfigurationProvider().set("coder.telemetry.level", "local"); + enableLocalTelemetry(); const progress = new MockProgress<{ message?: string }>(); const userInteraction = new MockUserInteraction(); const sm = new WorkspaceStateMachine( @@ -412,14 +415,9 @@ describe("WorkspaceStateMachine", () => { await sm.processWorkspace(workspace(), progress); expect(mock).toHaveBeenCalledOnce(); - expect(sink.eventsNamed(eventName)).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ result: "success" }), - measurements: expect.objectContaining({ - durationMs: expect.any(Number), - }), - }), - ]); + const event = sink.expectOne(eventName); + expect(event.properties.result).toBe("success"); + expect(event.measurements.durationMs).toEqual(expect.any(Number)); }, ); @@ -437,12 +435,9 @@ describe("WorkspaceStateMachine", () => { // existing template version, so processWorkspace resolves. await sm.processWorkspace(runningWorkspace(), progress); - expect(sink.eventsNamed("workspace.update.triggered")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ result: "error" }), - error: { message: "update failed" }, - }), - ]); + const event = sink.expectOne("workspace.update.triggered"); + expect(event.properties.result).toBe("error"); + expect(event.error).toEqual({ message: "update failed" }); }); it("emits agent state transitions with observed duration", async () => { @@ -455,25 +450,23 @@ describe("WorkspaceStateMachine", () => { ); await sm.processWorkspace(runningWorkspace(), progress); - expect(sink.eventsNamed("workspace.agent.state_transitioned")).toEqual([ - expect.objectContaining({ - properties: expect.objectContaining({ - fromStatus: "unknown", - toStatus: "connecting", - fromLifecycleState: "unknown", - toLifecycleState: "created", - }), - }), - expect.objectContaining({ - properties: expect.objectContaining({ - fromStatus: "connecting", - toStatus: "connected", - fromLifecycleState: "created", - toLifecycleState: "ready", - }), - measurements: { observedDurationMs: expect.any(Number) }, - }), - ]); + const events = sink.eventsNamed("workspace.agent.state_transitioned"); + expect(events).toHaveLength(2); + expect(events[0].properties).toMatchObject({ + fromStatus: "unknown", + toStatus: "connecting", + fromLifecycleState: "unknown", + toLifecycleState: "created", + }); + expect(events[1].properties).toMatchObject({ + fromStatus: "connecting", + toStatus: "connected", + fromLifecycleState: "created", + toLifecycleState: "ready", + }); + expect(events[1].measurements.observedDurationMs).toEqual( + expect.any(Number), + ); }); }); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index eb027f65c5..e52d405e7c 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -305,6 +305,7 @@ describe("TelemetryService", () => { escapedSpan?.setProperty("late", "ignored"); escapedSpan?.setMeasurement("lateMs", 99); escapedSpan?.markAborted(); + escapedSpan?.markFailure(); // Mutations dropped: emitted event is unchanged. expect(h.sink.events[0].properties.late).toBeUndefined(); @@ -312,7 +313,7 @@ describe("TelemetryService", () => { expect(h.sink.events[0].properties.result).toBe("success"); // Each post-emit mutation logs a warning. - expect(vi.mocked(h.logger.warn).mock.calls.length).toBe(warnBefore + 3); + expect(vi.mocked(h.logger.warn).mock.calls.length).toBe(warnBefore + 4); expect(vi.mocked(h.logger.warn).mock.calls[warnBefore][0]).toContain( "setProperty", ); @@ -322,6 +323,9 @@ describe("TelemetryService", () => { expect(vi.mocked(h.logger.warn).mock.calls[warnBefore + 2][0]).toContain( "markAborted", ); + expect(vi.mocked(h.logger.warn).mock.calls[warnBefore + 3][0]).toContain( + "markFailure", + ); }); it("markAborted flips result to 'aborted' on normal return", async () => { diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index bfc87936ee..d07af24eb1 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -11,11 +11,12 @@ import { type SocketFactory, } from "@/websocket/reconnectingWebSocket"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { - createMockLogger, - MockConfigurationProvider, -} from "../../mocks/testHelpers"; + createTestTelemetryService, + enableLocalTelemetry, + TestSink, +} from "../../mocks/telemetry"; +import { createMockLogger } from "../../mocks/testHelpers"; import type { CloseEvent, Event as WsEvent } from "ws"; @@ -595,7 +596,7 @@ describe("ReconnectingWebSocket", () => { describe("Telemetry wiring", () => { it("walks the state machine through a full reconnect lifecycle", async () => { - new MockConfigurationProvider().set("coder.telemetry.level", "local"); + enableLocalTelemetry(); const sink = new TestSink(); const telemetry = createTestTelemetryService(sink); const { ws, sockets } = await createReconnectingWebSocket({ telemetry }); @@ -641,7 +642,7 @@ describe("ReconnectingWebSocket", () => { }); it("emits a normal-close drop and disconnects on server-initiated close", async () => { - new MockConfigurationProvider().set("coder.telemetry.level", "local"); + enableLocalTelemetry(); const sink = new TestSink(); const telemetry = createTestTelemetryService(sink); const { ws, sockets } = await createReconnectingWebSocket({ telemetry }); @@ -669,7 +670,7 @@ describe("ReconnectingWebSocket", () => { }); it("records certificate_refresh as the reconnect reason on successful refresh", async () => { - new MockConfigurationProvider().set("coder.telemetry.level", "local"); + enableLocalTelemetry(); const sink = new TestSink(); const telemetry = createTestTelemetryService(sink); const sockets: MockSocket[] = []; diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index f8417f0f97..69000de631 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -5,7 +5,11 @@ import { WorkspaceMonitor } from "@/workspace/workspaceMonitor"; import { workspace as createWorkspace } from "@repo/mocks"; -import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { + createTestTelemetryService, + enableLocalTelemetry, + TestSink, +} from "../../mocks/telemetry"; import { createMockServiceContainer, MockConfigurationProvider, @@ -69,10 +73,11 @@ describe("WorkspaceMonitor", () => { describe("telemetry", () => { const buildSinkContext = () => { - const stream = new MockEventStream(); - const sink = new TestSink(); - new MockConfigurationProvider().set("coder.telemetry.level", "local"); - return { stream, sink }; + enableLocalTelemetry(); + return { + stream: new MockEventStream(), + sink: new TestSink(), + }; }; it("emits initial state plus subsequent transitions with duration", async () => { @@ -152,7 +157,7 @@ describe("WorkspaceMonitor", () => { expect(reasons).toEqual(["autostop", "initiator"]); }); - it("emits buildDurationMs on the event that resolves a build run", async () => { + it("emits observedBuildDurationMs on the event that resolves a build run", async () => { const { stream, sink } = buildSinkContext(); await setup( @@ -171,20 +176,20 @@ describe("WorkspaceMonitor", () => { ); const events = sink.eventsNamed("workspace.state_transitioned"); - // pending and starting are intermediate; only running carries buildDurationMs. + // pending and starting are intermediate; only running carries observedBuildDurationMs. expect(events.map((e) => e.properties.to)).toEqual([ "pending", "starting", "running", "stopping", ]); - expect(events[0].measurements.buildDurationMs).toBeUndefined(); - expect(events[1].measurements.buildDurationMs).toBeUndefined(); - expect(events[2].measurements.buildDurationMs).toEqual( + expect(events[0].measurements.observedBuildDurationMs).toBeUndefined(); + expect(events[1].measurements.observedBuildDurationMs).toBeUndefined(); + expect(events[2].measurements.observedBuildDurationMs).toEqual( expect.any(Number), ); // Next build cycle resets; stopping doesn't carry the previous duration. - expect(events[3].measurements.buildDurationMs).toBeUndefined(); + expect(events[3].measurements.observedBuildDurationMs).toBeUndefined(); }); }); From 57902fc518178faea028a935f0a154052c651d51 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Fri, 15 May 2026 13:55:55 +0300 Subject: [PATCH 9/9] refactor(telemetry): simplify span result tracking and property typing MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit - Collapse the `aborted`/`failed` boolean pair in `#startSpan` into a single `mark` field; `markFailure` wins over `markAborted` via precedence-aware assignment. - Widen `CallerProperties` values to `string | number | boolean` (new `CallerPropertyValue` alias); a `normalizeProps` helper stringifies at the entry boundary so the wire format stays `Record`. Drops 6 `String(...)` casts and one `"false"` literal across the auth/ssh/websocket instrumentations. - Rename `INITIAL_STATE` sentinel from `"unknown"` to `"none"` — the former collides with real `WorkspaceAgentStatus`/`WorkspaceAgentLifecycle` values the server reports. --- src/instrumentation/auth.ts | 4 +- src/instrumentation/ssh.ts | 9 ++- src/instrumentation/websocket.ts | 2 +- src/instrumentation/workspace.ts | 4 +- src/telemetry/event.ts | 7 +- src/telemetry/service.ts | 70 ++++++++++++------- src/telemetry/span.ts | 8 ++- .../unit/remote/workspaceStateMachine.test.ts | 4 +- test/unit/workspace/workspaceMonitor.test.ts | 2 +- 9 files changed, 68 insertions(+), 42 deletions(-) diff --git a/src/instrumentation/auth.ts b/src/instrumentation/auth.ts index 0e2a7d0055..b2ce08ce83 100644 --- a/src/instrumentation/auth.ts +++ b/src/instrumentation/auth.ts @@ -51,9 +51,9 @@ export class AuthTelemetry { fn({ setRecovery: (recovery) => span.setProperty("recovery", recovery), setRefreshAttempted: (attempted) => - span.setProperty("refreshAttempted", String(attempted)), + span.setProperty("refreshAttempted", attempted), }), - { recovery: "none", refreshAttempted: "false" }, + { recovery: "none", refreshAttempted: false }, ); } diff --git a/src/instrumentation/ssh.ts b/src/instrumentation/ssh.ts index 4f0daedbb3..3ec3d0200d 100644 --- a/src/instrumentation/ssh.ts +++ b/src/instrumentation/ssh.ts @@ -34,7 +34,7 @@ export class SshTelemetry { ): Promise { return this.#telemetry.trace("ssh.process.discovered", async (span) => { const { pid, attempts } = await fn(); - span.setProperty("found", String(pid !== undefined)); + span.setProperty("found", pid !== undefined); span.setMeasurement("attempts", attempts); return pid; }); @@ -87,7 +87,7 @@ export class SshTelemetry { } this.#telemetry.log( "ssh.process.replaced", - { wasLost: String(this.#processLostAtMs !== undefined) }, + { wasLost: this.#processLostAtMs !== undefined }, measurements, ); } @@ -103,10 +103,9 @@ export class SshTelemetry { return; } const now = performance.now(); - const wasLost = this.#processLostAtMs !== undefined; this.#telemetry.log( "ssh.process.disposed", - { wasLost: String(wasLost) }, + { wasLost: this.#processLostAtMs !== undefined }, { uptimeMs: now - this.#processStartedAtMs }, ); this.#processStartedAtMs = undefined; @@ -130,7 +129,7 @@ export class SshTelemetry { this.#telemetry.log( "ssh.network.sampled", { - p2p: String(network.p2p), + p2p: network.p2p, preferredDerp: network.preferred_derp, }, { diff --git a/src/instrumentation/websocket.ts b/src/instrumentation/websocket.ts index f111c7eba0..7c9b0efd15 100644 --- a/src/instrumentation/websocket.ts +++ b/src/instrumentation/websocket.ts @@ -102,7 +102,7 @@ export class WebSocketTelemetry { const properties: CallerProperties = { cause }; if (closeCode !== undefined) { - properties.closeCode = String(closeCode); + properties.closeCode = closeCode; } const measurements = { connectionDurationMs: performance.now() - openedAtMs, diff --git a/src/instrumentation/workspace.ts b/src/instrumentation/workspace.ts index dcdb1439a2..6d782ff081 100644 --- a/src/instrumentation/workspace.ts +++ b/src/instrumentation/workspace.ts @@ -9,7 +9,8 @@ import type { import type { TelemetryReporter } from "../telemetry/reporter"; -const INITIAL_STATE = "unknown"; +/** Sentinel for `from*` before any state is observed. `"unknown"` is a real server-reported value, so avoid it. */ +const INITIAL_STATE = "none"; /** Statuses where a provisioner job is actively running. */ const PROVISIONING_STATUSES: ReadonlySet = new Set([ @@ -115,7 +116,6 @@ export class WorkspaceAgentTelemetry { } const now = performance.now(); - // Flat camelCase matches the codebase; switch to dot-namespaced grouping (from.status, from.lifecycleState, ...) if a third state dimension lands. this.telemetry.log( "workspace.agent.state_transitioned", { diff --git a/src/telemetry/event.ts b/src/telemetry/event.ts index 54e5159e30..1749a068a2 100644 --- a/src/telemetry/event.ts +++ b/src/telemetry/event.ts @@ -6,8 +6,13 @@ import { toError } from "../error/errorUtils"; /** Telemetry level, mirrors `coder.telemetry.level`. Ordered: off < local. */ export type TelemetryLevel = "off" | "local"; +/** Value types accepted from callers; the framework stringifies at the wire boundary. */ +export type CallerPropertyValue = string | number | boolean; + /** Caller properties. `result` is framework-managed on traced events. */ -export type CallerProperties = Record & { result?: never }; +export type CallerProperties = Record & { + result?: never; +}; /** Caller measurements. `durationMs` is framework-managed on traced events. */ export type CallerMeasurements = Record & { diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index 86a95749b1..a9099fc86e 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -11,6 +11,7 @@ import { buildErrorBlock, type CallerMeasurements, type CallerProperties, + type CallerPropertyValue, type SessionContext, type TelemetryEvent, type TelemetryLevel, @@ -29,6 +30,16 @@ const LEVEL_ORDER: Readonly> = { const readLevel = (): TelemetryLevel => readTelemetryLevel(vscode.workspace.getConfiguration()); +const normalizeProps = ( + props: Record, +): Record => { + const out: Record = {}; + for (const [k, v] of Object.entries(props)) { + out[k] = typeof v === "string" ? v : String(v); + } + return out; +}; + /** Trace context shared by all events in one trace. */ interface SpanOptions { traceId: string; @@ -88,7 +99,12 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { if (this.#level === "off") { return; } - this.#safeEmit(newSpanId(), eventName, properties, measurements); + this.#safeEmit( + newSpanId(), + eventName, + normalizeProps(properties), + measurements, + ); } public logError( @@ -100,9 +116,13 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { if (this.#level === "off") { return; } - this.#safeEmit(newSpanId(), eventName, properties, measurements, { - error, - }); + this.#safeEmit( + newSpanId(), + eventName, + normalizeProps(properties), + measurements, + { error }, + ); } /** @@ -120,10 +140,16 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { if (this.#level === "off") { return fn(NOOP_SPAN); } - return this.#startSpan(eventName, fn, properties, measurements, { - traceId: newTraceId(), - traceLevel: this.#level, - }); + return this.#startSpan( + eventName, + fn, + normalizeProps(properties), + measurements, + { + traceId: newTraceId(), + traceLevel: this.#level, + }, + ); } public async dispose(): Promise { @@ -148,8 +174,8 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { const spanMeasurements = { ...measurements }; const { traceId, traceLevel } = spanOpts; let completed = false; - let aborted = false; - let failed = false; + // `markFailure` wins over `markAborted` regardless of call order. + let mark: "aborted" | "error" | undefined; const warnPostEmit = (op: string, name: string): void => { this.logger.warn( `Telemetry span '${eventName}' ${op}('${name}') called after emit; mutation dropped`, @@ -162,24 +188,25 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { phase: ( phaseName: string, phaseFn: (childSpan: Span) => Promise, - phaseProps: Record = {}, + phaseProps: CallerProperties = {}, phaseMeasurements: Record = {}, ): Promise => { const safeName = this.#sanitizePhaseName(phaseName); return this.#startSpan( `${eventName}.${safeName}`, phaseFn, - phaseProps, + normalizeProps(phaseProps), phaseMeasurements, { traceId, parentEventId: eventId, traceLevel }, ); }, - setProperty(name: string, value: string): void { + setProperty(name: string, value: CallerPropertyValue): void { if (completed) { warnPostEmit("setProperty", name); return; } - spanProperties[name] = value; + spanProperties[name] = + typeof value === "string" ? value : String(value); }, setMeasurement(name: string, value: number): void { if (completed) { @@ -193,25 +220,16 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { warnPostEmit("markAborted", ""); return; } - aborted = true; + mark ??= "aborted"; }, markFailure(): void { if (completed) { warnPostEmit("markFailure", ""); return; } - failed = true; + mark = "error"; }, }; - const resolveResult = (): SpanResult => { - if (failed) { - return "error"; - } else if (aborted) { - return "aborted"; - } else { - return "success"; - } - }; return this.#emitTimed( eventId, eventName, @@ -219,7 +237,7 @@ export class TelemetryService implements vscode.Disposable, TelemetryReporter { spanProperties, spanMeasurements, spanOpts, - resolveResult, + () => mark ?? "success", ).finally(() => { completed = true; }); diff --git a/src/telemetry/span.ts b/src/telemetry/span.ts index a50329570c..303db591e3 100644 --- a/src/telemetry/span.ts +++ b/src/telemetry/span.ts @@ -1,4 +1,8 @@ -import type { CallerMeasurements, CallerProperties } from "./event"; +import type { + CallerMeasurements, + CallerProperties, + CallerPropertyValue, +} from "./event"; /** * Final disposition recorded on a traced event's `result` property. @@ -27,7 +31,7 @@ export interface Span { measurements?: CallerMeasurements, ): Promise; /** Add or replace a property on the event emitted for this span. */ - setProperty(name: string, value: string): void; + setProperty(name: string, value: CallerPropertyValue): void; /** Add or replace a measurement on the event emitted for this span. */ setMeasurement(name: string, value: number): void; /** Flip this span's `result` from `success` to `aborted` on normal return. */ diff --git a/test/unit/remote/workspaceStateMachine.test.ts b/test/unit/remote/workspaceStateMachine.test.ts index b8c82d6d23..da9e19cd62 100644 --- a/test/unit/remote/workspaceStateMachine.test.ts +++ b/test/unit/remote/workspaceStateMachine.test.ts @@ -453,9 +453,9 @@ describe("WorkspaceStateMachine", () => { const events = sink.eventsNamed("workspace.agent.state_transitioned"); expect(events).toHaveLength(2); expect(events[0].properties).toMatchObject({ - fromStatus: "unknown", + fromStatus: "none", toStatus: "connecting", - fromLifecycleState: "unknown", + fromLifecycleState: "none", toLifecycleState: "created", }); expect(events[1].properties).toMatchObject({ diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index 69000de631..feee1aa035 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -101,7 +101,7 @@ describe("WorkspaceMonitor", () => { const events = sink.eventsNamed("workspace.state_transitioned"); expect(events).toHaveLength(2); expect(events[0].properties).toMatchObject({ - from: "unknown", + from: "none", to: "running", }); expect(events[0].measurements.observedDurationMs).toBeUndefined();