From 27bdb91ad19cb8a15bf76306af630117caef064b Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Thu, 7 May 2026 11:06:58 +0000 Subject: [PATCH 1/5] feat: instrument startup telemetry --- src/core/cliManager.ts | 101 ++-- src/core/container.ts | 37 +- src/extension.ts | 45 +- src/instrumentation/activation.ts | 38 ++ src/instrumentation/remoteSetup.ts | 19 + src/remote/remote.ts | 528 ++++++++++++------- src/telemetry/service.ts | 12 +- src/telemetry/span.ts | 12 +- test/mocks/telemetry.ts | 22 +- test/unit/core/cliManager.concurrent.test.ts | 2 + test/unit/core/cliManager.test.ts | 114 ++++ test/unit/telemetry/service.test.ts | 34 ++ 12 files changed, 700 insertions(+), 264 deletions(-) create mode 100644 src/instrumentation/activation.ts create mode 100644 src/instrumentation/remoteSetup.ts diff --git a/src/core/cliManager.ts b/src/core/cliManager.ts index 022d29a7..61538be6 100644 --- a/src/core/cliManager.ts +++ b/src/core/cliManager.ts @@ -25,6 +25,7 @@ import type { Api } from "coder/site/src/api/api"; import type { IncomingMessage } from "node:http"; import type { Logger } from "../logging/logger"; +import type { TelemetryService } from "../telemetry/service"; import type { CliCredentialManager } from "./cliCredentialManager"; import type { PathResolver } from "./pathResolver"; @@ -33,6 +34,18 @@ type ResolvedBinary = | { binPath: string; stat: Stats; source: "file-path" | "directory" } | { binPath: string; source: "not-found" }; +type CliDownloadReason = "missing" | "version_mismatch"; + +interface BinaryDownloadResult { + binPath: string; + downloadedBytes?: number; +} + +interface DownloadResult { + status: number; + downloadedBytes: number; +} + export class CliManager { private readonly binaryLock: BinaryLock; @@ -40,6 +53,7 @@ export class CliManager { private readonly output: Logger, private readonly pathResolver: PathResolver, private readonly cliCredentialManager: CliCredentialManager, + private readonly telemetry: TelemetryService, ) { this.binaryLock = new BinaryLock(output); } @@ -140,6 +154,8 @@ export class CliManager { ); let existingVersion: string | null = null; + const downloadReason: CliDownloadReason = + resolved.source === "not-found" ? "missing" : "version_mismatch"; if (resolved.source !== "not-found") { this.output.debug( "Existing binary size is", @@ -224,13 +240,28 @@ export class CliManager { latestVersion = latestParsedVersion; } - await this.performBinaryDownload( - restClient, - latestVersion, - downloadBinPath, - progressLogPath, + return await this.telemetry.trace( + "cli.download", + async (span) => { + const recordDownloadedBytes = (downloadedBytes: number): void => { + if (downloadedBytes > 0) { + span.setMeasurement("downloadedBytes", downloadedBytes); + } + }; + const downloadResult = await this.performBinaryDownload( + restClient, + latestVersion, + downloadBinPath, + progressLogPath, + recordDownloadedBytes, + ); + if (downloadResult.downloadedBytes !== undefined) { + recordDownloadedBytes(downloadResult.downloadedBytes); + } + return this.renameToFinalPath(resolved, downloadResult.binPath); + }, + { reason: downloadReason }, ); - return await this.renameToFinalPath(resolved, downloadBinPath); } catch (error) { const fallback = await this.handleAnyBinaryFailure( error, @@ -413,7 +444,8 @@ export class CliManager { parsedVersion: semver.SemVer, binPath: string, progressLogPath: string, - ): Promise { + recordDownloadedBytes: (downloadedBytes: number) => void, + ): Promise { const cfg = vscode.workspace.getConfiguration("coder"); const tempFile = tempFilePath(binPath, "temp"); @@ -449,6 +481,7 @@ export class CliManager { bytesDownloaded: number, totalBytes: number | null, ) => { + recordDownloadedBytes(bytesDownloaded); await downloadProgress.writeProgress(progressLogPath, { bytesDownloaded, totalBytes, @@ -457,7 +490,7 @@ export class CliManager { }; const client = restClient.getAxiosInstance(); - const status = await this.download( + const downloadResult = await this.download( client, binSource, writeStream, @@ -467,7 +500,7 @@ export class CliManager { onProgress, ); - switch (status) { + switch (downloadResult.status) { case 200: { await downloadProgress.writeProgress(progressLogPath, { bytesDownloaded: 0, @@ -480,27 +513,32 @@ export class CliManager { "Skipping binary signature verification due to settings", ); } else { - await this.verifyBinarySignatures(client, tempFile, [ - // A signature placed at the same level as the binary. It must be - // named exactly the same with an appended `.asc` (such as - // coder-windows-amd64.exe.asc or coder-linux-amd64.asc). - binSource + ".asc", - // The releases.coder.com bucket does not include the leading "v", - // and unlike what we get from buildinfo it uses a truncated version - // with only major.minor.patch. The signature name follows the same - // rule as above. - `https://releases.coder.com/coder-cli/${parsedVersion.major}.${parsedVersion.minor}.${parsedVersion.patch}/${binName}.asc`, - ]); + await this.telemetry.trace("cli.verify", () => + this.verifyBinarySignatures(client, tempFile, [ + // A signature placed at the same level as the binary. It must be + // named exactly the same with an appended `.asc` (such as + // coder-windows-amd64.exe.asc or coder-linux-amd64.asc). + binSource + ".asc", + // The releases.coder.com bucket does not include the leading "v", + // and unlike what we get from buildinfo it uses a truncated version + // with only major.minor.patch. The signature name follows the same + // rule as above. + `https://releases.coder.com/coder-cli/${parsedVersion.major}.${parsedVersion.minor}.${parsedVersion.patch}/${binName}.asc`, + ]), + ); } // Replace existing binary (handles both renames + Windows lock) await this.replaceExistingBinary(binPath, tempFile); - return binPath; + return { + binPath, + downloadedBytes: downloadResult.downloadedBytes, + }; } case 304: { this.output.info("Using existing binary since server returned a 304"); - return binPath; + return { binPath }; } case 404: { vscode.window @@ -537,7 +575,7 @@ export class CliManager { } const params = new URLSearchParams({ title: `Failed to download binary on \`${cliUtils.goos()}-${cliUtils.goarch()}\``, - body: `Received status code \`${status}\` when downloading the binary.`, + body: `Received status code \`${downloadResult.status}\` when downloading the binary.`, }); const uri = vscode.Uri.parse( `https://github.com/coder/vscode-coder/issues/new?${params.toString()}`, @@ -565,7 +603,7 @@ export class CliManager { bytesDownloaded: number, totalBytes: number | null, ) => Promise, - ): Promise { + ): Promise { const baseUrl = client.defaults.baseURL; const controller = new AbortController(); @@ -583,6 +621,7 @@ export class CliManager { }); this.output.info("Got status code", resp.status); + let written = 0; if (resp.status === 200) { const rawContentLength = (resp.headers["content-length"] ?? resp.headers["x-original-content-length"]) as unknown; @@ -599,9 +638,6 @@ export class CliManager { this.output.info("Got content length", prettyBytes(contentLength)); } - // Track how many bytes were written. - let written = 0; - const completed = await vscode.window.withProgress( { location: vscode.ProgressLocation.Notification, @@ -686,7 +722,10 @@ export class CliManager { this.output.info(`Downloaded ${prettyBytes(written)}`); } - return resp.status; + return { + status: resp.status, + downloadedBytes: written, + }; } /** @@ -776,8 +815,8 @@ export class CliManager { this.output.info("Downloading signature from", source); const signaturePath = path.join(cliPath + ".asc"); const writeStream = createWriteStream(signaturePath); - const status = await this.download(client, source, writeStream); - if (status === 200) { + const downloadResult = await this.download(client, source, writeStream); + if (downloadResult.status === 200) { try { await pgp.verifySignature( publicKeys, @@ -806,7 +845,7 @@ export class CliManager { this.output.info("Binary will be ran anyway at user request"); } } - return status; + return downloadResult.status; } /** diff --git a/src/core/container.ts b/src/core/container.ts index 7259a30b..042eb81f 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -51,6 +51,25 @@ export class ServiceContainer implements vscode.Disposable { context.globalState, this.logger, ); + + const sessionId = newSessionId(); + const localJsonlSink = LocalJsonlSink.start( + { + baseDir: this.pathResolver.getTelemetryPath(), + sessionId, + }, + this.logger, + ); + const session = buildSession( + extractExtensionVersion(context.extension.packageJSON), + sessionId, + ); + this.telemetryService = new TelemetryService( + session, + [localJsonlSink], + this.logger, + ); + // Circular ref: cliCredentialManager ↔ cliManager. The resolver // closure captures `this` by reference, so `this.cliManager` is // available when the closure is called (after construction). @@ -75,6 +94,7 @@ export class ServiceContainer implements vscode.Disposable { this.logger, this.pathResolver, this.cliCredentialManager, + this.telemetryService, ); this.contextManager = new ContextManager(context); this.oauthCallback = new OAuthCallback(context.secrets, this.logger); @@ -96,23 +116,6 @@ export class ServiceContainer implements vscode.Disposable { this.logger, ); - const sessionId = newSessionId(); - const localJsonlSink = LocalJsonlSink.start( - { - baseDir: this.pathResolver.getTelemetryPath(), - sessionId, - }, - this.logger, - ); - const session = buildSession( - extractExtensionVersion(context.extension.packageJSON), - sessionId, - ); - this.telemetryService = new TelemetryService( - session, - [localJsonlSink], - this.logger, - ); this.commandManager = new CommandManager(this.telemetryService); } diff --git a/src/extension.ts b/src/extension.ts index 0ba96aff..ce4d3202 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -14,6 +14,7 @@ import { ServiceContainer } from "./core/container"; import { DeploymentManager } from "./deployment/deploymentManager"; import { CertificateError } from "./error/certificateError"; import { getErrorDetail, toError } from "./error/errorUtils"; +import { ActivationTelemetry } from "./instrumentation/activation"; import { OAuthSessionManager } from "./oauth/sessionManager"; import { Remote } from "./remote/remote"; import { getRemoteSshExtension } from "./remote/sshExtension"; @@ -30,6 +31,22 @@ const MY_WORKSPACES_TREE_ID = "myWorkspaces"; const ALL_WORKSPACES_TREE_ID = "allWorkspaces"; export async function activate(ctx: vscode.ExtensionContext): Promise { + const serviceContainer = new ServiceContainer(ctx); + ctx.subscriptions.push(serviceContainer); + const activationTelemetry = new ActivationTelemetry( + serviceContainer.getTelemetryService(), + ); + + await activationTelemetry.trace(() => + doActivate(ctx, serviceContainer, activationTelemetry), + ); +} + +async function doActivate( + ctx: vscode.ExtensionContext, + serviceContainer: ServiceContainer, + activationTelemetry: ActivationTelemetry, +): Promise { // The Remote SSH extension's proposed APIs are used to override the SSH host // name in VS Code itself. It's visually unappealing having a lengthy name! // @@ -59,9 +76,6 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { // Initialize the global vscodeProposed module for use throughout the extension initVscodeProposed(vscodeProposed); - const serviceContainer = new ServiceContainer(ctx); - ctx.subscriptions.push(serviceContainer); - const output = serviceContainer.getLogger(); const mementoManager = serviceContainer.getMementoManager(); const secretsManager = serviceContainer.getSecretsManager(); @@ -75,6 +89,12 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { const startupMode = await mementoManager.getAndClearStartupMode(); const deployment = await secretsManager.getCurrentDeployment(); + const deploymentSessionAuth = deployment + ? await secretsManager.getSessionAuth(deployment.safeHostname) + : undefined; + activationTelemetry.setAuthState( + deploymentSessionAuth ? "valid_token" : "none", + ); // Shared handler for auth failures (used by interceptor + session manager) const handleAuthFailure = (): Promise => { @@ -111,8 +131,7 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { // in commands that operate on the current login. const client = CoderApi.create( deployment?.url || "", - (await secretsManager.getSessionAuth(deployment?.safeHostname ?? "")) - ?.token, + deploymentSessionAuth?.token, output, ); ctx.subscriptions.push(client); @@ -372,11 +391,14 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { if (details) { ctx.subscriptions.push(details); - await deploymentManager.setDeploymentIfValid({ + const deploymentSet = await deploymentManager.setDeploymentIfValid({ safeHostname: details.safeHostname, url: details.url, token: details.token, }); + activationTelemetry.setAuthState( + deploymentSet ? "valid_token" : "expired", + ); // If a deep link stored a chat agent ID before the // remote-authority reload, open it now that the @@ -391,7 +413,9 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { } catch (ex) { if (ex instanceof CertificateError) { output.warn(ex.detail); - await ex.showNotification("Failed to open workspace", { modal: true }); + await ex.showNotification("Failed to open workspace", { + modal: true, + }); } else if (isAxiosError(ex)) { const msg = getErrorMessage(ex, "None"); const detail = getErrorDetail(ex) || "None"; @@ -432,9 +456,10 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { contextManager.set("coder.loaded", true); } else if (deployment) { output.info(`Initializing deployment: ${deployment.url}`); - deploymentManager - .setDeploymentIfValid(deployment) - // Failure is logged internally + activationTelemetry + .traceDeploymentInit(() => + deploymentManager.setDeploymentIfValid(deployment), + ) .then((success) => { if (success) { output.info("Deployment authenticated and set"); diff --git a/src/instrumentation/activation.ts b/src/instrumentation/activation.ts new file mode 100644 index 00000000..9221321d --- /dev/null +++ b/src/instrumentation/activation.ts @@ -0,0 +1,38 @@ +import type { TelemetryService } from "../telemetry/service"; +import type { Span } from "../telemetry/span"; + +export type ActivationAuthState = "none" | "valid_token" | "expired"; + +export class ActivationTelemetry { + private authState: ActivationAuthState = "none"; + private span: Span | undefined; + + public constructor(private readonly telemetry: TelemetryService) {} + + public trace(fn: () => Promise): Promise { + return this.telemetry.trace("activation", async (span) => { + this.span = span; + span.setProperty("authState", this.authState); + try { + return await fn(); + } finally { + this.span = undefined; + } + }); + } + + public setAuthState(authState: ActivationAuthState): void { + this.authState = authState; + this.span?.setProperty("authState", authState); + } + + public traceDeploymentInit(fn: () => Promise): Promise { + const initialAuthState = this.authState; + return this.telemetry.trace("activation.deployment_init", async (span) => { + span.setProperty("authState", initialAuthState); + const success = await fn(); + span.setProperty("authState", success ? "valid_token" : "expired"); + return success; + }); + } +} diff --git a/src/instrumentation/remoteSetup.ts b/src/instrumentation/remoteSetup.ts new file mode 100644 index 00000000..72ecdfc0 --- /dev/null +++ b/src/instrumentation/remoteSetup.ts @@ -0,0 +1,19 @@ +import type { Span } from "../telemetry/span"; + +export type RemoteSetupPhase = + | "auth_retrieval" + | "workspace_lookup" + | "workspace_ready" + | "agent_ready" + | "ssh_config_write"; + +export class RemoteSetupTelemetry { + public constructor(private readonly span: Span) {} + + public phase( + phaseName: RemoteSetupPhase, + fn: () => T | PromiseLike, + ): Promise { + return this.span.phase(phaseName, () => Promise.resolve(fn())); + } +} diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 0f8714d5..5c69ea3e 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -32,6 +32,7 @@ import { type SecretsManager } from "../core/secretsManager"; import { toError } from "../error/errorUtils"; import { featureSetForVersion, type FeatureSet } from "../featureSet"; import { Inbox } from "../inbox"; +import { RemoteSetupTelemetry } from "../instrumentation/remoteSetup"; import { type Logger } from "../logging/logger"; import { type LoginCoordinator } from "../login/loginCoordinator"; import { OAuthSessionManager } from "../oauth/sessionManager"; @@ -64,12 +65,32 @@ import { SshProcessMonitor } from "./sshProcess"; import { computeSshProperties, sshSupportsSetEnv } from "./sshSupport"; import { WorkspaceStateMachine } from "./workspaceStateMachine"; +import type { TelemetryService } from "../telemetry/service"; + export interface RemoteDetails extends vscode.Disposable { safeHostname: string; url: string; token: string; } +type RemoteAuthorityParts = NonNullable< + ReturnType +>; + +interface RemoteSetupBaseContext { + parts: RemoteAuthorityParts; + workspaceName: string; + remoteAuthority: string; + startupMode: StartupMode; + remoteSshExtensionId: string; +} + +interface RemoteSetupContext extends RemoteSetupBaseContext { + baseUrlRaw: string; + token: string | undefined; + disposables: vscode.Disposable[]; +} + export class Remote { private readonly logger: Logger; private readonly pathResolver: PathResolver; @@ -77,6 +98,7 @@ export class Remote { private readonly contextManager: ContextManager; private readonly secretsManager: SecretsManager; private readonly loginCoordinator: LoginCoordinator; + private readonly telemetryService: TelemetryService; public constructor( private readonly serviceContainer: ServiceContainer, @@ -89,6 +111,7 @@ export class Remote { this.contextManager = serviceContainer.getContextManager(); this.secretsManager = serviceContainer.getSecretsManager(); this.loginCoordinator = serviceContainer.getLoginCoordinator(); + this.telemetryService = serviceContainer.getTelemetryService(); } /** @@ -115,11 +138,32 @@ export class Remote { const workspaceName = `${parts.username}/${parts.workspace}`; - // Migrate existing legacy file-based auth to secrets storage. - await this.migrateToSecretsStorage(parts.safeHostname); + return this.telemetryService.trace("remote.setup", (span) => + this.setupCoderRemote( + { + parts, + workspaceName, + remoteAuthority, + startupMode, + remoteSshExtensionId, + }, + new RemoteSetupTelemetry(span), + ), + ); + } + + private async setupCoderRemote( + baseContext: RemoteSetupBaseContext, + setupTelemetry: RemoteSetupTelemetry, + ): Promise { + const { parts } = baseContext; + const auth = await setupTelemetry.phase("auth_retrieval", async () => { + // Migrate existing legacy file-based auth to secrets storage. + await this.migrateToSecretsStorage(parts.safeHostname); - // Get the URL and token belonging to this host. - const auth = await this.secretsManager.getSessionAuth(parts.safeHostname); + // Get the URL and token belonging to this host. + return this.secretsManager.getSessionAuth(parts.safeHostname); + }); const baseUrlRaw = auth?.url ?? ""; const token = auth?.token; this.logger.debug("Retrieved auth for hostname", { @@ -127,59 +171,41 @@ export class Remote { hasUrl: Boolean(baseUrlRaw), hasToken: token !== undefined, }); - const disposables: vscode.Disposable[] = []; + const setupContext: RemoteSetupContext = { + ...baseContext, + baseUrlRaw, + token, + disposables: [], + }; + const { + workspaceName, + remoteAuthority, + startupMode, + remoteSshExtensionId, + disposables, + } = setupContext; try { - // Shared dialog for session expiry (used by interceptor + session manager) - const showSessionExpiredDialog = () => - this.loginCoordinator.ensureLoggedInWithDialog({ - safeHostname: parts.safeHostname, - url: baseUrlRaw, - message: "Your session expired...", - detailPrefix: `You must log in to access ${workspaceName}.`, - }); - // Create OAuth session manager for this remote deployment const remoteOAuthManager = OAuthSessionManager.create( { url: baseUrlRaw, safeHostname: parts.safeHostname }, this.serviceContainer, async () => { - await showSessionExpiredDialog(); + await this.showSessionExpiredDialog(setupContext); }, ); disposables.push(remoteOAuthManager); - const ensureLoggedInAndRetry = async ( - message: string, - url: string | undefined, - ) => { - const result = await this.loginCoordinator.ensureLoggedInWithDialog({ - safeHostname: parts.safeHostname, - url, - message, - detailPrefix: `You must log in to access ${workspaceName}.`, - }); - - // Dispose before retrying since setup will create new disposables - disposables.forEach((d) => { - d.dispose(); - }); - if (result.success) { - // Login successful, retry setup - return this.setup(remoteAuthority, startupMode, remoteSshExtensionId); - } else { - // User cancelled or login failed - await this.closeRemote(); - return undefined; - } - }; - // It could be that the cli config was deleted. If so, ask for the url. if ( !baseUrlRaw || (!token && needToken(vscode.workspace.getConfiguration())) ) { - return ensureLoggedInAndRetry("You are not logged in...", baseUrlRaw); + return this.ensureLoggedInAndRetry( + setupContext, + "You are not logged in...", + baseUrlRaw, + ); } this.logger.info("Using deployment URL", baseUrlRaw); @@ -200,7 +226,7 @@ export class Remote { remoteOAuthManager, this.secretsManager, async () => { - const result = await showSessionExpiredDialog(); + const result = await this.showSessionExpiredDialog(setupContext); return result.success; }, ); @@ -209,21 +235,7 @@ export class Remote { // Store for use in commands. this.commands.remoteWorkspaceClient = workspaceClient; - let binaryPath: string | undefined; - if ( - this.extensionContext.extensionMode === vscode.ExtensionMode.Production - ) { - binaryPath = await this.cliManager.fetchBinary(workspaceClient); - } else { - try { - // In development, try to use `/tmp/coder` as the binary path. - // This is useful for debugging with a custom bin! - binaryPath = path.join(os.tmpdir(), "coder"); - await fs.stat(binaryPath); - } catch { - binaryPath = await this.cliManager.fetchBinary(workspaceClient); - } - } + const binaryPath = await this.resolveRemoteBinary(workspaceClient); // Write token to keyring or file if (baseUrlRaw && token !== undefined) { @@ -232,27 +244,7 @@ export class Remote { // Listen for token changes for this deployment disposables.push( - this.secretsManager.onDidChangeSessionAuth( - parts.safeHostname, - async (auth) => { - workspaceClient.setCredentials(auth?.url, auth?.token); - if (auth?.url) { - try { - await this.cliManager.configure(auth.url, auth.token, { - silent: true, - }); - this.logger.info( - "Updated CLI config with new token for remote deployment", - ); - } catch (error) { - this.logger.error( - "Failed to update CLI config for remote deployment", - error, - ); - } - } - }, - ), + this.watchRemoteSessionAuth(setupContext, workspaceClient), ); // First thing is to check the version. @@ -296,46 +288,14 @@ export class Remote { } // Next is to find the workspace from the URI scheme provided. - let workspace: Workspace; - try { - this.logger.info(`Looking for workspace ${workspaceName}...`); - workspace = await workspaceClient.getWorkspaceByOwnerAndName( - parts.username, - parts.workspace, - ); - this.logger.info( - `Found workspace ${workspaceName} with status`, - workspace.latest_build.status, - ); - this.commands.workspace = workspace; - } catch (error) { - if (!isAxiosError(error)) { - throw error; - } - switch (error.response?.status) { - case 404: { - const result = await vscodeProposed.window.showInformationMessage( - `That workspace doesn't exist!`, - { - modal: true, - detail: `${workspaceName} cannot be found on ${baseUrlRaw}. Maybe it was deleted...`, - useCustom: true, - }, - "Open Workspace", - ); - disposables.forEach((d) => { - d.dispose(); - }); - if (!result) { - await this.closeRemote(); - } - await vscode.commands.executeCommand("coder.open"); - return; - } - default: - throw error; - } + const foundWorkspace = await setupTelemetry.phase( + "workspace_lookup", + () => this.lookupWorkspace(setupContext, workspaceClient), + ); + if (!foundWorkspace) { + return; } + let workspace: Workspace = foundWorkspace; // Register before connection so the label still displays! let labelFormatterDisposable = this.registerLabelFormatter( @@ -378,56 +338,8 @@ export class Remote { disposables.push(stateMachine); try { - workspace = await vscodeProposed.window.withProgress( - { - location: vscode.ProgressLocation.Notification, - cancellable: false, - title: "Connecting to workspace", - }, - async (progress) => { - let inProgress = false; - let pendingWorkspace: Workspace | null = null; - - return new Promise((resolve, reject) => { - const processWorkspace = async (w: Workspace) => { - if (inProgress) { - // Process one workspace at a time, keeping only the last - pendingWorkspace = w; - return; - } - - inProgress = true; - try { - pendingWorkspace = null; - - const isReady = await stateMachine.processWorkspace( - w, - progress, - ); - if (isReady) { - subscription.dispose(); - resolve(w); - return; - } - } catch (error: unknown) { - subscription.dispose(); - reject(toError(error)); - return; - } finally { - inProgress = false; - } - - if (pendingWorkspace) { - void processWorkspace(pendingWorkspace); - } - }; - - void processWorkspace(workspace); - const subscription = monitor.onChange.event((w) => { - void processWorkspace(w); - }); - }); - }, + workspace = await setupTelemetry.phase("workspace_ready", () => + this.waitForWorkspaceReady(workspace, monitor, stateMachine), ); } finally { stateMachine.dispose(); @@ -436,46 +348,28 @@ export class Remote { // Mark initial setup as complete so the monitor can start notifying about state changes monitor.markInitialSetupComplete(); - const agents = extractAgents(workspace.latest_build.resources); - const agent = agents.find( - (agent) => agent.id === stateMachine.getAgentId(), + const agent = await setupTelemetry.phase("agent_ready", () => + this.findReadyAgent(setupContext, workspace, stateMachine), ); - if (!agent) { - throw new Error("Failed to get workspace or agent from state machine"); - } - - this.logger.info("Workspace ready", { - workspace: workspaceName, - agent: agent.name, - status: workspace.latest_build.status, - }); - - this.commands.workspace = workspace; - // Watch coder inbox for messages const inbox = await Inbox.create(workspace, workspaceClient, this.logger); disposables.push(inbox); const logDir = this.getLogDir(featureSet); - let computedSshProperties: Record = {}; - try { - this.logger.info("Updating SSH config..."); - computedSshProperties = await this.updateSSHConfig( - workspaceClient, - parts.safeHostname, - parts.sshHost, - binaryPath, - logDir, - featureSet, - cliAuth, - ); - } catch (error) { - this.logger.warn("Failed to configure SSH", error); - throw error; - } - + const computedSshProperties = await setupTelemetry.phase( + "ssh_config_write", + () => + this.writeRemoteSshConfig( + setupContext, + workspaceClient, + binaryPath, + logDir, + featureSet, + cliAuth, + ), + ); const remoteCommand = computedSshProperties.RemoteCommand; this.logger.info("Modifying settings..."); @@ -593,6 +487,242 @@ export class Remote { }; } + private async lookupWorkspace( + context: RemoteSetupContext, + workspaceClient: CoderApi, + ): Promise { + try { + this.logger.info(`Looking for workspace ${context.workspaceName}...`); + const workspace = await workspaceClient.getWorkspaceByOwnerAndName( + context.parts.username, + context.parts.workspace, + ); + this.logger.info( + `Found workspace ${context.workspaceName} with status`, + workspace.latest_build.status, + ); + this.commands.workspace = workspace; + return workspace; + } catch (error) { + if (!isAxiosError(error)) { + throw error; + } + switch (error.response?.status) { + case 404: { + const result = await vscodeProposed.window.showInformationMessage( + `That workspace doesn't exist!`, + { + modal: true, + detail: `${context.workspaceName} cannot be found on ${context.baseUrlRaw}. Maybe it was deleted...`, + useCustom: true, + }, + "Open Workspace", + ); + context.disposables.forEach((disposable) => { + disposable.dispose(); + }); + if (!result) { + await this.closeRemote(); + } + await vscode.commands.executeCommand("coder.open"); + return undefined; + } + default: + throw error; + } + } + } + + private async waitForWorkspaceReady( + workspace: Workspace, + monitor: WorkspaceMonitor, + stateMachine: WorkspaceStateMachine, + ): Promise { + return vscodeProposed.window.withProgress( + { + location: vscode.ProgressLocation.Notification, + cancellable: false, + title: "Connecting to workspace", + }, + async (progress) => { + let inProgress = false; + let pendingWorkspace: Workspace | null = null; + + return new Promise((resolve, reject) => { + const processWorkspace = async (w: Workspace) => { + if (inProgress) { + // Process one workspace at a time, keeping only the last + pendingWorkspace = w; + return; + } + + inProgress = true; + try { + pendingWorkspace = null; + + const isReady = await stateMachine.processWorkspace(w, progress); + if (isReady) { + subscription.dispose(); + resolve(w); + return; + } + } catch (error: unknown) { + subscription.dispose(); + reject(toError(error)); + return; + } finally { + inProgress = false; + } + + if (pendingWorkspace) { + void processWorkspace(pendingWorkspace); + } + }; + + void processWorkspace(workspace); + const subscription = monitor.onChange.event((w) => { + void processWorkspace(w); + }); + }); + }, + ); + } + + private findReadyAgent( + context: RemoteSetupContext, + workspace: Workspace, + stateMachine: WorkspaceStateMachine, + ): WorkspaceAgent { + const agents = extractAgents(workspace.latest_build.resources); + const agent = agents.find( + (agent) => agent.id === stateMachine.getAgentId(), + ); + + if (!agent) { + throw new Error("Failed to get workspace or agent from state machine"); + } + + this.logger.info("Workspace ready", { + workspace: context.workspaceName, + agent: agent.name, + status: workspace.latest_build.status, + }); + + this.commands.workspace = workspace; + return agent; + } + + private async writeRemoteSshConfig( + context: RemoteSetupContext, + workspaceClient: Api, + binaryPath: string, + logDir: string, + featureSet: FeatureSet, + cliAuth: CliAuth, + ): Promise> { + try { + this.logger.info("Updating SSH config..."); + return await this.updateSSHConfig( + workspaceClient, + context.parts.safeHostname, + context.parts.sshHost, + binaryPath, + logDir, + featureSet, + cliAuth, + ); + } catch (error) { + this.logger.warn("Failed to configure SSH", error); + throw error; + } + } + + private showSessionExpiredDialog(context: RemoteSetupContext) { + return this.loginCoordinator.ensureLoggedInWithDialog({ + safeHostname: context.parts.safeHostname, + url: context.baseUrlRaw, + message: "Your session expired...", + detailPrefix: `You must log in to access ${context.workspaceName}.`, + }); + } + + private async ensureLoggedInAndRetry( + context: RemoteSetupContext, + message: string, + url: string | undefined, + ): Promise { + const result = await this.loginCoordinator.ensureLoggedInWithDialog({ + safeHostname: context.parts.safeHostname, + url, + message, + detailPrefix: `You must log in to access ${context.workspaceName}.`, + }); + + // Dispose before retrying since setup will create new disposables + context.disposables.forEach((disposable) => { + disposable.dispose(); + }); + if (result.success) { + // Login successful, retry setup + return this.setup( + context.remoteAuthority, + context.startupMode, + context.remoteSshExtensionId, + ); + } + + // User cancelled or login failed + await this.closeRemote(); + return undefined; + } + + private async resolveRemoteBinary(workspaceClient: Api): Promise { + if ( + this.extensionContext.extensionMode === vscode.ExtensionMode.Production + ) { + return this.cliManager.fetchBinary(workspaceClient); + } + + try { + // In development, try to use `/tmp/coder` as the binary path. + // This is useful for debugging with a custom bin! + const binaryPath = path.join(os.tmpdir(), "coder"); + await fs.stat(binaryPath); + return binaryPath; + } catch { + return this.cliManager.fetchBinary(workspaceClient); + } + } + + private watchRemoteSessionAuth( + context: RemoteSetupContext, + workspaceClient: CoderApi, + ): vscode.Disposable { + return this.secretsManager.onDidChangeSessionAuth( + context.parts.safeHostname, + async (auth) => { + workspaceClient.setCredentials(auth?.url, auth?.token); + if (!auth?.url) { + return; + } + + try { + await this.cliManager.configure(auth.url, auth.token, { + silent: true, + }); + this.logger.info( + "Updated CLI config with new token for remote deployment", + ); + } catch (error) { + this.logger.error( + "Failed to update CLI config for remote deployment", + error, + ); + } + }, + ); + } + /** * Migrate legacy file-based auth to secrets storage. */ diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index 9ada725d..bd1ed564 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -141,6 +141,8 @@ export class TelemetryService implements vscode.Disposable { spanOpts: SpanOptions, ): Promise { const eventId = newSpanId(); + const spanProperties = { ...properties }; + const spanMeasurements = { ...measurements }; const { traceId, traceLevel } = spanOpts; const span: Span = { traceId, @@ -161,13 +163,19 @@ export class TelemetryService implements vscode.Disposable { { traceId, parentEventId: eventId, traceLevel }, ); }, + setProperty(name: string, value: string): void { + spanProperties[name] = value; + }, + setMeasurement(name: string, value: number): void { + spanMeasurements[name] = value; + }, }; return this.#emitTimed( eventId, eventName, () => fn(span), - properties, - measurements, + spanProperties, + spanMeasurements, spanOpts, ); } diff --git a/src/telemetry/span.ts b/src/telemetry/span.ts index 626c4bb4..6daa1a90 100644 --- a/src/telemetry/span.ts +++ b/src/telemetry/span.ts @@ -1,4 +1,4 @@ -import { type CallerProperties } from "./event"; +import type { CallerProperties } from "./event"; /** * Parent span handle. Children's `eventName` composes as `${parent.eventName}.${phaseName}`. @@ -16,6 +16,10 @@ export interface Span { properties?: CallerProperties, measurements?: Record, ): Promise; + /** Add or replace a property on the event emitted for this span. */ + setProperty(name: string, value: string): void; + /** Add or replace a measurement on the event emitted for this span. */ + setMeasurement(name: string, value: number): void; } /** No-op `Span` used when telemetry is off. Runs phase fns but emits nothing. */ @@ -31,4 +35,10 @@ export const NOOP_SPAN: Span = { ): Promise { return fn(NOOP_SPAN); }, + setProperty(): void { + return undefined; + }, + setMeasurement(): void { + return undefined; + }, }; diff --git a/test/mocks/telemetry.ts b/test/mocks/telemetry.ts index 4a9c1886..9cdeb064 100644 --- a/test/mocks/telemetry.ts +++ b/test/mocks/telemetry.ts @@ -1,10 +1,14 @@ import { vi } from "vitest"; -import type { - TelemetryEvent, - TelemetryLevel, - TelemetrySink, +import { + buildSession, + type TelemetryEvent, + type TelemetryLevel, + type TelemetrySink, } from "@/telemetry/event"; +import { TelemetryService } from "@/telemetry/service"; + +import { createMockLogger } from "./testHelpers"; /** * In-memory `TelemetrySink` for tests. Captures every written event and @@ -26,3 +30,13 @@ export class TestSink implements TelemetrySink { this.events.push(event); } } + +export function createTestTelemetryService( + sink: TestSink = new TestSink(), +): TelemetryService { + return new TelemetryService( + buildSession("1.2.3-test", "test-session"), + [sink], + createMockLogger(), + ); +} diff --git a/test/unit/core/cliManager.concurrent.test.ts b/test/unit/core/cliManager.concurrent.test.ts index 08a47091..0df85330 100644 --- a/test/unit/core/cliManager.concurrent.test.ts +++ b/test/unit/core/cliManager.concurrent.test.ts @@ -17,6 +17,7 @@ import * as cliUtils from "@/core/cliUtils"; import { PathResolver } from "@/core/pathResolver"; import * as pgp from "@/pgp"; +import { createTestTelemetryService } from "../../mocks/telemetry"; import { createMockCliCredentialManager, createMockLogger, @@ -87,6 +88,7 @@ function setupManager(testDir: string): CliManager { createMockLogger(), new PathResolver(testDir, "/code/log"), createMockCliCredentialManager(), + createTestTelemetryService(), ); } diff --git a/test/unit/core/cliManager.test.ts b/test/unit/core/cliManager.test.ts index ab05ea4b..53a6424d 100644 --- a/test/unit/core/cliManager.test.ts +++ b/test/unit/core/cliManager.test.ts @@ -15,6 +15,7 @@ import { PathResolver } from "@/core/pathResolver"; import * as pgp from "@/pgp"; import { isKeyringEnabled } from "@/settings/cli"; +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; import { createMockCliCredentialManager, createMockLogger, @@ -76,6 +77,7 @@ describe("CliManager", () => { let mockApi: Api; let mockAxios: AxiosInstance; let mockCredManager: CliCredentialManager; + let telemetrySink: TestSink; const TEST_VERSION = "1.2.3"; const TEST_URL = "https://test.coder.com"; @@ -97,10 +99,12 @@ describe("CliManager", () => { mockProgress = new MockProgressReporter(); mockUI = new MockUserInteraction(); mockCredManager = createMockCliCredentialManager(); + telemetrySink = new TestSink(); manager = new CliManager( createMockLogger(), new PathResolver(BASE_PATH, "/code/log"), mockCredManager, + createTestTelemetryService(telemetrySink), ); // Mock only what's necessary @@ -769,6 +773,115 @@ describe("CliManager", () => { ); }); + describe("Telemetry", () => { + const telemetryEvent = (eventName: string) => + telemetrySink.events.find((event) => event.eventName === eventName); + + it.each([ + { + name: "missing", + reason: "missing", + setup: () => undefined, + }, + { + name: "version mismatch", + reason: "version_mismatch", + setup: () => withExistingBinary("1.0.0"), + }, + ])("emits cli.download for $name binary", async ({ reason, setup }) => { + setup(); + withSuccessfulDownload(); + await manager.fetchBinary(mockApi); + + const event = telemetryEvent("cli.download"); + expect(event).toMatchObject({ + properties: { reason, result: "success" }, + }); + expect(event?.measurements.durationMs).toBeGreaterThanOrEqual(0); + expect(event?.measurements.downloadedBytes).toBe( + Buffer.byteLength(mockBinaryContent(TEST_VERSION)), + ); + }); + + it("does not emit cli.download when a cached binary already matches", async () => { + withExistingBinary(TEST_VERSION); + await manager.fetchBinary(mockApi); + + expect(telemetryEvent("cli.download")).toBeUndefined(); + }); + + it("omits downloadedBytes when the server returns 304", async () => { + withExistingBinary("1.0.0"); + withHttpResponse(304); + await manager.fetchBinary(mockApi); + + const event = telemetryEvent("cli.download"); + expect(event).toMatchObject({ + properties: { reason: "version_mismatch", result: "success" }, + }); + expect(event?.measurements.downloadedBytes).toBeUndefined(); + }); + + it("emits downloadedBytes when a download fails after writing bytes", async () => { + const partialContent = "partial-binary"; + withHttpResponse( + 200, + { "content-length": "1024" }, + createMockStream(partialContent, { + error: new Error("connection reset"), + }), + ); + + await expect(manager.fetchBinary(mockApi)).rejects.toThrow( + "Unable to download binary: connection reset", + ); + + const event = telemetryEvent("cli.download"); + expect(event).toMatchObject({ + properties: { reason: "missing", result: "error" }, + error: { + message: "Unable to download binary: connection reset", + }, + }); + expect(event?.measurements.downloadedBytes).toBe( + Buffer.byteLength(partialContent), + ); + }); + + it("emits cli.verify on successful signature verification", async () => { + mockConfig.set("coder.disableSignatureVerification", false); + withSuccessfulDownload(); + withSignatureResponses([200]); + await manager.fetchBinary(mockApi); + + const event = telemetryEvent("cli.verify"); + expect(event).toMatchObject({ + properties: { result: "success" }, + }); + expect(event?.measurements.durationMs).toBeGreaterThanOrEqual(0); + }); + + it("emits cli.verify error when signature verification fails", async () => { + mockConfig.set("coder.disableSignatureVerification", false); + withSuccessfulDownload(); + withSignatureResponses([200]); + vi.mocked(pgp.verifySignature).mockRejectedValueOnce( + createVerificationError("Invalid signature"), + ); + mockUI.setResponse("Signature does not match", undefined); + + await expect(manager.fetchBinary(mockApi)).rejects.toThrow( + "Signature verification aborted", + ); + + const event = telemetryEvent("cli.verify"); + expect(event).toMatchObject({ + properties: { result: "error" }, + error: { message: "Signature verification aborted" }, + }); + }); + }); + describe("File System Operations", () => { it("creates binary directory", async () => { expect(memfs.existsSync(BINARY_DIR)).toBe(false); @@ -799,6 +912,7 @@ describe("CliManager", () => { createMockLogger(), new PathResolver(pathWithSpaces, "/log"), createMockCliCredentialManager(), + createTestTelemetryService(), ); withSuccessfulDownload(); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index b71c5cc2..4a08f4dd 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -135,6 +135,40 @@ describe("TelemetryService", () => { expect(event.measurements.durationMs).toBeGreaterThanOrEqual(0); }); + it("does not observe later caller object mutations", async () => { + const properties = { phase: "start" }; + const measurements = { attempts: 1 }; + + await h.service.trace( + "op", + () => { + properties.phase = "changed"; + measurements.attempts = 2; + return Promise.resolve(); + }, + properties, + measurements, + ); + + expect(h.sink.events[0]).toMatchObject({ + properties: { phase: "start", result: "success" }, + measurements: { attempts: 1 }, + }); + }); + + it("lets spans set properties and measurements before emit", async () => { + await h.service.trace("cli.download", (span) => { + span.setProperty("reason", "missing"); + span.setMeasurement("downloadedBytes", 123); + return Promise.resolve(); + }); + + expect(h.sink.events[0]).toMatchObject({ + properties: { reason: "missing", result: "success" }, + measurements: { downloadedBytes: 123 }, + }); + }); + it("flat traces (no phases) emit a single event with a fresh traceId", async () => { await h.service.trace("a", () => Promise.resolve(1)); await h.service.trace("b", () => Promise.resolve(2)); From 374c156e3d00bbefb515be4df6f7e8998153d04d Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Thu, 7 May 2026 17:08:42 +0300 Subject: [PATCH 2/5] refactor(telemetry): simplify startup telemetry instrumentation - Bundle activation tracer methods (setAuthState, traceDeploymentInit) into a span-scoped ActivationTracer interface; drop instance-state from ActivationTelemetry - Mirror the same shape for remote.setup: RemoteSetupTracer exposes phase() and is owned by RemoteSetupTelemetry; remote.ts no longer touches Span directly - Build RemoteSetupContext after auth retrieval (no empty-default mutation); group setup args under args; rename baseUrlRaw -> baseUrl - Reuse AuthorityParts from util instead of synthesizing a local alias - Drop redundant post-download recordDownloadedBytes and the BinaryDownloadResult/DownloadResult types; per-chunk progress already records the final value - Adopt createTestTelemetryService helper in commandManager.test.ts --- src/core/cliManager.ts | 58 +++------ src/extension.ts | 24 ++-- src/instrumentation/activation.ts | 50 ++++--- src/instrumentation/remoteSetup.ts | 21 ++- src/remote/remote.ts | 180 ++++++++++++-------------- test/unit/core/cliManager.test.ts | 123 ++++++++---------- test/unit/core/commandManager.test.ts | 22 +--- 7 files changed, 215 insertions(+), 263 deletions(-) diff --git a/src/core/cliManager.ts b/src/core/cliManager.ts index 61538be6..3674fdc7 100644 --- a/src/core/cliManager.ts +++ b/src/core/cliManager.ts @@ -36,16 +36,6 @@ type ResolvedBinary = type CliDownloadReason = "missing" | "version_mismatch"; -interface BinaryDownloadResult { - binPath: string; - downloadedBytes?: number; -} - -interface DownloadResult { - status: number; - downloadedBytes: number; -} - export class CliManager { private readonly binaryLock: BinaryLock; @@ -243,22 +233,18 @@ export class CliManager { return await this.telemetry.trace( "cli.download", async (span) => { - const recordDownloadedBytes = (downloadedBytes: number): void => { - if (downloadedBytes > 0) { - span.setMeasurement("downloadedBytes", downloadedBytes); - } - }; - const downloadResult = await this.performBinaryDownload( + const downloadedBinPath = await this.performBinaryDownload( restClient, latestVersion, downloadBinPath, progressLogPath, - recordDownloadedBytes, + (downloadedBytes) => { + if (downloadedBytes > 0) { + span.setMeasurement("downloadedBytes", downloadedBytes); + } + }, ); - if (downloadResult.downloadedBytes !== undefined) { - recordDownloadedBytes(downloadResult.downloadedBytes); - } - return this.renameToFinalPath(resolved, downloadResult.binPath); + return this.renameToFinalPath(resolved, downloadedBinPath); }, { reason: downloadReason }, ); @@ -445,7 +431,7 @@ export class CliManager { binPath: string, progressLogPath: string, recordDownloadedBytes: (downloadedBytes: number) => void, - ): Promise { + ): Promise { const cfg = vscode.workspace.getConfiguration("coder"); const tempFile = tempFilePath(binPath, "temp"); @@ -490,7 +476,7 @@ export class CliManager { }; const client = restClient.getAxiosInstance(); - const downloadResult = await this.download( + const status = await this.download( client, binSource, writeStream, @@ -500,7 +486,7 @@ export class CliManager { onProgress, ); - switch (downloadResult.status) { + switch (status) { case 200: { await downloadProgress.writeProgress(progressLogPath, { bytesDownloaded: 0, @@ -531,14 +517,11 @@ export class CliManager { // Replace existing binary (handles both renames + Windows lock) await this.replaceExistingBinary(binPath, tempFile); - return { - binPath, - downloadedBytes: downloadResult.downloadedBytes, - }; + return binPath; } case 304: { this.output.info("Using existing binary since server returned a 304"); - return { binPath }; + return binPath; } case 404: { vscode.window @@ -575,7 +558,7 @@ export class CliManager { } const params = new URLSearchParams({ title: `Failed to download binary on \`${cliUtils.goos()}-${cliUtils.goarch()}\``, - body: `Received status code \`${downloadResult.status}\` when downloading the binary.`, + body: `Received status code \`${status}\` when downloading the binary.`, }); const uri = vscode.Uri.parse( `https://github.com/coder/vscode-coder/issues/new?${params.toString()}`, @@ -603,7 +586,7 @@ export class CliManager { bytesDownloaded: number, totalBytes: number | null, ) => Promise, - ): Promise { + ): Promise { const baseUrl = client.defaults.baseURL; const controller = new AbortController(); @@ -621,8 +604,8 @@ export class CliManager { }); this.output.info("Got status code", resp.status); - let written = 0; if (resp.status === 200) { + let written = 0; const rawContentLength = (resp.headers["content-length"] ?? resp.headers["x-original-content-length"]) as unknown; const contentLength = Number.parseInt( @@ -722,10 +705,7 @@ export class CliManager { this.output.info(`Downloaded ${prettyBytes(written)}`); } - return { - status: resp.status, - downloadedBytes: written, - }; + return resp.status; } /** @@ -815,8 +795,8 @@ export class CliManager { this.output.info("Downloading signature from", source); const signaturePath = path.join(cliPath + ".asc"); const writeStream = createWriteStream(signaturePath); - const downloadResult = await this.download(client, source, writeStream); - if (downloadResult.status === 200) { + const status = await this.download(client, source, writeStream); + if (status === 200) { try { await pgp.verifySignature( publicKeys, @@ -845,7 +825,7 @@ export class CliManager { this.output.info("Binary will be ran anyway at user request"); } } - return downloadResult.status; + return status; } /** diff --git a/src/extension.ts b/src/extension.ts index ce4d3202..d4c4f25d 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -14,7 +14,10 @@ import { ServiceContainer } from "./core/container"; import { DeploymentManager } from "./deployment/deploymentManager"; import { CertificateError } from "./error/certificateError"; import { getErrorDetail, toError } from "./error/errorUtils"; -import { ActivationTelemetry } from "./instrumentation/activation"; +import { + ActivationTelemetry, + type ActivationTracer, +} from "./instrumentation/activation"; import { OAuthSessionManager } from "./oauth/sessionManager"; import { Remote } from "./remote/remote"; import { getRemoteSshExtension } from "./remote/sshExtension"; @@ -37,15 +40,15 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { serviceContainer.getTelemetryService(), ); - await activationTelemetry.trace(() => - doActivate(ctx, serviceContainer, activationTelemetry), + await activationTelemetry.trace((tracer) => + doActivate(ctx, serviceContainer, tracer), ); } async function doActivate( ctx: vscode.ExtensionContext, serviceContainer: ServiceContainer, - activationTelemetry: ActivationTelemetry, + tracer: ActivationTracer, ): Promise { // The Remote SSH extension's proposed APIs are used to override the SSH host // name in VS Code itself. It's visually unappealing having a lengthy name! @@ -89,12 +92,13 @@ async function doActivate( const startupMode = await mementoManager.getAndClearStartupMode(); const deployment = await secretsManager.getCurrentDeployment(); + if (deployment) { + serviceContainer.getTelemetryService().setDeploymentUrl(deployment.url); + } const deploymentSessionAuth = deployment ? await secretsManager.getSessionAuth(deployment.safeHostname) : undefined; - activationTelemetry.setAuthState( - deploymentSessionAuth ? "valid_token" : "none", - ); + tracer.setAuthState(deploymentSessionAuth ? "valid_token" : "none"); // Shared handler for auth failures (used by interceptor + session manager) const handleAuthFailure = (): Promise => { @@ -396,9 +400,7 @@ async function doActivate( url: details.url, token: details.token, }); - activationTelemetry.setAuthState( - deploymentSet ? "valid_token" : "expired", - ); + tracer.setAuthState(deploymentSet ? "valid_token" : "expired"); // If a deep link stored a chat agent ID before the // remote-authority reload, open it now that the @@ -456,7 +458,7 @@ async function doActivate( contextManager.set("coder.loaded", true); } else if (deployment) { output.info(`Initializing deployment: ${deployment.url}`); - activationTelemetry + tracer .traceDeploymentInit(() => deploymentManager.setDeploymentIfValid(deployment), ) diff --git a/src/instrumentation/activation.ts b/src/instrumentation/activation.ts index 9221321d..af4e60f9 100644 --- a/src/instrumentation/activation.ts +++ b/src/instrumentation/activation.ts @@ -1,38 +1,34 @@ import type { TelemetryService } from "../telemetry/service"; -import type { Span } from "../telemetry/span"; export type ActivationAuthState = "none" | "valid_token" | "expired"; -export class ActivationTelemetry { - private authState: ActivationAuthState = "none"; - private span: Span | undefined; +/** Helpers scoped to the activation trace's lifetime. */ +export interface ActivationTracer { + setAuthState(state: ActivationAuthState): void; + traceDeploymentInit(fn: () => Promise): Promise; +} +export class ActivationTelemetry { public constructor(private readonly telemetry: TelemetryService) {} - public trace(fn: () => Promise): Promise { + public trace(fn: (tracer: ActivationTracer) => Promise): Promise { return this.telemetry.trace("activation", async (span) => { - this.span = span; - span.setProperty("authState", this.authState); - try { - return await fn(); - } finally { - this.span = undefined; - } - }); - } - - public setAuthState(authState: ActivationAuthState): void { - this.authState = authState; - this.span?.setProperty("authState", authState); - } - - public traceDeploymentInit(fn: () => Promise): Promise { - const initialAuthState = this.authState; - return this.telemetry.trace("activation.deployment_init", async (span) => { - span.setProperty("authState", initialAuthState); - const success = await fn(); - span.setProperty("authState", success ? "valid_token" : "expired"); - return success; + span.setProperty("authState", "none"); + return fn({ + setAuthState: (state) => span.setProperty("authState", state), + traceDeploymentInit: (initFn) => + this.telemetry.trace( + "activation.deployment_init", + async (childSpan) => { + const success = await initFn(); + childSpan.setProperty( + "authState", + success ? "valid_token" : "expired", + ); + return success; + }, + ), + }); }); } } diff --git a/src/instrumentation/remoteSetup.ts b/src/instrumentation/remoteSetup.ts index 72ecdfc0..ce50082f 100644 --- a/src/instrumentation/remoteSetup.ts +++ b/src/instrumentation/remoteSetup.ts @@ -1,4 +1,4 @@ -import type { Span } from "../telemetry/span"; +import type { TelemetryService } from "../telemetry/service"; export type RemoteSetupPhase = | "auth_retrieval" @@ -7,13 +7,20 @@ export type RemoteSetupPhase = | "agent_ready" | "ssh_config_write"; +/** Helpers scoped to the remote.setup trace's lifetime. */ +export interface RemoteSetupTracer { + phase(name: RemoteSetupPhase, fn: () => T | PromiseLike): Promise; +} + export class RemoteSetupTelemetry { - public constructor(private readonly span: Span) {} + public constructor(private readonly telemetry: TelemetryService) {} - public phase( - phaseName: RemoteSetupPhase, - fn: () => T | PromiseLike, - ): Promise { - return this.span.phase(phaseName, () => Promise.resolve(fn())); + public trace(fn: (tracer: RemoteSetupTracer) => Promise): Promise { + return this.telemetry.trace("remote.setup", (span) => + fn({ + phase: (name, phaseFn) => + span.phase(name, () => Promise.resolve(phaseFn())), + }), + ); } } diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 5c69ea3e..7d754408 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -32,7 +32,10 @@ import { type SecretsManager } from "../core/secretsManager"; import { toError } from "../error/errorUtils"; import { featureSetForVersion, type FeatureSet } from "../featureSet"; import { Inbox } from "../inbox"; -import { RemoteSetupTelemetry } from "../instrumentation/remoteSetup"; +import { + RemoteSetupTelemetry, + type RemoteSetupTracer, +} from "../instrumentation/remoteSetup"; import { type Logger } from "../logging/logger"; import { type LoginCoordinator } from "../login/loginCoordinator"; import { OAuthSessionManager } from "../oauth/sessionManager"; @@ -46,6 +49,7 @@ import { import { getHeaderCommand } from "../settings/headers"; import { AuthorityPrefix, + type AuthorityParts, escapeCommandArg, expandPath, parseRemoteAuthority, @@ -65,28 +69,24 @@ import { SshProcessMonitor } from "./sshProcess"; import { computeSshProperties, sshSupportsSetEnv } from "./sshSupport"; import { WorkspaceStateMachine } from "./workspaceStateMachine"; -import type { TelemetryService } from "../telemetry/service"; - export interface RemoteDetails extends vscode.Disposable { safeHostname: string; url: string; token: string; } -type RemoteAuthorityParts = NonNullable< - ReturnType ->; - -interface RemoteSetupBaseContext { - parts: RemoteAuthorityParts; - workspaceName: string; +/** Original {@link Remote.setup} args; retained so auth retries can re-invoke. */ +interface RemoteSetupArgs { remoteAuthority: string; startupMode: StartupMode; remoteSshExtensionId: string; } -interface RemoteSetupContext extends RemoteSetupBaseContext { - baseUrlRaw: string; +interface RemoteSetupContext { + args: RemoteSetupArgs; + parts: AuthorityParts; + workspaceName: string; + baseUrl: string; token: string | undefined; disposables: vscode.Disposable[]; } @@ -98,7 +98,7 @@ export class Remote { private readonly contextManager: ContextManager; private readonly secretsManager: SecretsManager; private readonly loginCoordinator: LoginCoordinator; - private readonly telemetryService: TelemetryService; + private readonly setupTelemetry: RemoteSetupTelemetry; public constructor( private readonly serviceContainer: ServiceContainer, @@ -111,7 +111,9 @@ export class Remote { this.contextManager = serviceContainer.getContextManager(); this.secretsManager = serviceContainer.getSecretsManager(); this.loginCoordinator = serviceContainer.getLoginCoordinator(); - this.telemetryService = serviceContainer.getTelemetryService(); + this.setupTelemetry = new RemoteSetupTelemetry( + serviceContainer.getTelemetryService(), + ); } /** @@ -136,59 +138,51 @@ export class Remote { agent: parts.agent || "(default)", }); + const args: RemoteSetupArgs = { + remoteAuthority, + startupMode, + remoteSshExtensionId, + }; const workspaceName = `${parts.username}/${parts.workspace}`; - return this.telemetryService.trace("remote.setup", (span) => - this.setupCoderRemote( + return this.setupTelemetry.trace(async (tracer) => { + const auth = await tracer.phase("auth_retrieval", async () => { + await this.migrateToSecretsStorage(parts.safeHostname); + return this.secretsManager.getSessionAuth(parts.safeHostname); + }); + if (auth?.url) { + this.serviceContainer.getTelemetryService().setDeploymentUrl(auth.url); + } + this.logger.debug("Retrieved auth for hostname", { + hostname: parts.safeHostname, + hasUrl: Boolean(auth?.url), + hasToken: auth?.token !== undefined, + }); + return this.setupCoderRemote( { + args, parts, workspaceName, - remoteAuthority, - startupMode, - remoteSshExtensionId, + baseUrl: auth?.url ?? "", + token: auth?.token, + disposables: [], }, - new RemoteSetupTelemetry(span), - ), - ); + tracer, + ); + }); } private async setupCoderRemote( - baseContext: RemoteSetupBaseContext, - setupTelemetry: RemoteSetupTelemetry, + setupContext: RemoteSetupContext, + tracer: RemoteSetupTracer, ): Promise { - const { parts } = baseContext; - const auth = await setupTelemetry.phase("auth_retrieval", async () => { - // Migrate existing legacy file-based auth to secrets storage. - await this.migrateToSecretsStorage(parts.safeHostname); - - // Get the URL and token belonging to this host. - return this.secretsManager.getSessionAuth(parts.safeHostname); - }); - const baseUrlRaw = auth?.url ?? ""; - const token = auth?.token; - this.logger.debug("Retrieved auth for hostname", { - hostname: parts.safeHostname, - hasUrl: Boolean(baseUrlRaw), - hasToken: token !== undefined, - }); - const setupContext: RemoteSetupContext = { - ...baseContext, - baseUrlRaw, - token, - disposables: [], - }; - const { - workspaceName, - remoteAuthority, - startupMode, - remoteSshExtensionId, - disposables, - } = setupContext; + const { args, parts, workspaceName, baseUrl, token, disposables } = + setupContext; try { // Create OAuth session manager for this remote deployment const remoteOAuthManager = OAuthSessionManager.create( - { url: baseUrlRaw, safeHostname: parts.safeHostname }, + { url: baseUrl, safeHostname: parts.safeHostname }, this.serviceContainer, async () => { await this.showSessionExpiredDialog(setupContext); @@ -198,17 +192,17 @@ export class Remote { // It could be that the cli config was deleted. If so, ask for the url. if ( - !baseUrlRaw || + !baseUrl || (!token && needToken(vscode.workspace.getConfiguration())) ) { return this.ensureLoggedInAndRetry( setupContext, "You are not logged in...", - baseUrlRaw, + baseUrl, ); } - this.logger.info("Using deployment URL", baseUrlRaw); + this.logger.info("Using deployment URL", baseUrl); this.logger.info("Using hostname", parts.safeHostname || "n/a"); // We could use the plugin client, but it is possible for the user to log @@ -216,7 +210,7 @@ export class Remote { // break this connection. We could force close the remote session or // disallow logging out/in altogether, but for now just use a separate // client to remain unaffected by whatever the plugin is doing. - const workspaceClient = CoderApi.create(baseUrlRaw, token, this.logger); + const workspaceClient = CoderApi.create(baseUrl, token, this.logger); disposables.push(workspaceClient); // Create 401 interceptor - handles auth failures with re-login dialog @@ -238,8 +232,8 @@ export class Remote { const binaryPath = await this.resolveRemoteBinary(workspaceClient); // Write token to keyring or file - if (baseUrlRaw && token !== undefined) { - await this.cliManager.configure(baseUrlRaw, token); + if (baseUrl && token !== undefined) { + await this.cliManager.configure(baseUrl, token); } // Listen for token changes for this deployment @@ -264,7 +258,7 @@ export class Remote { const cliAuth = resolveCliAuth( vscode.workspace.getConfiguration(), featureSet, - baseUrlRaw, + baseUrl, configDir, ); @@ -288,9 +282,8 @@ export class Remote { } // Next is to find the workspace from the URI scheme provided. - const foundWorkspace = await setupTelemetry.phase( - "workspace_lookup", - () => this.lookupWorkspace(setupContext, workspaceClient), + const foundWorkspace = await tracer.phase("workspace_lookup", () => + this.lookupWorkspace(setupContext, workspaceClient), ); if (!foundWorkspace) { return; @@ -299,7 +292,7 @@ export class Remote { // Register before connection so the label still displays! let labelFormatterDisposable = this.registerLabelFormatter( - remoteAuthority, + args.remoteAuthority, workspace.owner_name, workspace.name, ); @@ -329,7 +322,7 @@ export class Remote { const stateMachine = new WorkspaceStateMachine( parts, workspaceClient, - startupMode, + args.startupMode, binaryPath, featureSet, this.logger, @@ -338,7 +331,7 @@ export class Remote { disposables.push(stateMachine); try { - workspace = await setupTelemetry.phase("workspace_ready", () => + workspace = await tracer.phase("workspace_ready", () => this.waitForWorkspaceReady(workspace, monitor, stateMachine), ); } finally { @@ -348,7 +341,7 @@ export class Remote { // Mark initial setup as complete so the monitor can start notifying about state changes monitor.markInitialSetupComplete(); - const agent = await setupTelemetry.phase("agent_ready", () => + const agent = await tracer.phase("agent_ready", () => this.findReadyAgent(setupContext, workspace, stateMachine), ); @@ -358,17 +351,15 @@ export class Remote { const logDir = this.getLogDir(featureSet); - const computedSshProperties = await setupTelemetry.phase( - "ssh_config_write", - () => - this.writeRemoteSshConfig( - setupContext, - workspaceClient, - binaryPath, - logDir, - featureSet, - cliAuth, - ), + const computedSshProperties = await tracer.phase("ssh_config_write", () => + this.writeRemoteSshConfig( + setupContext, + workspaceClient, + binaryPath, + logDir, + featureSet, + cliAuth, + ), ); const remoteCommand = computedSshProperties.RemoteCommand; @@ -398,7 +389,7 @@ export class Remote { proxyLogDir: logDir || undefined, logger: this.logger, codeLogDir: this.pathResolver.getCodeLogDir(), - remoteSshExtensionId, + remoteSshExtensionId: args.remoteSshExtensionId, }); disposables.push(sshMonitor); @@ -407,7 +398,7 @@ export class Remote { const reregisterLabelFormatter = () => { labelFormatterDisposable.dispose(); labelFormatterDisposable = this.registerLabelFormatter( - remoteAuthority, + args.remoteAuthority, workspace.owner_name, workspace.name, agent.name, @@ -477,7 +468,7 @@ export class Remote { // explained above. return { safeHostname: parts.safeHostname, - url: baseUrlRaw, + url: baseUrl, token: token ?? "", dispose: () => { disposables.forEach((d) => { @@ -513,13 +504,13 @@ export class Remote { `That workspace doesn't exist!`, { modal: true, - detail: `${context.workspaceName} cannot be found on ${context.baseUrlRaw}. Maybe it was deleted...`, + detail: `${context.workspaceName} cannot be found on ${context.baseUrl}. Maybe it was deleted...`, useCustom: true, }, "Open Workspace", ); - context.disposables.forEach((disposable) => { - disposable.dispose(); + context.disposables.forEach((d) => { + d.dispose(); }); if (!result) { await this.closeRemote(); @@ -640,7 +631,7 @@ export class Remote { private showSessionExpiredDialog(context: RemoteSetupContext) { return this.loginCoordinator.ensureLoggedInWithDialog({ safeHostname: context.parts.safeHostname, - url: context.baseUrlRaw, + url: context.baseUrl, message: "Your session expired...", detailPrefix: `You must log in to access ${context.workspaceName}.`, }); @@ -658,17 +649,14 @@ export class Remote { detailPrefix: `You must log in to access ${context.workspaceName}.`, }); - // Dispose before retrying since setup will create new disposables - context.disposables.forEach((disposable) => { - disposable.dispose(); + // Dispose before retrying since setup will create new disposables. + context.disposables.forEach((d) => { + d.dispose(); }); if (result.success) { - // Login successful, retry setup - return this.setup( - context.remoteAuthority, - context.startupMode, - context.remoteSshExtensionId, - ); + const { remoteAuthority, startupMode, remoteSshExtensionId } = + context.args; + return this.setup(remoteAuthority, startupMode, remoteSshExtensionId); } // User cancelled or login failed @@ -682,10 +670,8 @@ export class Remote { ) { return this.cliManager.fetchBinary(workspaceClient); } - + // Dev override: use a custom binary at /tmp/coder if it exists. try { - // In development, try to use `/tmp/coder` as the binary path. - // This is useful for debugging with a custom bin! const binaryPath = path.join(os.tmpdir(), "coder"); await fs.stat(binaryPath); return binaryPath; diff --git a/test/unit/core/cliManager.test.ts b/test/unit/core/cliManager.test.ts index 53a6424d..0e81bd31 100644 --- a/test/unit/core/cliManager.test.ts +++ b/test/unit/core/cliManager.test.ts @@ -774,40 +774,37 @@ describe("CliManager", () => { }); describe("Telemetry", () => { - const telemetryEvent = (eventName: string) => - telemetrySink.events.find((event) => event.eventName === eventName); + const event = (name: string) => + telemetrySink.events.find((e) => e.eventName === name); it.each([ - { - name: "missing", - reason: "missing", - setup: () => undefined, - }, - { - name: "version mismatch", - reason: "version_mismatch", - setup: () => withExistingBinary("1.0.0"), - }, - ])("emits cli.download for $name binary", async ({ reason, setup }) => { - setup(); - withSuccessfulDownload(); - await manager.fetchBinary(mockApi); + { reason: "missing", existing: undefined }, + { reason: "version_mismatch", existing: "1.0.0" }, + ])( + "emits cli.download with reason=$reason", + async ({ reason, existing }) => { + if (existing) { + withExistingBinary(existing); + } + withSuccessfulDownload(); + await manager.fetchBinary(mockApi); - const event = telemetryEvent("cli.download"); - expect(event).toMatchObject({ - properties: { reason, result: "success" }, - }); - expect(event?.measurements.durationMs).toBeGreaterThanOrEqual(0); - expect(event?.measurements.downloadedBytes).toBe( - Buffer.byteLength(mockBinaryContent(TEST_VERSION)), - ); - }); + const e = event("cli.download"); + expect(e).toMatchObject({ + properties: { reason, result: "success" }, + }); + expect(e?.measurements.durationMs).toBeGreaterThanOrEqual(0); + expect(e?.measurements.downloadedBytes).toBe( + Buffer.byteLength(mockBinaryContent(TEST_VERSION)), + ); + }, + ); it("does not emit cli.download when a cached binary already matches", async () => { withExistingBinary(TEST_VERSION); await manager.fetchBinary(mockApi); - expect(telemetryEvent("cli.download")).toBeUndefined(); + expect(event("cli.download")).toBeUndefined(); }); it("omits downloadedBytes when the server returns 304", async () => { @@ -815,69 +812,61 @@ describe("CliManager", () => { withHttpResponse(304); await manager.fetchBinary(mockApi); - const event = telemetryEvent("cli.download"); - expect(event).toMatchObject({ + const e = event("cli.download"); + expect(e).toMatchObject({ properties: { reason: "version_mismatch", result: "success" }, }); - expect(event?.measurements.downloadedBytes).toBeUndefined(); + expect(e?.measurements.downloadedBytes).toBeUndefined(); }); - it("emits downloadedBytes when a download fails after writing bytes", async () => { - const partialContent = "partial-binary"; + it("emits downloadedBytes when a download fails mid-stream", async () => { + const partial = "partial-binary"; withHttpResponse( 200, { "content-length": "1024" }, - createMockStream(partialContent, { - error: new Error("connection reset"), - }), + createMockStream(partial, { error: new Error("connection reset") }), ); await expect(manager.fetchBinary(mockApi)).rejects.toThrow( "Unable to download binary: connection reset", ); - const event = telemetryEvent("cli.download"); - expect(event).toMatchObject({ + expect(event("cli.download")).toMatchObject({ properties: { reason: "missing", result: "error" }, - error: { - message: "Unable to download binary: connection reset", - }, + error: { message: "Unable to download binary: connection reset" }, + measurements: { downloadedBytes: Buffer.byteLength(partial) }, }); - expect(event?.measurements.downloadedBytes).toBe( - Buffer.byteLength(partialContent), - ); }); - it("emits cli.verify on successful signature verification", async () => { - mockConfig.set("coder.disableSignatureVerification", false); - withSuccessfulDownload(); - withSignatureResponses([200]); - await manager.fetchBinary(mockApi); + describe("cli.verify", () => { + beforeEach(() => { + mockConfig.set("coder.disableSignatureVerification", false); + withSuccessfulDownload(); + withSignatureResponses([200]); + }); - const event = telemetryEvent("cli.verify"); - expect(event).toMatchObject({ - properties: { result: "success" }, + it("emits success on valid signature", async () => { + await manager.fetchBinary(mockApi); + + const e = event("cli.verify"); + expect(e).toMatchObject({ properties: { result: "success" } }); + expect(e?.measurements.durationMs).toBeGreaterThanOrEqual(0); }); - expect(event?.measurements.durationMs).toBeGreaterThanOrEqual(0); - }); - it("emits cli.verify error when signature verification fails", async () => { - mockConfig.set("coder.disableSignatureVerification", false); - withSuccessfulDownload(); - withSignatureResponses([200]); - vi.mocked(pgp.verifySignature).mockRejectedValueOnce( - createVerificationError("Invalid signature"), - ); - mockUI.setResponse("Signature does not match", undefined); + it("emits error when verification is aborted", async () => { + vi.mocked(pgp.verifySignature).mockRejectedValueOnce( + createVerificationError("Invalid signature"), + ); + mockUI.setResponse("Signature does not match", undefined); - await expect(manager.fetchBinary(mockApi)).rejects.toThrow( - "Signature verification aborted", - ); + await expect(manager.fetchBinary(mockApi)).rejects.toThrow( + "Signature verification aborted", + ); - const event = telemetryEvent("cli.verify"); - expect(event).toMatchObject({ - properties: { result: "error" }, - error: { message: "Signature verification aborted" }, + expect(event("cli.verify")).toMatchObject({ + properties: { result: "error" }, + error: { message: "Signature verification aborted" }, + }); }); }); }); diff --git a/test/unit/core/commandManager.test.ts b/test/unit/core/commandManager.test.ts index c05065ef..fa48904b 100644 --- a/test/unit/core/commandManager.test.ts +++ b/test/unit/core/commandManager.test.ts @@ -8,14 +8,9 @@ import { CommandManager, type CoderCommandId, } from "@/core/commandManager"; -import { buildSession } from "@/telemetry/event"; -import { TelemetryService } from "@/telemetry/service"; -import { TestSink } from "../../mocks/telemetry"; -import { - createMockLogger, - MockConfigurationProvider, -} from "../../mocks/testHelpers"; +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { MockConfigurationProvider } from "../../mocks/testHelpers"; interface Harness { manager: CommandManager; @@ -23,15 +18,12 @@ interface Harness { } function makeHarness(): Harness { - const config = new MockConfigurationProvider(); - config.set("coder.telemetry.level", "local"); + new MockConfigurationProvider(); const sink = new TestSink(); - const telemetry = new TelemetryService( - buildSession("1.2.3-test", "test-session"), - [sink], - createMockLogger(), - ); - return { manager: new CommandManager(telemetry), sink }; + return { + manager: new CommandManager(createTestTelemetryService(sink)), + sink, + }; } function getRegisteredCallback( From 5d2c26310eb4a47b04ad6b73fa260786cb718736 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Thu, 7 May 2026 19:41:47 +0300 Subject: [PATCH 3/5] add changelog entry --- CHANGELOG.md | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 4dcc92f1..32e8e137 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -16,6 +16,11 @@ - 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. ### Fixed From aa21198c8a140388ba7b1d5c86d912d5c2d80c84 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Fri, 8 May 2026 20:54:32 +0300 Subject: [PATCH 4/5] refactor(telemetry): tighten startup span outcomes and lifecycle Address PR review feedback on the startup telemetry instrumentation: - Hoist auth retrieval and the no-auth check out of the `remote.setup` trace; auth retrieval is now its own `remote.auth_retrieval` top-level event so login retries no longer produce nested `remote.setup` events with dialog time in `durationMs`. - Add `RemoteSetupTracer.setOutcome` and annotate the non-throwing failure paths (`workspace_not_found`, `incompatible_server`). - Distinguish verified, bypassed, and sig-not-found verification outcomes; verify is now a `cli.download.verify` child phase. - Add `unreadable` download reason for the case where a binary exists but `cliVersion()` throws. - Use `stored` for an unvalidated stored token; reserve `valid_token` for post-validation. Default `unknown` on `activation.deployment_init` before `initFn` runs. - Track and warn on post-emit span mutations; eliminate the only realistic case by accumulating download bytes locally and emitting the measurement once before `performBinaryDownload` returns. - Rename `findReadyAgent` -> `resolveAgent`, phase `agent_ready` -> `resolve_agent`, parameter `setupContext` -> `context`. - Add unit tests for `ActivationTelemetry` and `RemoteSetupTelemetry`. --- src/core/cliManager.ts | 147 ++++++++++-------- src/extension.ts | 2 +- src/instrumentation/activation.ts | 16 +- src/instrumentation/remoteSetup.ts | 10 +- src/remote/remote.ts | 100 ++++++------ src/telemetry/service.ts | 18 ++- test/unit/core/cliManager.test.ts | 43 ++++- test/unit/instrumentation/activation.test.ts | 102 ++++++++++++ test/unit/instrumentation/remoteSetup.test.ts | 79 ++++++++++ test/unit/telemetry/service.test.ts | 40 ++++- 10 files changed, 428 insertions(+), 129 deletions(-) create mode 100644 test/unit/instrumentation/activation.test.ts create mode 100644 test/unit/instrumentation/remoteSetup.test.ts diff --git a/src/core/cliManager.ts b/src/core/cliManager.ts index 3674fdc7..13e2bb4f 100644 --- a/src/core/cliManager.ts +++ b/src/core/cliManager.ts @@ -26,6 +26,7 @@ import type { IncomingMessage } from "node:http"; import type { Logger } from "../logging/logger"; import type { TelemetryService } from "../telemetry/service"; +import type { Span } from "../telemetry/span"; import type { CliCredentialManager } from "./cliCredentialManager"; import type { PathResolver } from "./pathResolver"; @@ -34,7 +35,14 @@ type ResolvedBinary = | { binPath: string; stat: Stats; source: "file-path" | "directory" } | { binPath: string; source: "not-found" }; -type CliDownloadReason = "missing" | "version_mismatch"; +type CliDownloadReason = "missing" | "version_mismatch" | "unreadable"; + +type CliVerifyOutcome = "verified" | "bypassed" | "sig_not_found"; + +type SingleVerifyResult = + | { kind: "verified" } + | { kind: "bypassed" } + | { kind: "sig_unavailable"; status: number }; export class CliManager { private readonly binaryLock: BinaryLock; @@ -144,9 +152,11 @@ export class CliManager { ); let existingVersion: string | null = null; - const downloadReason: CliDownloadReason = - resolved.source === "not-found" ? "missing" : "version_mismatch"; - if (resolved.source !== "not-found") { + let downloadReason: CliDownloadReason; + if (resolved.source === "not-found") { + downloadReason = "missing"; + this.output.info("No existing binary found, starting download"); + } else { this.output.debug( "Existing binary size is", prettyBytes(resolved.stat.size), @@ -154,14 +164,14 @@ export class CliManager { try { existingVersion = await cliVersion(resolved.binPath); this.output.debug("Existing binary version is", existingVersion); + downloadReason = "version_mismatch"; } catch (error) { this.output.warn( "Unable to get version of existing binary, downloading instead", error, ); + downloadReason = "unreadable"; } - } else { - this.output.info("No existing binary found, starting download"); } if (existingVersion === buildInfo.version) { @@ -238,11 +248,7 @@ export class CliManager { latestVersion, downloadBinPath, progressLogPath, - (downloadedBytes) => { - if (downloadedBytes > 0) { - span.setMeasurement("downloadedBytes", downloadedBytes); - } - }, + span, ); return this.renameToFinalPath(resolved, downloadedBinPath); }, @@ -430,11 +436,14 @@ export class CliManager { parsedVersion: semver.SemVer, binPath: string, progressLogPath: string, - recordDownloadedBytes: (downloadedBytes: number) => void, + downloadSpan: Span, ): Promise { const cfg = vscode.workspace.getConfiguration("coder"); const tempFile = tempFilePath(binPath, "temp"); + // Tracked locally because onProgress can fire after the trace closes. + let bytesWritten = 0; + try { const removed = await cliUtils.rmOld(binPath); for (const { fileName, error } of removed) { @@ -467,7 +476,7 @@ export class CliManager { bytesDownloaded: number, totalBytes: number | null, ) => { - recordDownloadedBytes(bytesDownloaded); + bytesWritten = bytesDownloaded; await downloadProgress.writeProgress(progressLogPath, { bytesDownloaded, totalBytes, @@ -499,19 +508,24 @@ export class CliManager { "Skipping binary signature verification due to settings", ); } else { - await this.telemetry.trace("cli.verify", () => - this.verifyBinarySignatures(client, tempFile, [ - // A signature placed at the same level as the binary. It must be - // named exactly the same with an appended `.asc` (such as - // coder-windows-amd64.exe.asc or coder-linux-amd64.asc). - binSource + ".asc", - // The releases.coder.com bucket does not include the leading "v", - // and unlike what we get from buildinfo it uses a truncated version - // with only major.minor.patch. The signature name follows the same - // rule as above. - `https://releases.coder.com/coder-cli/${parsedVersion.major}.${parsedVersion.minor}.${parsedVersion.patch}/${binName}.asc`, - ]), - ); + await downloadSpan.phase("verify", async (verifySpan) => { + const outcome = await this.verifyBinarySignatures( + client, + tempFile, + [ + // A signature placed at the same level as the binary. It must be + // named exactly the same with an appended `.asc` (such as + // coder-windows-amd64.exe.asc or coder-linux-amd64.asc). + binSource + ".asc", + // The releases.coder.com bucket does not include the leading "v", + // and unlike what we get from buildinfo it uses a truncated version + // with only major.minor.patch. The signature name follows the same + // rule as above. + `https://releases.coder.com/coder-cli/${parsedVersion.major}.${parsedVersion.minor}.${parsedVersion.patch}/${binName}.asc`, + ], + ); + verifySpan.setProperty("outcome", outcome); + }); } // Replace existing binary (handles both renames + Windows lock) @@ -569,6 +583,9 @@ export class CliManager { } } } finally { + if (bytesWritten > 0) { + downloadSpan.setMeasurement("downloadedBytes", bytesWritten); + } await downloadProgress.clearProgress(progressLogPath); } } @@ -724,7 +741,7 @@ export class CliManager { client: AxiosInstance, cliPath: string, sources: string[], - ): Promise { + ): Promise { const publicKeys = await pgp.readPublicKeys(this.output); for (let i = 0; i < sources.length; ++i) { const source = sources[i]; @@ -733,14 +750,14 @@ export class CliManager { if (i === 1) { client = globalAxios.create(); } - const status = await this.verifyBinarySignature( + const result = await this.verifyBinarySignature( client, cliPath, publicKeys, source, ); - if (status === 200) { - return; + if (result.kind === "verified" || result.kind === "bypassed") { + return result.kind; } // If we failed to download, try the next source. let nextPrompt = ""; @@ -752,14 +769,16 @@ export class CliManager { } options.push("Run without verification"); const action = await vscodeProposed.window.showWarningMessage( - status === 404 ? "Signature not found" : "Failed to download signature", + result.status === 404 + ? "Signature not found" + : "Failed to download signature", { useCustom: true, modal: true, detail: - status === 404 + result.status === 404 ? `No binary signature was found at ${source}.${nextPrompt}` - : `Received ${status} trying to download binary signature from ${source}.${nextPrompt}`, + : `Received ${result.status} trying to download binary signature from ${source}.${nextPrompt}`, }, ...options, ); @@ -770,7 +789,7 @@ export class CliManager { case "Run without verification": this.output.info(`Signature download from ${nextSource} declined`); this.output.info("Binary will be ran anyway at user request"); - return; + return "sig_not_found"; default: this.output.info(`Signature download from ${nextSource} declined`); this.output.info("Binary was rejected at user request"); @@ -791,41 +810,43 @@ export class CliManager { cliPath: string, publicKeys: pgp.Key[], source: string, - ): Promise { + ): Promise { this.output.info("Downloading signature from", source); const signaturePath = path.join(cliPath + ".asc"); const writeStream = createWriteStream(signaturePath); const status = await this.download(client, source, writeStream); - if (status === 200) { - try { - await pgp.verifySignature( - publicKeys, - cliPath, - signaturePath, - this.output, - ); - } catch (error) { - const action = await vscodeProposed.window.showWarningMessage( - // VerificationError should be the only thing that throws, but - // unfortunately caught errors are always type unknown. - error instanceof pgp.VerificationError - ? error.summary() - : "Failed to verify signature", - { - useCustom: true, - modal: true, - detail: `${errToStr(error)} Would you like to accept this risk and run the binary anyway?`, - }, - "Run anyway", - ); - if (!action) { - this.output.info("Binary was rejected at user request"); - throw new Error("Signature verification aborted", { cause: error }); - } - this.output.info("Binary will be ran anyway at user request"); + if (status !== 200) { + return { kind: "sig_unavailable", status }; + } + try { + await pgp.verifySignature( + publicKeys, + cliPath, + signaturePath, + this.output, + ); + return { kind: "verified" }; + } catch (error) { + const action = await vscodeProposed.window.showWarningMessage( + // VerificationError should be the only thing that throws, but + // unfortunately caught errors are always type unknown. + error instanceof pgp.VerificationError + ? error.summary() + : "Failed to verify signature", + { + useCustom: true, + modal: true, + detail: `${errToStr(error)} Would you like to accept this risk and run the binary anyway?`, + }, + "Run anyway", + ); + if (!action) { + this.output.info("Binary was rejected at user request"); + throw new Error("Signature verification aborted", { cause: error }); } + this.output.info("Binary will be ran anyway at user request"); + return { kind: "bypassed" }; } - return status; } /** diff --git a/src/extension.ts b/src/extension.ts index d4c4f25d..7972774d 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -98,7 +98,7 @@ async function doActivate( const deploymentSessionAuth = deployment ? await secretsManager.getSessionAuth(deployment.safeHostname) : undefined; - tracer.setAuthState(deploymentSessionAuth ? "valid_token" : "none"); + tracer.setAuthState(deploymentSessionAuth ? "stored" : "none"); // Shared handler for auth failures (used by interceptor + session manager) const handleAuthFailure = (): Promise => { diff --git a/src/instrumentation/activation.ts b/src/instrumentation/activation.ts index af4e60f9..ecbf35d3 100644 --- a/src/instrumentation/activation.ts +++ b/src/instrumentation/activation.ts @@ -1,6 +1,15 @@ import type { TelemetryService } from "../telemetry/service"; -export type ActivationAuthState = "none" | "valid_token" | "expired"; +/** + * `none`: no stored token. `stored`: token present, not yet validated. + * `valid_token`/`expired`: post-validation. `unknown`: validation threw. + */ +export type ActivationAuthState = + | "none" + | "stored" + | "valid_token" + | "expired" + | "unknown"; /** Helpers scoped to the activation trace's lifetime. */ export interface ActivationTracer { @@ -8,6 +17,10 @@ export interface ActivationTracer { traceDeploymentInit(fn: () => Promise): Promise; } +/** + * Emits `activation` with `authState`, plus a sibling `activation.deployment_init` + * trace (sibling, not child, because deployment init outlives the activation span). + */ export class ActivationTelemetry { public constructor(private readonly telemetry: TelemetryService) {} @@ -20,6 +33,7 @@ export class ActivationTelemetry { this.telemetry.trace( "activation.deployment_init", async (childSpan) => { + childSpan.setProperty("authState", "unknown"); const success = await initFn(); childSpan.setProperty( "authState", diff --git a/src/instrumentation/remoteSetup.ts b/src/instrumentation/remoteSetup.ts index ce50082f..8ceb68a6 100644 --- a/src/instrumentation/remoteSetup.ts +++ b/src/instrumentation/remoteSetup.ts @@ -1,17 +1,22 @@ import type { TelemetryService } from "../telemetry/service"; export type RemoteSetupPhase = - | "auth_retrieval" | "workspace_lookup" | "workspace_ready" - | "agent_ready" + | "resolve_agent" | "ssh_config_write"; +/** Outcome on the parent `remote.setup` event for non-throwing early exits. */ +export type RemoteSetupOutcome = "workspace_not_found" | "incompatible_server"; + /** Helpers scoped to the remote.setup trace's lifetime. */ export interface RemoteSetupTracer { phase(name: RemoteSetupPhase, fn: () => T | PromiseLike): Promise; + /** Annotate the parent event for non-throwing exits (e.g. workspace 404). */ + setOutcome(outcome: RemoteSetupOutcome): void; } +/** Emits `remote.setup` with typed child phases and an `outcome` property. */ export class RemoteSetupTelemetry { public constructor(private readonly telemetry: TelemetryService) {} @@ -20,6 +25,7 @@ export class RemoteSetupTelemetry { fn({ phase: (name, phaseFn) => span.phase(name, () => Promise.resolve(phaseFn())), + setOutcome: (outcome) => span.setProperty("outcome", outcome), }), ); } diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 7d754408..2080c92c 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -82,6 +82,7 @@ interface RemoteSetupArgs { remoteSshExtensionId: string; } +/** Per-attempt state for the remote setup flow, threaded through helpers. */ interface RemoteSetupContext { args: RemoteSetupArgs; parts: AuthorityParts; @@ -138,46 +139,59 @@ export class Remote { agent: parts.agent || "(default)", }); + // Both run before `remote.setup` so an auth-required retry doesn't nest + // traces, and migration is kept out of `remote.auth_retrieval` so a slow + // first-run migration doesn't pollute that signal. + await this.migrateToSecretsStorage(parts.safeHostname); + const telemetry = this.serviceContainer.getTelemetryService(); + const auth = await telemetry.trace("remote.auth_retrieval", () => + this.secretsManager.getSessionAuth(parts.safeHostname), + ); + if (auth?.url) { + telemetry.setDeploymentUrl(auth.url); + } + this.logger.debug("Retrieved auth for hostname", { + hostname: parts.safeHostname, + hasUrl: Boolean(auth?.url), + hasToken: auth?.token !== undefined, + }); + const args: RemoteSetupArgs = { remoteAuthority, startupMode, remoteSshExtensionId, }; const workspaceName = `${parts.username}/${parts.workspace}`; + const context: RemoteSetupContext = { + args, + parts, + workspaceName, + baseUrl: auth?.url ?? "", + token: auth?.token, + disposables: [], + }; - return this.setupTelemetry.trace(async (tracer) => { - const auth = await tracer.phase("auth_retrieval", async () => { - await this.migrateToSecretsStorage(parts.safeHostname); - return this.secretsManager.getSessionAuth(parts.safeHostname); - }); - if (auth?.url) { - this.serviceContainer.getTelemetryService().setDeploymentUrl(auth.url); - } - this.logger.debug("Retrieved auth for hostname", { - hostname: parts.safeHostname, - hasUrl: Boolean(auth?.url), - hasToken: auth?.token !== undefined, - }); - return this.setupCoderRemote( - { - args, - parts, - workspaceName, - baseUrl: auth?.url ?? "", - token: auth?.token, - disposables: [], - }, - tracer, + if ( + !context.baseUrl || + (!context.token && needToken(vscode.workspace.getConfiguration())) + ) { + return this.ensureLoggedInAndRetry( + context, + "You are not logged in...", + context.baseUrl, ); - }); + } + + return this.setupTelemetry.trace((tracer) => + this.setupCoderRemote(context, tracer), + ); } private async setupCoderRemote( - setupContext: RemoteSetupContext, + context: RemoteSetupContext, tracer: RemoteSetupTracer, ): Promise { - const { args, parts, workspaceName, baseUrl, token, disposables } = - setupContext; + const { args, parts, workspaceName, baseUrl, token, disposables } = context; try { // Create OAuth session manager for this remote deployment @@ -185,23 +199,11 @@ export class Remote { { url: baseUrl, safeHostname: parts.safeHostname }, this.serviceContainer, async () => { - await this.showSessionExpiredDialog(setupContext); + await this.showSessionExpiredDialog(context); }, ); disposables.push(remoteOAuthManager); - // It could be that the cli config was deleted. If so, ask for the url. - if ( - !baseUrl || - (!token && needToken(vscode.workspace.getConfiguration())) - ) { - return this.ensureLoggedInAndRetry( - setupContext, - "You are not logged in...", - baseUrl, - ); - } - this.logger.info("Using deployment URL", baseUrl); this.logger.info("Using hostname", parts.safeHostname || "n/a"); @@ -220,7 +222,7 @@ export class Remote { remoteOAuthManager, this.secretsManager, async () => { - const result = await this.showSessionExpiredDialog(setupContext); + const result = await this.showSessionExpiredDialog(context); return result.success; }, ); @@ -237,9 +239,7 @@ export class Remote { } // Listen for token changes for this deployment - disposables.push( - this.watchRemoteSessionAuth(setupContext, workspaceClient), - ); + disposables.push(this.watchRemoteSessionAuth(context, workspaceClient)); // First thing is to check the version. const buildInfo = await workspaceClient.getBuildInfo(); @@ -264,6 +264,7 @@ export class Remote { // Server versions before v0.14.1 don't support the vscodessh command! if (!featureSet.vscodessh) { + tracer.setOutcome("incompatible_server"); await vscodeProposed.window.showErrorMessage( "Incompatible Server", { @@ -283,9 +284,10 @@ export class Remote { // Next is to find the workspace from the URI scheme provided. const foundWorkspace = await tracer.phase("workspace_lookup", () => - this.lookupWorkspace(setupContext, workspaceClient), + this.lookupWorkspace(context, workspaceClient), ); if (!foundWorkspace) { + tracer.setOutcome("workspace_not_found"); return; } let workspace: Workspace = foundWorkspace; @@ -341,8 +343,8 @@ export class Remote { // Mark initial setup as complete so the monitor can start notifying about state changes monitor.markInitialSetupComplete(); - const agent = await tracer.phase("agent_ready", () => - this.findReadyAgent(setupContext, workspace, stateMachine), + const agent = await tracer.phase("resolve_agent", () => + this.resolveAgent(context, workspace, stateMachine), ); // Watch coder inbox for messages @@ -353,7 +355,7 @@ export class Remote { const computedSshProperties = await tracer.phase("ssh_config_write", () => this.writeRemoteSshConfig( - setupContext, + context, workspaceClient, binaryPath, logDir, @@ -579,7 +581,7 @@ export class Remote { ); } - private findReadyAgent( + private resolveAgent( context: RemoteSetupContext, workspace: Workspace, stateMachine: WorkspaceStateMachine, diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index bd1ed564..447ed6b7 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -144,6 +144,12 @@ export class TelemetryService implements vscode.Disposable { const spanProperties = { ...properties }; const spanMeasurements = { ...measurements }; const { traceId, traceLevel } = spanOpts; + let completed = false; + const warnPostEmit = (op: string, name: string): void => { + this.logger.warn( + `Telemetry span '${eventName}' ${op}('${name}') called after emit; mutation dropped`, + ); + }; const span: Span = { traceId, eventId, @@ -164,9 +170,17 @@ export class TelemetryService implements vscode.Disposable { ); }, setProperty(name: string, value: string): void { + if (completed) { + warnPostEmit("setProperty", name); + return; + } spanProperties[name] = value; }, setMeasurement(name: string, value: number): void { + if (completed) { + warnPostEmit("setMeasurement", name); + return; + } spanMeasurements[name] = value; }, }; @@ -177,7 +191,9 @@ export class TelemetryService implements vscode.Disposable { spanProperties, spanMeasurements, spanOpts, - ); + ).finally(() => { + completed = true; + }); } #sanitizePhaseName(name: string): string { diff --git a/test/unit/core/cliManager.test.ts b/test/unit/core/cliManager.test.ts index 0e81bd31..4a8d8619 100644 --- a/test/unit/core/cliManager.test.ts +++ b/test/unit/core/cliManager.test.ts @@ -838,22 +838,53 @@ describe("CliManager", () => { }); }); - describe("cli.verify", () => { + describe("cli.download.verify", () => { beforeEach(() => { mockConfig.set("coder.disableSignatureVerification", false); withSuccessfulDownload(); + }); + + it("emits outcome=verified on valid signature", async () => { withSignatureResponses([200]); + await manager.fetchBinary(mockApi); + + const verify = event("cli.download.verify"); + const download = event("cli.download"); + expect(verify).toMatchObject({ + properties: { outcome: "verified", result: "success" }, + }); + expect(verify?.measurements.durationMs).toBeGreaterThanOrEqual(0); + expect(verify?.traceId).toBe(download?.traceId); + expect(verify?.parentEventId).toBe(download?.eventId); }); - it("emits success on valid signature", async () => { + it("emits outcome=bypassed when user runs anyway despite invalid signature", async () => { + withSignatureResponses([200]); + vi.mocked(pgp.verifySignature).mockRejectedValueOnce( + createVerificationError("Invalid signature"), + ); + mockUI.setResponse("Signature does not match", "Run anyway"); + await manager.fetchBinary(mockApi); - const e = event("cli.verify"); - expect(e).toMatchObject({ properties: { result: "success" } }); - expect(e?.measurements.durationMs).toBeGreaterThanOrEqual(0); + expect(event("cli.download.verify")).toMatchObject({ + properties: { outcome: "bypassed", result: "success" }, + }); + }); + + it("emits outcome=sig_not_found when user runs without verification", async () => { + withSignatureResponses([404, 404]); + mockUI.setResponse("Signature not found", "Run without verification"); + + await manager.fetchBinary(mockApi); + + expect(event("cli.download.verify")).toMatchObject({ + properties: { outcome: "sig_not_found", result: "success" }, + }); }); it("emits error when verification is aborted", async () => { + withSignatureResponses([200]); vi.mocked(pgp.verifySignature).mockRejectedValueOnce( createVerificationError("Invalid signature"), ); @@ -863,7 +894,7 @@ describe("CliManager", () => { "Signature verification aborted", ); - expect(event("cli.verify")).toMatchObject({ + expect(event("cli.download.verify")).toMatchObject({ properties: { result: "error" }, error: { message: "Signature verification aborted" }, }); diff --git a/test/unit/instrumentation/activation.test.ts b/test/unit/instrumentation/activation.test.ts new file mode 100644 index 00000000..6f77099a --- /dev/null +++ b/test/unit/instrumentation/activation.test.ts @@ -0,0 +1,102 @@ +import { describe, expect, it } from "vitest"; + +import { ActivationTelemetry } from "@/instrumentation/activation"; + +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { MockConfigurationProvider } from "../../mocks/testHelpers"; + +function makeHarness() { + new MockConfigurationProvider().set("coder.telemetry.level", "local"); + const sink = new TestSink(); + return { + sink, + activation: new ActivationTelemetry(createTestTelemetryService(sink)), + }; +} + +const find = (sink: TestSink, name: string) => + sink.events.find((e) => e.eventName === name); + +describe("ActivationTelemetry.trace", () => { + it("emits one 'activation' event with default authState=none", async () => { + const { sink, activation } = makeHarness(); + await activation.trace(() => Promise.resolve()); + + expect(sink.events).toHaveLength(1); + expect(sink.events[0]).toMatchObject({ + eventName: "activation", + properties: { authState: "none", result: "success" }, + }); + }); + + it("setAuthState records the last value set during the trace", async () => { + const { sink, activation } = makeHarness(); + await activation.trace((tracer) => { + tracer.setAuthState("stored"); + tracer.setAuthState("valid_token"); + return Promise.resolve(); + }); + + expect(sink.events[0].properties.authState).toBe("valid_token"); + }); + + it("rethrows fn errors and emits result=error with the default authState", async () => { + const { sink, activation } = makeHarness(); + const boom = new Error("nope"); + + await expect(activation.trace(() => Promise.reject(boom))).rejects.toBe( + boom, + ); + expect(sink.events[0]).toMatchObject({ + properties: { authState: "none", result: "error" }, + error: { message: "nope" }, + }); + }); +}); + +describe("ActivationTelemetry.traceDeploymentInit", () => { + it("emits a sibling trace with its own traceId", async () => { + const { sink, activation } = makeHarness(); + await activation.trace((tracer) => + tracer.traceDeploymentInit(() => Promise.resolve(true)), + ); + + const init = find(sink, "activation.deployment_init"); + const parent = find(sink, "activation"); + expect(init?.parentEventId).toBeUndefined(); + expect(init?.traceId).not.toBe(parent?.traceId); + }); + + it.each([ + { ret: true, expected: "valid_token" }, + { ret: false, expected: "expired" }, + ])( + "maps initFn returning $ret to authState=$expected", + async ({ ret, expected }) => { + const { sink, activation } = makeHarness(); + await activation.trace((tracer) => + tracer.traceDeploymentInit(() => Promise.resolve(ret)), + ); + + expect(find(sink, "activation.deployment_init")).toMatchObject({ + properties: { authState: expected, result: "success" }, + }); + }, + ); + + it("records authState=unknown when initFn throws", async () => { + const { sink, activation } = makeHarness(); + const boom = new Error("init failed"); + + await activation.trace(async (tracer) => { + await expect( + tracer.traceDeploymentInit(() => Promise.reject(boom)), + ).rejects.toBe(boom); + }); + + expect(find(sink, "activation.deployment_init")).toMatchObject({ + properties: { authState: "unknown", result: "error" }, + error: { message: "init failed" }, + }); + }); +}); diff --git a/test/unit/instrumentation/remoteSetup.test.ts b/test/unit/instrumentation/remoteSetup.test.ts new file mode 100644 index 00000000..33cf5ff6 --- /dev/null +++ b/test/unit/instrumentation/remoteSetup.test.ts @@ -0,0 +1,79 @@ +import { describe, expect, it } from "vitest"; + +import { RemoteSetupTelemetry } from "@/instrumentation/remoteSetup"; + +import { createTestTelemetryService, TestSink } from "../../mocks/telemetry"; +import { MockConfigurationProvider } from "../../mocks/testHelpers"; + +function makeHarness() { + new MockConfigurationProvider().set("coder.telemetry.level", "local"); + const sink = new TestSink(); + return { + sink, + remoteSetup: new RemoteSetupTelemetry(createTestTelemetryService(sink)), + }; +} + +describe("RemoteSetupTelemetry", () => { + it("emits a single 'remote.setup' event when no phases run", async () => { + const { sink, remoteSetup } = makeHarness(); + await remoteSetup.trace(() => Promise.resolve()); + + expect(sink.events).toHaveLength(1); + expect(sink.events[0]).toMatchObject({ + eventName: "remote.setup", + properties: { result: "success" }, + }); + expect(sink.events[0].properties.outcome).toBeUndefined(); + }); + + it("emits each named phase as a child of remote.setup with shared traceId", async () => { + const { sink, remoteSetup } = makeHarness(); + await remoteSetup.trace(async (tracer) => { + await tracer.phase("workspace_lookup", () => "ws"); + await tracer.phase("ssh_config_write", () => Promise.resolve("cfg")); + }); + + const [lookup, sshWrite, parent] = sink.events; + expect(lookup.eventName).toBe("remote.setup.workspace_lookup"); + expect(sshWrite.eventName).toBe("remote.setup.ssh_config_write"); + expect(parent.eventName).toBe("remote.setup"); + expect(lookup.traceId).toBe(parent.traceId); + expect(sshWrite.traceId).toBe(parent.traceId); + expect(lookup.parentEventId).toBe(parent.eventId); + expect(sshWrite.parentEventId).toBe(parent.eventId); + }); + + it("setOutcome annotates the parent event for non-throwing exits", async () => { + const { sink, remoteSetup } = makeHarness(); + await remoteSetup.trace((tracer) => { + tracer.setOutcome("workspace_not_found"); + return Promise.resolve(); + }); + + expect(sink.events[0]).toMatchObject({ + properties: { outcome: "workspace_not_found", result: "success" }, + }); + }); + + it("propagates errors from phases up through the parent", async () => { + const { sink, remoteSetup } = makeHarness(); + const boom = new Error("phase broke"); + + await expect( + remoteSetup.trace((tracer) => + tracer.phase("workspace_lookup", () => Promise.reject(boom)), + ), + ).rejects.toBe(boom); + + const [phase, parent] = sink.events; + expect(phase).toMatchObject({ + eventName: "remote.setup.workspace_lookup", + properties: { result: "error" }, + }); + expect(parent).toMatchObject({ + properties: { result: "error" }, + error: { message: "phase broke" }, + }); + }); +}); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index 4a08f4dd..f97c7af1 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -9,6 +9,9 @@ import { MockConfigurationProvider, } from "../../mocks/testHelpers"; +import type { Logger } from "@/logging/logger"; +import type { Span } from "@/telemetry/span"; + const TEST_VERSION = "1.2.3-test"; const TEST_SESSION_ID = "test-session"; @@ -18,18 +21,16 @@ interface Harness { service: TelemetryService; sink: TestSink; config: MockConfigurationProvider; + logger: Logger; } function makeHarness(level: "off" | "local" = "local"): Harness { const config = new MockConfigurationProvider(); config.set("coder.telemetry.level", level); const sink = new TestSink(); - const service = new TelemetryService( - testSession(), - [sink], - createMockLogger(), - ); - return { service, sink, config }; + const logger = createMockLogger(); + const service = new TelemetryService(testSession(), [sink], logger); + return { service, sink, config, logger }; } function makeService(sinks: TelemetrySink[]): TelemetryService { @@ -291,6 +292,33 @@ describe("TelemetryService", () => { expect(phase.eventName).toBe("op.bad_name"); }); + it("warns and ignores setProperty/setMeasurement called after emit", async () => { + let escapedSpan: Span | undefined; + await h.service.trace("op", (span) => { + escapedSpan = span; + return Promise.resolve(); + }); + + expect(h.sink.events).toHaveLength(1); + const warnBefore = vi.mocked(h.logger.warn).mock.calls.length; + + escapedSpan?.setProperty("late", "ignored"); + escapedSpan?.setMeasurement("lateMs", 99); + + // Mutations dropped: emitted event is unchanged. + expect(h.sink.events[0].properties.late).toBeUndefined(); + expect(h.sink.events[0].measurements.lateMs).toBeUndefined(); + + // Each post-emit mutation logs a warning. + expect(vi.mocked(h.logger.warn).mock.calls.length).toBe(warnBefore + 2); + expect(vi.mocked(h.logger.warn).mock.calls[warnBefore][0]).toContain( + "setProperty", + ); + expect(vi.mocked(h.logger.warn).mock.calls[warnBefore + 1][0]).toContain( + "setMeasurement", + ); + }); + 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"); From 41ffe70c175849e57b5f533091c4c85db737b205 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Fri, 8 May 2026 21:28:53 +0300 Subject: [PATCH 5/5] refactor(telemetry): tighten authState and verify outcome labels Address R2 review feedback: - Rename `authState: "expired"` -> `"auth_failed"`. The label no longer asserts token expiration when `setDeploymentIfValid` returns false for any failure (401, network/DNS, cert, server errors). - Record `sigStatus` (HTTP status) alongside `outcome: "sig_not_found"` on `cli.download.verify`, distinguishing 404 (no signatures published) from 5xx (signature download failure) without changing the outcome label. - Cover the `unreadable` download reason in the parametric `cli.download` telemetry test. --- src/core/cliManager.ts | 18 ++++-- src/extension.ts | 2 +- src/instrumentation/activation.ts | 8 ++- test/unit/core/cliManager.test.ts | 66 +++++++++++--------- test/unit/instrumentation/activation.test.ts | 2 +- 5 files changed, 55 insertions(+), 41 deletions(-) diff --git a/src/core/cliManager.ts b/src/core/cliManager.ts index 13e2bb4f..e5eaa04d 100644 --- a/src/core/cliManager.ts +++ b/src/core/cliManager.ts @@ -37,7 +37,10 @@ type ResolvedBinary = type CliDownloadReason = "missing" | "version_mismatch" | "unreadable"; -type CliVerifyOutcome = "verified" | "bypassed" | "sig_not_found"; +type CliVerifyResult = + | { kind: "verified" } + | { kind: "bypassed" } + | { kind: "sig_not_found"; status: number }; type SingleVerifyResult = | { kind: "verified" } @@ -509,7 +512,7 @@ export class CliManager { ); } else { await downloadSpan.phase("verify", async (verifySpan) => { - const outcome = await this.verifyBinarySignatures( + const result = await this.verifyBinarySignatures( client, tempFile, [ @@ -524,7 +527,10 @@ export class CliManager { `https://releases.coder.com/coder-cli/${parsedVersion.major}.${parsedVersion.minor}.${parsedVersion.patch}/${binName}.asc`, ], ); - verifySpan.setProperty("outcome", outcome); + verifySpan.setProperty("outcome", result.kind); + if (result.kind === "sig_not_found") { + verifySpan.setProperty("sigStatus", String(result.status)); + } }); } @@ -741,7 +747,7 @@ export class CliManager { client: AxiosInstance, cliPath: string, sources: string[], - ): Promise { + ): Promise { const publicKeys = await pgp.readPublicKeys(this.output); for (let i = 0; i < sources.length; ++i) { const source = sources[i]; @@ -757,7 +763,7 @@ export class CliManager { source, ); if (result.kind === "verified" || result.kind === "bypassed") { - return result.kind; + return { kind: result.kind }; } // If we failed to download, try the next source. let nextPrompt = ""; @@ -789,7 +795,7 @@ export class CliManager { case "Run without verification": this.output.info(`Signature download from ${nextSource} declined`); this.output.info("Binary will be ran anyway at user request"); - return "sig_not_found"; + return { kind: "sig_not_found", status: result.status }; default: this.output.info(`Signature download from ${nextSource} declined`); this.output.info("Binary was rejected at user request"); diff --git a/src/extension.ts b/src/extension.ts index 7972774d..cf310bce 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -400,7 +400,7 @@ async function doActivate( url: details.url, token: details.token, }); - tracer.setAuthState(deploymentSet ? "valid_token" : "expired"); + tracer.setAuthState(deploymentSet ? "valid_token" : "auth_failed"); // If a deep link stored a chat agent ID before the // remote-authority reload, open it now that the diff --git a/src/instrumentation/activation.ts b/src/instrumentation/activation.ts index ecbf35d3..e4f6acdb 100644 --- a/src/instrumentation/activation.ts +++ b/src/instrumentation/activation.ts @@ -2,13 +2,15 @@ import type { TelemetryService } from "../telemetry/service"; /** * `none`: no stored token. `stored`: token present, not yet validated. - * `valid_token`/`expired`: post-validation. `unknown`: validation threw. + * `valid_token`: server validation passed. `auth_failed`: validation returned + * false (covers expiration, network/DNS, cert, server errors — the boolean + * doesn't distinguish). `unknown`: validation threw before classification. */ export type ActivationAuthState = | "none" | "stored" | "valid_token" - | "expired" + | "auth_failed" | "unknown"; /** Helpers scoped to the activation trace's lifetime. */ @@ -37,7 +39,7 @@ export class ActivationTelemetry { const success = await initFn(); childSpan.setProperty( "authState", - success ? "valid_token" : "expired", + success ? "valid_token" : "auth_failed", ); return success; }, diff --git a/test/unit/core/cliManager.test.ts b/test/unit/core/cliManager.test.ts index 4a8d8619..4e0c185d 100644 --- a/test/unit/core/cliManager.test.ts +++ b/test/unit/core/cliManager.test.ts @@ -778,27 +778,23 @@ describe("CliManager", () => { telemetrySink.events.find((e) => e.eventName === name); it.each([ - { reason: "missing", existing: undefined }, - { reason: "version_mismatch", existing: "1.0.0" }, - ])( - "emits cli.download with reason=$reason", - async ({ reason, existing }) => { - if (existing) { - withExistingBinary(existing); - } - withSuccessfulDownload(); - await manager.fetchBinary(mockApi); + { reason: "missing", setup: () => {} }, + { reason: "version_mismatch", setup: () => withExistingBinary("1.0.0") }, + { reason: "unreadable", setup: () => withCorruptedBinary() }, + ])("emits cli.download with reason=$reason", async ({ reason, setup }) => { + setup(); + withSuccessfulDownload(); + await manager.fetchBinary(mockApi); - const e = event("cli.download"); - expect(e).toMatchObject({ - properties: { reason, result: "success" }, - }); - expect(e?.measurements.durationMs).toBeGreaterThanOrEqual(0); - expect(e?.measurements.downloadedBytes).toBe( - Buffer.byteLength(mockBinaryContent(TEST_VERSION)), - ); - }, - ); + const e = event("cli.download"); + expect(e).toMatchObject({ + properties: { reason, result: "success" }, + }); + expect(e?.measurements.durationMs).toBeGreaterThanOrEqual(0); + expect(e?.measurements.downloadedBytes).toBe( + Buffer.byteLength(mockBinaryContent(TEST_VERSION)), + ); + }); it("does not emit cli.download when a cached binary already matches", async () => { withExistingBinary(TEST_VERSION); @@ -872,16 +868,26 @@ describe("CliManager", () => { }); }); - it("emits outcome=sig_not_found when user runs without verification", async () => { - withSignatureResponses([404, 404]); - mockUI.setResponse("Signature not found", "Run without verification"); - - await manager.fetchBinary(mockApi); - - expect(event("cli.download.verify")).toMatchObject({ - properties: { outcome: "sig_not_found", result: "success" }, - }); - }); + it.each([ + { status: 404, message: "Signature not found" }, + { status: 500, message: "Failed to download signature" }, + ])( + "emits outcome=sig_not_found with sigStatus=$status when user runs without verification", + async ({ status, message }) => { + withSignatureResponses([status, status]); + mockUI.setResponse(message, "Run without verification"); + + await manager.fetchBinary(mockApi); + + expect(event("cli.download.verify")).toMatchObject({ + properties: { + outcome: "sig_not_found", + sigStatus: String(status), + result: "success", + }, + }); + }, + ); it("emits error when verification is aborted", async () => { withSignatureResponses([200]); diff --git a/test/unit/instrumentation/activation.test.ts b/test/unit/instrumentation/activation.test.ts index 6f77099a..80a64c62 100644 --- a/test/unit/instrumentation/activation.test.ts +++ b/test/unit/instrumentation/activation.test.ts @@ -69,7 +69,7 @@ describe("ActivationTelemetry.traceDeploymentInit", () => { it.each([ { ret: true, expected: "valid_token" }, - { ret: false, expected: "expired" }, + { ret: false, expected: "auth_failed" }, ])( "maps initFn returning $ret to authState=$expected", async ({ ret, expected }) => {