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 diff --git a/src/core/cliManager.ts b/src/core/cliManager.ts index 022d29a7..e5eaa04d 100644 --- a/src/core/cliManager.ts +++ b/src/core/cliManager.ts @@ -25,6 +25,8 @@ 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 { Span } from "../telemetry/span"; import type { CliCredentialManager } from "./cliCredentialManager"; import type { PathResolver } from "./pathResolver"; @@ -33,6 +35,18 @@ type ResolvedBinary = | { binPath: string; stat: Stats; source: "file-path" | "directory" } | { binPath: string; source: "not-found" }; +type CliDownloadReason = "missing" | "version_mismatch" | "unreadable"; + +type CliVerifyResult = + | { kind: "verified" } + | { kind: "bypassed" } + | { kind: "sig_not_found"; status: number }; + +type SingleVerifyResult = + | { kind: "verified" } + | { kind: "bypassed" } + | { kind: "sig_unavailable"; status: number }; + export class CliManager { private readonly binaryLock: BinaryLock; @@ -40,6 +54,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,7 +155,11 @@ export class CliManager { ); let existingVersion: string | null = null; - 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), @@ -148,14 +167,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) { @@ -224,13 +243,20 @@ export class CliManager { latestVersion = latestParsedVersion; } - await this.performBinaryDownload( - restClient, - latestVersion, - downloadBinPath, - progressLogPath, + return await this.telemetry.trace( + "cli.download", + async (span) => { + const downloadedBinPath = await this.performBinaryDownload( + restClient, + latestVersion, + downloadBinPath, + progressLogPath, + span, + ); + return this.renameToFinalPath(resolved, downloadedBinPath); + }, + { reason: downloadReason }, ); - return await this.renameToFinalPath(resolved, downloadBinPath); } catch (error) { const fallback = await this.handleAnyBinaryFailure( error, @@ -413,10 +439,14 @@ export class CliManager { parsedVersion: semver.SemVer, binPath: string, progressLogPath: string, + 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) { @@ -449,6 +479,7 @@ export class CliManager { bytesDownloaded: number, totalBytes: number | null, ) => { + bytesWritten = bytesDownloaded; await downloadProgress.writeProgress(progressLogPath, { bytesDownloaded, totalBytes, @@ -480,17 +511,27 @@ 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 downloadSpan.phase("verify", async (verifySpan) => { + const result = 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", result.kind); + if (result.kind === "sig_not_found") { + verifySpan.setProperty("sigStatus", String(result.status)); + } + }); } // Replace existing binary (handles both renames + Windows lock) @@ -548,6 +589,9 @@ export class CliManager { } } } finally { + if (bytesWritten > 0) { + downloadSpan.setMeasurement("downloadedBytes", bytesWritten); + } await downloadProgress.clearProgress(progressLogPath); } } @@ -584,6 +628,7 @@ export class CliManager { this.output.info("Got status code", resp.status); 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( @@ -599,9 +644,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, @@ -705,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]; @@ -714,14 +756,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 { kind: result.kind }; } // If we failed to download, try the next source. let nextPrompt = ""; @@ -733,14 +775,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, ); @@ -751,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; + 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"); @@ -772,41 +816,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/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..cf310bce 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -14,6 +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, + type ActivationTracer, +} from "./instrumentation/activation"; import { OAuthSessionManager } from "./oauth/sessionManager"; import { Remote } from "./remote/remote"; import { getRemoteSshExtension } from "./remote/sshExtension"; @@ -30,6 +34,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((tracer) => + doActivate(ctx, serviceContainer, tracer), + ); +} + +async function doActivate( + ctx: vscode.ExtensionContext, + serviceContainer: ServiceContainer, + 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! // @@ -59,9 +79,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 +92,13 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { 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; + tracer.setAuthState(deploymentSessionAuth ? "stored" : "none"); // Shared handler for auth failures (used by interceptor + session manager) const handleAuthFailure = (): Promise => { @@ -111,8 +135,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 +395,12 @@ 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, }); + 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 @@ -391,7 +415,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 +458,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 + tracer + .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..e4f6acdb --- /dev/null +++ b/src/instrumentation/activation.ts @@ -0,0 +1,50 @@ +import type { TelemetryService } from "../telemetry/service"; + +/** + * `none`: no stored token. `stored`: token present, not yet validated. + * `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" + | "auth_failed" + | "unknown"; + +/** Helpers scoped to the activation trace's lifetime. */ +export interface ActivationTracer { + setAuthState(state: ActivationAuthState): void; + 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) {} + + public trace(fn: (tracer: ActivationTracer) => Promise): Promise { + return this.telemetry.trace("activation", async (span) => { + span.setProperty("authState", "none"); + return fn({ + setAuthState: (state) => span.setProperty("authState", state), + traceDeploymentInit: (initFn) => + this.telemetry.trace( + "activation.deployment_init", + async (childSpan) => { + childSpan.setProperty("authState", "unknown"); + const success = await initFn(); + childSpan.setProperty( + "authState", + success ? "valid_token" : "auth_failed", + ); + return success; + }, + ), + }); + }); + } +} diff --git a/src/instrumentation/remoteSetup.ts b/src/instrumentation/remoteSetup.ts new file mode 100644 index 00000000..8ceb68a6 --- /dev/null +++ b/src/instrumentation/remoteSetup.ts @@ -0,0 +1,32 @@ +import type { TelemetryService } from "../telemetry/service"; + +export type RemoteSetupPhase = + | "workspace_lookup" + | "workspace_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) {} + + public trace(fn: (tracer: RemoteSetupTracer) => Promise): Promise { + return this.telemetry.trace("remote.setup", (span) => + 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 0f8714d5..2080c92c 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -32,6 +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, + type RemoteSetupTracer, +} from "../instrumentation/remoteSetup"; import { type Logger } from "../logging/logger"; import { type LoginCoordinator } from "../login/loginCoordinator"; import { OAuthSessionManager } from "../oauth/sessionManager"; @@ -45,6 +49,7 @@ import { import { getHeaderCommand } from "../settings/headers"; import { AuthorityPrefix, + type AuthorityParts, escapeCommandArg, expandPath, parseRemoteAuthority, @@ -70,6 +75,23 @@ export interface RemoteDetails extends vscode.Disposable { token: string; } +/** Original {@link Remote.setup} args; retained so auth retries can re-invoke. */ +interface RemoteSetupArgs { + remoteAuthority: string; + startupMode: StartupMode; + remoteSshExtensionId: string; +} + +/** Per-attempt state for the remote setup flow, threaded through helpers. */ +interface RemoteSetupContext { + args: RemoteSetupArgs; + parts: AuthorityParts; + workspaceName: string; + baseUrl: string; + token: string | undefined; + disposables: vscode.Disposable[]; +} + export class Remote { private readonly logger: Logger; private readonly pathResolver: PathResolver; @@ -77,6 +99,7 @@ export class Remote { private readonly contextManager: ContextManager; private readonly secretsManager: SecretsManager; private readonly loginCoordinator: LoginCoordinator; + private readonly setupTelemetry: RemoteSetupTelemetry; public constructor( private readonly serviceContainer: ServiceContainer, @@ -89,6 +112,9 @@ export class Remote { this.contextManager = serviceContainer.getContextManager(); this.secretsManager = serviceContainer.getSecretsManager(); this.loginCoordinator = serviceContainer.getLoginCoordinator(); + this.setupTelemetry = new RemoteSetupTelemetry( + serviceContainer.getTelemetryService(), + ); } /** @@ -113,76 +139,72 @@ export class Remote { agent: parts.agent || "(default)", }); - const workspaceName = `${parts.username}/${parts.workspace}`; - - // Migrate existing legacy file-based auth to secrets storage. + // 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); - - // Get the URL and token belonging to this host. - const auth = await this.secretsManager.getSessionAuth(parts.safeHostname); - const baseUrlRaw = auth?.url ?? ""; - const token = auth?.token; + 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(baseUrlRaw), - hasToken: token !== undefined, + hasUrl: Boolean(auth?.url), + hasToken: auth?.token !== undefined, }); - const disposables: vscode.Disposable[] = []; - 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}.`, - }); + 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: [], + }; + 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( + context: RemoteSetupContext, + tracer: RemoteSetupTracer, + ): Promise { + const { args, parts, workspaceName, baseUrl, token, disposables } = context; + + 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 showSessionExpiredDialog(); + await this.showSessionExpiredDialog(context); }, ); 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); - } - - 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 @@ -190,7 +212,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 @@ -200,7 +222,7 @@ export class Remote { remoteOAuthManager, this.secretsManager, async () => { - const result = await showSessionExpiredDialog(); + const result = await this.showSessionExpiredDialog(context); return result.success; }, ); @@ -209,51 +231,15 @@ 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) { - await this.cliManager.configure(baseUrlRaw, token); + if (baseUrl && token !== undefined) { + await this.cliManager.configure(baseUrl, token); } // 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, - ); - } - } - }, - ), - ); + disposables.push(this.watchRemoteSessionAuth(context, workspaceClient)); // First thing is to check the version. const buildInfo = await workspaceClient.getBuildInfo(); @@ -272,12 +258,13 @@ export class Remote { const cliAuth = resolveCliAuth( vscode.workspace.getConfiguration(), featureSet, - baseUrlRaw, + baseUrl, configDir, ); // 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", { @@ -296,50 +283,18 @@ 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 tracer.phase("workspace_lookup", () => + this.lookupWorkspace(context, workspaceClient), + ); + if (!foundWorkspace) { + tracer.setOutcome("workspace_not_found"); + return; } + let workspace: Workspace = foundWorkspace; // Register before connection so the label still displays! let labelFormatterDisposable = this.registerLabelFormatter( - remoteAuthority, + args.remoteAuthority, workspace.owner_name, workspace.name, ); @@ -369,7 +324,7 @@ export class Remote { const stateMachine = new WorkspaceStateMachine( parts, workspaceClient, - startupMode, + args.startupMode, binaryPath, featureSet, this.logger, @@ -378,56 +333,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 tracer.phase("workspace_ready", () => + this.waitForWorkspaceReady(workspace, monitor, stateMachine), ); } finally { stateMachine.dispose(); @@ -436,46 +343,26 @@ 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 tracer.phase("resolve_agent", () => + this.resolveAgent(context, 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( + const computedSshProperties = await tracer.phase("ssh_config_write", () => + this.writeRemoteSshConfig( + context, workspaceClient, - parts.safeHostname, - parts.sshHost, binaryPath, logDir, featureSet, cliAuth, - ); - } catch (error) { - this.logger.warn("Failed to configure SSH", error); - throw error; - } - + ), + ); const remoteCommand = computedSshProperties.RemoteCommand; this.logger.info("Modifying settings..."); @@ -504,7 +391,7 @@ export class Remote { proxyLogDir: logDir || undefined, logger: this.logger, codeLogDir: this.pathResolver.getCodeLogDir(), - remoteSshExtensionId, + remoteSshExtensionId: args.remoteSshExtensionId, }); disposables.push(sshMonitor); @@ -513,7 +400,7 @@ export class Remote { const reregisterLabelFormatter = () => { labelFormatterDisposable.dispose(); labelFormatterDisposable = this.registerLabelFormatter( - remoteAuthority, + args.remoteAuthority, workspace.owner_name, workspace.name, agent.name, @@ -583,7 +470,7 @@ export class Remote { // explained above. return { safeHostname: parts.safeHostname, - url: baseUrlRaw, + url: baseUrl, token: token ?? "", dispose: () => { disposables.forEach((d) => { @@ -593,6 +480,237 @@ 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.baseUrl}. Maybe it was deleted...`, + useCustom: true, + }, + "Open Workspace", + ); + context.disposables.forEach((d) => { + d.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 resolveAgent( + 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.baseUrl, + 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((d) => { + d.dispose(); + }); + if (result.success) { + const { remoteAuthority, startupMode, remoteSshExtensionId } = + context.args; + return this.setup(remoteAuthority, startupMode, 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); + } + // Dev override: use a custom binary at /tmp/coder if it exists. + try { + 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..447ed6b7 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -141,7 +141,15 @@ export class TelemetryService implements vscode.Disposable { spanOpts: SpanOptions, ): Promise { const eventId = newSpanId(); + 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, @@ -161,15 +169,31 @@ export class TelemetryService implements vscode.Disposable { { traceId, parentEventId: eventId, traceLevel }, ); }, + 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; + }, }; return this.#emitTimed( eventId, eventName, () => fn(span), - properties, - measurements, + spanProperties, + spanMeasurements, spanOpts, - ); + ).finally(() => { + completed = true; + }); } #sanitizePhaseName(name: string): string { 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..4e0c185d 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,141 @@ describe("CliManager", () => { ); }); + describe("Telemetry", () => { + const event = (name: string) => + telemetrySink.events.find((e) => e.eventName === name); + + it.each([ + { 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)), + ); + }); + + it("does not emit cli.download when a cached binary already matches", async () => { + withExistingBinary(TEST_VERSION); + await manager.fetchBinary(mockApi); + + expect(event("cli.download")).toBeUndefined(); + }); + + it("omits downloadedBytes when the server returns 304", async () => { + withExistingBinary("1.0.0"); + withHttpResponse(304); + await manager.fetchBinary(mockApi); + + const e = event("cli.download"); + expect(e).toMatchObject({ + properties: { reason: "version_mismatch", result: "success" }, + }); + expect(e?.measurements.downloadedBytes).toBeUndefined(); + }); + + it("emits downloadedBytes when a download fails mid-stream", async () => { + const partial = "partial-binary"; + withHttpResponse( + 200, + { "content-length": "1024" }, + createMockStream(partial, { error: new Error("connection reset") }), + ); + + await expect(manager.fetchBinary(mockApi)).rejects.toThrow( + "Unable to download binary: connection reset", + ); + + expect(event("cli.download")).toMatchObject({ + properties: { reason: "missing", result: "error" }, + error: { message: "Unable to download binary: connection reset" }, + measurements: { downloadedBytes: Buffer.byteLength(partial) }, + }); + }); + + 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 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); + + expect(event("cli.download.verify")).toMatchObject({ + properties: { outcome: "bypassed", 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]); + 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", + ); + + expect(event("cli.download.verify")).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 +938,7 @@ describe("CliManager", () => { createMockLogger(), new PathResolver(pathWithSpaces, "/log"), createMockCliCredentialManager(), + createTestTelemetryService(), ); withSuccessfulDownload(); 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( diff --git a/test/unit/instrumentation/activation.test.ts b/test/unit/instrumentation/activation.test.ts new file mode 100644 index 00000000..80a64c62 --- /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: "auth_failed" }, + ])( + "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 b71c5cc2..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 { @@ -135,6 +136,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)); @@ -257,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");