From 8a3c28df35574988c56f4463475b08f6d46c0ed7 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 27 Apr 2026 17:01:29 +0300 Subject: [PATCH 1/8] feat: add telemetry service infrastructure (Phase A core) Lays the spine for Phase A telemetry per the RFC. Defines the TelemetryEvent, TelemetryContext, and TelemetrySink interfaces, adds the TelemetryService with log/logError/time/trace, the Trace correlation handle, the coder.telemetry.level setting (off, local; default local), and ServiceContainer plus DeploymentManager wiring. No real sinks ship in this PR. LocalJsonlSink and the instrumentation sites land in follow-up tickets. Sinks are static and self-gating: the service holds a kill switch on coder.telemetry.level === "off", and each sink decides whether to emit based on its own gating signal. The setting is reactive via the existing watchConfigurationChanges helper, which now passes the changed values along so consumers don't have to re-read the config. Refs https://github.com/coder/vscode-coder/issues/900 --- package.json | 13 + src/configWatcher.ts | 12 +- src/core/container.ts | 9 + src/deployment/deploymentManager.ts | 5 + src/remote/remote.ts | 4 +- src/telemetry/event.ts | 122 +++++++ src/telemetry/service.ts | 216 ++++++++++++ src/telemetry/trace.ts | 71 ++++ test/mocks/telemetry.ts | 22 ++ test/mocks/vscode.runtime.ts | 3 + test/unit/configWatcher.test.ts | 25 +- .../unit/deployment/deploymentManager.test.ts | 5 + test/unit/telemetry/event.test.ts | 95 ++++++ test/unit/telemetry/service.test.ts | 316 ++++++++++++++++++ test/unit/telemetry/trace.test.ts | 92 +++++ 15 files changed, 991 insertions(+), 19 deletions(-) create mode 100644 src/telemetry/event.ts create mode 100644 src/telemetry/service.ts create mode 100644 src/telemetry/trace.ts create mode 100644 test/mocks/telemetry.ts create mode 100644 test/unit/telemetry/event.test.ts create mode 100644 test/unit/telemetry/service.test.ts create mode 100644 test/unit/telemetry/trace.test.ts diff --git a/package.json b/package.json index 66e4c87e44..8ab010fc0d 100644 --- a/package.json +++ b/package.json @@ -189,6 +189,19 @@ "Logs everything from *headers* plus request and response bodies (may include sensitive data)" ], "default": "basic" + }, + "coder.telemetry.level": { + "markdownDescription": "Controls Coder-owned telemetry collection. Local telemetry never leaves your machine and is used to diagnose issues with the extension.", + "type": "string", + "enum": [ + "off", + "local" + ], + "markdownEnumDescriptions": [ + "Disables telemetry collection entirely. No events are recorded and no files are written.", + "Records telemetry events to a local file under the extension's storage directory. Nothing is transmitted off the machine." + ], + "default": "local" } } }, diff --git a/src/configWatcher.ts b/src/configWatcher.ts index ee63f4489f..cc026c9087 100644 --- a/src/configWatcher.ts +++ b/src/configWatcher.ts @@ -8,16 +8,18 @@ export interface WatchedSetting { /** * Watch for configuration changes and invoke a callback when values change. + * The callback receives a map of changed settings to their new values, so + * consumers can act on the new value without re-reading the configuration. * Only fires when actual values change, not just when settings are touched. */ export function watchConfigurationChanges( settings: WatchedSetting[], - onChange: (changedSettings: string[]) => void, + onChange: (changes: ReadonlyMap) => void, ): vscode.Disposable { const appliedValues = new Map(settings.map((s) => [s.setting, s.getValue()])); return vscode.workspace.onDidChangeConfiguration((e) => { - const changedSettings: string[] = []; + const changes = new Map(); for (const { setting, getValue } of settings) { if (!e.affectsConfiguration(setting)) { @@ -27,13 +29,13 @@ export function watchConfigurationChanges( const newValue = getValue(); if (!configValuesEqual(newValue, appliedValues.get(setting))) { - changedSettings.push(setting); + changes.set(setting, newValue); appliedValues.set(setting, newValue); } } - if (changedSettings.length > 0) { - onChange(changedSettings); + if (changes.size > 0) { + onChange(changes); } }); } diff --git a/src/core/container.ts b/src/core/container.ts index 330ad8969f..92cc800c14 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -3,6 +3,7 @@ import * as vscode from "vscode"; import { CoderApi } from "../api/coderApi"; import { LoginCoordinator } from "../login/loginCoordinator"; import { OAuthCallback } from "../oauth/oauthCallback"; +import { TelemetryService } from "../telemetry/service"; import { SpeedtestPanelFactory } from "../webviews/speedtest/speedtestPanelFactory"; import { DuplicateWorkspaceIpc } from "../workspace/duplicateWorkspaceIpc"; @@ -31,6 +32,7 @@ export class ServiceContainer implements vscode.Disposable { private readonly duplicateWorkspaceIpc: DuplicateWorkspaceIpc; private readonly oauthCallback: OAuthCallback; private readonly speedtestPanelFactory: SpeedtestPanelFactory; + private readonly telemetryService: TelemetryService; constructor(context: vscode.ExtensionContext) { this.logger = vscode.window.createOutputChannel("Coder", { log: true }); @@ -88,6 +90,7 @@ export class ServiceContainer implements vscode.Disposable { context.extensionUri, this.logger, ); + this.telemetryService = new TelemetryService(context, [], this.logger); } getPathResolver(): PathResolver { @@ -134,6 +137,10 @@ export class ServiceContainer implements vscode.Disposable { return this.speedtestPanelFactory; } + getTelemetryService(): TelemetryService { + return this.telemetryService; + } + /** * Dispose of all services and clean up resources. */ @@ -141,5 +148,7 @@ export class ServiceContainer implements vscode.Disposable { this.contextManager.dispose(); this.logger.dispose(); this.loginCoordinator.dispose(); + // Fire-and-forget: VS Code does not await deactivation. + void this.telemetryService.dispose(); } } diff --git a/src/deployment/deploymentManager.ts b/src/deployment/deploymentManager.ts index 9eaf2ccf35..adb732a0fc 100644 --- a/src/deployment/deploymentManager.ts +++ b/src/deployment/deploymentManager.ts @@ -5,6 +5,7 @@ import { type MementoManager } from "../core/mementoManager"; import { type SecretsManager } from "../core/secretsManager"; import { type Logger } from "../logging/logger"; import { type OAuthSessionManager } from "../oauth/sessionManager"; +import { type TelemetryService } from "../telemetry/service"; import { type WorkspaceProvider } from "../workspace/workspacesProvider"; import { @@ -33,6 +34,7 @@ export class DeploymentManager implements vscode.Disposable { private readonly mementoManager: MementoManager; private readonly contextManager: ContextManager; private readonly logger: Logger; + private readonly telemetryService: TelemetryService; #deployment: Deployment | null = null; #authListenerDisposable: vscode.Disposable | undefined; @@ -48,6 +50,7 @@ export class DeploymentManager implements vscode.Disposable { this.mementoManager = serviceContainer.getMementoManager(); this.contextManager = serviceContainer.getContextManager(); this.logger = serviceContainer.getLogger(); + this.telemetryService = serviceContainer.getTelemetryService(); } public static create( @@ -124,6 +127,7 @@ export class DeploymentManager implements vscode.Disposable { user: deployment.user.username, }); this.#deployment = { ...deployment }; + this.telemetryService.setDeploymentUrl(deployment.url); // Updates client credentials if (deployment.token === undefined) { @@ -155,6 +159,7 @@ export class DeploymentManager implements vscode.Disposable { this.#authListenerDisposable?.dispose(); this.#authListenerDisposable = undefined; this.#deployment = null; + this.telemetryService.setDeploymentUrl(""); await this.secretsManager.setCurrentDeployment(undefined); } diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 240afe65f3..0f8714d5b5 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -861,8 +861,8 @@ export class Remote { ): vscode.Disposable { const titleMap = new Map(settings.map((s) => [s.setting, s.title])); - return watchConfigurationChanges(settings, (changedSettings) => { - const changedTitles = changedSettings + return watchConfigurationChanges(settings, (changes) => { + const changedTitles = [...changes.keys()] .map((s) => titleMap.get(s)) .filter((t) => t !== undefined); diff --git a/src/telemetry/event.ts b/src/telemetry/event.ts new file mode 100644 index 0000000000..fc39f60cde --- /dev/null +++ b/src/telemetry/event.ts @@ -0,0 +1,122 @@ +import * as os from "node:os"; +import * as vscode from "vscode"; + +import { toError } from "../error/errorUtils"; + +/** + * Session-stable resource attributes carried by every event. Field names + * follow OpenTelemetry semantic conventions (`os.type`, `os.version`, + * `host.arch`) so a future OTel collector translation is a rename. + */ +export interface TelemetryContext { + extensionVersion: string; + machineId: string; + sessionId: string; + deploymentUrl: string; + osType: string; + osVersion: string; + hostArch: string; + platformType: string; + platformVersion: string; +} + +export interface TelemetryEvent { + eventId: string; + eventName: string; + timestamp: string; + eventSequence: number; + + context: TelemetryContext; + + properties: Record; + measurements: Record; + + traceId?: string; + + error?: { + message: string; + type?: string; + code?: string; + }; +} + +/** + * Destination for telemetry events. `write` runs on the hot path and must + * buffer in memory; I/O happens in `flush`/`dispose`. Sinks own their own + * gating beyond the service-level kill switch (e.g. a server sink emits only + * when the user opts into deployment telemetry). + */ +export interface TelemetrySink { + readonly name: string; + write(event: TelemetryEvent): void; + flush(): Promise; + dispose(): Promise; +} + +/** + * Build the session-stable context attached to every event. `deploymentUrl` + * starts empty and is updated once the deployment is known. + */ +export function buildContext(ctx: vscode.ExtensionContext): TelemetryContext { + const packageJson = ctx.extension.packageJSON as + | { version?: unknown } + | undefined; + const rawVersion = packageJson?.version; + const extensionVersion = typeof rawVersion === "string" ? rawVersion : ""; + + return { + extensionVersion, + machineId: vscode.env.machineId, + sessionId: vscode.env.sessionId, + deploymentUrl: "", + osType: detectOsType(), + osVersion: os.release(), + hostArch: process.arch, + platformType: detectPlatformType(vscode.env.appName ?? ""), + platformVersion: vscode.version ?? "", + }; +} + +/** + * Normalize any thrown value into the structured `error` block of an event. + * `type` comes from `Error.name` (skipped when generic). `code` captures + * Node's `error.code` for system errors and HTTP statuses for API errors. + */ +export function buildErrorBlock( + value: unknown, +): NonNullable { + const err = toError(value); + const block: NonNullable = { message: err.message }; + if (err.name && err.name !== "Error") { + block.type = err.name; + } + const rawCode = (value as { code?: unknown } | null | undefined)?.code; + if (typeof rawCode === "string" || typeof rawCode === "number") { + block.code = String(rawCode); + } + return block; +} + +function detectPlatformType(appName: string): string { + const lower = appName.toLowerCase(); + if (lower.includes("cursor")) { + return "cursor"; + } + if (lower.includes("vscodium")) { + return "vscodium"; + } + return "vscode"; +} + +function detectOsType(): string { + switch (process.platform) { + case "linux": + return "linux"; + case "darwin": + return "darwin"; + case "win32": + return "windows"; + default: + return process.platform; + } +} diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts new file mode 100644 index 0000000000..b5900e1142 --- /dev/null +++ b/src/telemetry/service.ts @@ -0,0 +1,216 @@ +import * as vscode from "vscode"; + +import { watchConfigurationChanges } from "../configWatcher"; +import { type Logger } from "../logging/logger"; + +import { + buildContext, + buildErrorBlock, + type TelemetryContext, + type TelemetryEvent, + type TelemetrySink, +} from "./event"; +import { emitTimed, Trace, type EmitFn } from "./trace"; + +const noopEmit: EmitFn = () => { + // Intentionally empty: used by NOOP_TRACE when telemetry is off. +}; +const NOOP_TRACE = new Trace("", "", noopEmit); + +type TelemetryLevel = "off" | "local"; + +const TELEMETRY_LEVEL_SETTING = "coder.telemetry.level"; + +/** + * Emits structured telemetry events to a fan-out of sinks. + * + * Phase A ships with no real sinks; this service is the spine that future + * sinks (`LocalJsonlSink`, `CoderServerSink`, external services) plug into. + * Each sink owns its own gating beyond the service-level + * `coder.telemetry.level` kill switch. + * + * `dispose()` returns `Promise` for explicit awaits; VS Code does not + * await deactivation, so flushes during shutdown are best-effort. + */ +export class TelemetryService implements vscode.Disposable { + #level: TelemetryLevel; + #nextSequence = 0; + #context: TelemetryContext; + readonly #configWatcher: vscode.Disposable; + readonly #emitter: EmitFn = (n, p, m, t, e) => this.#emit(n, p, m, t, e); + + constructor( + ctx: vscode.ExtensionContext, + private readonly sinks: readonly TelemetrySink[], + private readonly logger: Logger, + ) { + this.#context = buildContext(ctx); + this.#level = readTelemetryLevel(); + this.#configWatcher = watchConfigurationChanges( + [ + { + setting: TELEMETRY_LEVEL_SETTING, + getValue: () => + vscode.workspace + .getConfiguration() + .get(TELEMETRY_LEVEL_SETTING), + }, + ], + (changes) => { + this.#applyLevelChange(changes.get(TELEMETRY_LEVEL_SETTING)).catch( + (err) => { + this.logger.warn("Telemetry level change failed", err); + }, + ); + }, + ); + } + + setDeploymentUrl(url: string): void { + if (url === this.#context.deploymentUrl) { + return; + } + this.#context = { ...this.#context, deploymentUrl: url }; + } + + log( + eventName: string, + properties: Record = {}, + measurements: Record = {}, + ): void { + if (this.#level === "off") { + return; + } + this.#emit(eventName, properties, measurements); + } + + logError( + eventName: string, + error: unknown, + properties: Record = {}, + measurements: Record = {}, + ): void { + if (this.#level === "off") { + return; + } + this.#emit(eventName, properties, measurements, undefined, error); + } + + time( + eventName: string, + fn: () => Promise, + properties: Record = {}, + ): Promise { + if (this.#level === "off") { + return fn(); + } + return emitTimed(this.#emitter, eventName, fn, properties); + } + + trace( + eventName: string, + fn: (trace: Trace) => Promise, + properties: Record = {}, + ): Promise { + if (this.#level === "off") { + return fn(NOOP_TRACE); + } + const traceId = crypto.randomUUID(); + const tracer = new Trace(eventName, traceId, this.#emitter); + return emitTimed( + this.#emitter, + eventName, + () => fn(tracer), + properties, + traceId, + ); + } + + async dispose(): Promise { + this.#configWatcher.dispose(); + await Promise.allSettled( + this.sinks.map(async (sink) => { + try { + await sink.flush(); + } catch (err) { + this.logger.warn( + `Telemetry sink '${sink.name}' flush failed during dispose`, + err, + ); + } + try { + await sink.dispose(); + } catch (err) { + this.logger.warn(`Telemetry sink '${sink.name}' dispose failed`, err); + } + }), + ); + } + + #emit( + eventName: string, + properties: Record, + measurements: Record, + traceId?: string, + error?: unknown, + ): void { + if (this.#level === "off") { + return; + } + + const event: TelemetryEvent = { + eventId: crypto.randomUUID(), + eventName, + timestamp: new Date().toISOString(), + eventSequence: this.#nextSequence++, + context: { ...this.#context }, + properties, + measurements, + }; + if (traceId !== undefined) { + event.traceId = traceId; + } + if (error !== undefined) { + event.error = buildErrorBlock(error); + } + + for (const sink of this.sinks) { + try { + sink.write(event); + } catch (err) { + this.logger.warn(`Telemetry sink '${sink.name}' write failed`, err); + } + } + + this.logger.trace(`[telemetry] ${eventName}`, event); + } + + async #applyLevelChange(rawValue: unknown): Promise { + const newLevel = coerceLevel(rawValue); + if (newLevel === this.#level) { + return; + } + this.#level = newLevel; + if (newLevel === "off") { + await Promise.allSettled( + this.sinks.map((sink) => + sink.flush().catch((err) => { + this.logger.warn(`Telemetry sink '${sink.name}' flush failed`, err); + }), + ), + ); + } + } +} + +function readTelemetryLevel(): TelemetryLevel { + return coerceLevel( + vscode.workspace + .getConfiguration() + .get(TELEMETRY_LEVEL_SETTING, "local"), + ); +} + +function coerceLevel(value: unknown): TelemetryLevel { + return value === "off" ? "off" : "local"; +} diff --git a/src/telemetry/trace.ts b/src/telemetry/trace.ts new file mode 100644 index 0000000000..d21a3d9fcc --- /dev/null +++ b/src/telemetry/trace.ts @@ -0,0 +1,71 @@ +/** + * Internal contract used by `Trace` to push events through the service. + * @internal + */ +export type EmitFn = ( + eventName: string, + properties: Record, + measurements: Record, + traceId?: string, + error?: unknown, +) => void; + +/** + * Run an async operation and emit a single event recording its outcome and + * `durationMs`. Used by `time`, `trace`, and `Trace.phase` to share the + * success/error reporting pattern. + */ +export async function emitTimed( + emit: EmitFn, + eventName: string, + fn: () => Promise, + properties: Record, + traceId?: string, +): Promise { + const start = performance.now(); + try { + const result = await fn(); + emit( + eventName, + { ...properties, result: "success" }, + { durationMs: performance.now() - start }, + traceId, + ); + return result; + } catch (err) { + emit( + eventName, + { ...properties, result: "error" }, + { durationMs: performance.now() - start }, + traceId, + err, + ); + throw err; + } +} + +/** + * Correlation handle for a multi-phase operation. The same `traceId` is + * shared by the parent event and every child phase event. + */ +export class Trace { + constructor( + private readonly parentEventName: string, + public readonly traceId: string, + private readonly emit: EmitFn, + ) {} + + phase( + phaseName: string, + fn: () => Promise, + properties: Record = {}, + ): Promise { + return emitTimed( + this.emit, + `${this.parentEventName}.phase`, + fn, + { ...properties, phase: phaseName }, + this.traceId, + ); + } +} diff --git a/test/mocks/telemetry.ts b/test/mocks/telemetry.ts new file mode 100644 index 0000000000..0a8f160c2e --- /dev/null +++ b/test/mocks/telemetry.ts @@ -0,0 +1,22 @@ +import { vi } from "vitest"; + +import type { TelemetryEvent, TelemetrySink } from "@/telemetry/event"; + +/** + * In-memory `TelemetrySink` for tests. Captures every written event and + * exposes `flush`/`dispose` as `vi.fn()` mocks for assertions. + */ +export class TestSink implements TelemetrySink { + readonly name: string; + readonly events: TelemetryEvent[] = []; + readonly flush = vi.fn(() => Promise.resolve()); + readonly dispose = vi.fn(() => Promise.resolve()); + + constructor(name = "test") { + this.name = name; + } + + write(event: TelemetryEvent): void { + this.events.push(event); + } +} diff --git a/test/mocks/vscode.runtime.ts b/test/mocks/vscode.runtime.ts index c4bdd20bc7..8def001eb6 100644 --- a/test/mocks/vscode.runtime.ts +++ b/test/mocks/vscode.runtime.ts @@ -185,6 +185,8 @@ export const extensions = { all: [] as unknown[], }; +export const version = "1.106.0-test"; + const vscode = { ProgressLocation, ViewColumn, @@ -204,6 +206,7 @@ const vscode = { workspace, env, extensions, + version, }; export default vscode; diff --git a/test/unit/configWatcher.test.ts b/test/unit/configWatcher.test.ts index 2327b2dfb5..7d552b8d47 100644 --- a/test/unit/configWatcher.test.ts +++ b/test/unit/configWatcher.test.ts @@ -10,25 +10,24 @@ import { MockConfigurationProvider } from "../mocks/testHelpers"; describe("watchConfigurationChanges", () => { const createWatcher = (...keys: string[]) => { - const changes: string[][] = []; + const changes: Array> = []; const settings: WatchedSetting[] = keys.map((key) => ({ setting: key, getValue: () => vscode.workspace.getConfiguration().get(key), })); - const watcher = watchConfigurationChanges(settings, (changed) => - changes.push(changed), - ); + const watcher = watchConfigurationChanges(settings, (c) => changes.push(c)); return { changes, dispose: () => watcher.dispose() }; }; - it("fires callback when watched setting value changes", () => { + it("fires callback with the new value when a watched setting changes", () => { const config = new MockConfigurationProvider(); config.set("test.setting", "initial"); const { changes, dispose } = createWatcher("test.setting"); config.set("test.setting", "changed"); - expect(changes).toEqual([["test.setting"]]); + expect(changes).toHaveLength(1); + expect(changes[0].get("test.setting")).toBe("changed"); dispose(); }); @@ -64,10 +63,10 @@ describe("watchConfigurationChanges", () => { config.set("test.setting", "changed2"); // same value - no callback config.set("test.setting", "changed1"); // back to changed1 - should fire - expect(changes).toEqual([ - ["test.setting"], - ["test.setting"], - ["test.setting"], + expect(changes.map((c) => c.get("test.setting"))).toEqual([ + "changed1", + "changed2", + "changed1", ]); dispose(); }); @@ -91,7 +90,8 @@ describe("watchConfigurationChanges", () => { config.set("test.setting", { key: "value" }); // deep equal - no callback config.set("test.setting", { key: "different" }); - expect(changes).toEqual([["test.setting"]]); + expect(changes).toHaveLength(1); + expect(changes[0].get("test.setting")).toEqual({ key: "different" }); dispose(); }); @@ -131,7 +131,8 @@ describe("watchConfigurationChanges", () => { config.set("test.setting", to); - expect(changes).toEqual([["test.setting"]]); + expect(changes).toHaveLength(1); + expect(changes[0].has("test.setting")).toBe(true); dispose(); }); }); diff --git a/test/unit/deployment/deploymentManager.test.ts b/test/unit/deployment/deploymentManager.test.ts index 2756b64717..d2830a5655 100644 --- a/test/unit/deployment/deploymentManager.test.ts +++ b/test/unit/deployment/deploymentManager.test.ts @@ -66,11 +66,16 @@ function createTestContext() { validationMockClient as unknown as CoderApi, ); + const telemetryService = { + setDeploymentUrl: vi.fn(), + }; + const container = { getSecretsManager: () => secretsManager, getMementoManager: () => mementoManager, getContextManager: () => contextManager as unknown as ContextManager, getLogger: () => logger, + getTelemetryService: () => telemetryService, }; const manager = DeploymentManager.create( diff --git a/test/unit/telemetry/event.test.ts b/test/unit/telemetry/event.test.ts new file mode 100644 index 0000000000..45d55a3e68 --- /dev/null +++ b/test/unit/telemetry/event.test.ts @@ -0,0 +1,95 @@ +import { afterEach, describe, expect, it } from "vitest"; +import * as vscode from "vscode"; + +import { buildContext, buildErrorBlock } from "@/telemetry/event"; + +import type * as vscodeTypes from "vscode"; + +function fakeContext( + version: unknown = "1.2.3-test", +): vscodeTypes.ExtensionContext { + return { + extension: { packageJSON: { version } }, + } as unknown as vscodeTypes.ExtensionContext; +} + +describe("buildContext", () => { + const env = vscode.env as { appName: string }; + const originalAppName = env.appName; + afterEach(() => { + env.appName = originalAppName; + }); + + it("populates session-stable fields from the extension context and vscode env", () => { + expect(buildContext(fakeContext())).toMatchObject({ + extensionVersion: "1.2.3-test", + machineId: "test-machine-id", + sessionId: "test-session-id", + deploymentUrl: "", + platformType: "vscode", + platformVersion: "1.106.0-test", + }); + }); + + it("returns truthy values for runtime os/host fields", () => { + const ctx = buildContext(fakeContext()); + expect(ctx.osType).toBeTruthy(); + expect(ctx.osVersion).toBeTruthy(); + expect(ctx.hostArch).toBeTruthy(); + }); + + it.each([ + ["Cursor", "cursor"], + ["VSCodium", "vscodium"], + ["Visual Studio Code", "vscode"], + ["Some Unknown Fork", "vscode"], + ])("derives platformType %s -> %s", (appName, expected) => { + env.appName = appName; + expect(buildContext(fakeContext()).platformType).toBe(expected); + }); + + it("falls back to empty string when packageJSON.version is missing or not a string", () => { + const noVersion = { + extension: { packageJSON: {} }, + } as unknown as vscodeTypes.ExtensionContext; + expect(buildContext(noVersion).extensionVersion).toBe(""); + expect(buildContext(fakeContext(123)).extensionVersion).toBe(""); + }); +}); + +describe("buildErrorBlock", () => { + it.each([ + [ + "Error instance", + new TypeError("nope"), + { message: "nope", type: "TypeError" }, + ], + ["string", "boom", { message: "boom" }], + [ + "plain object with message + name", + { message: "hi", name: "Custom" }, + { message: "hi", type: "Custom" }, + ], + ["null", null, { message: "Unknown error" }], + ])("normalizes %s", (_label, input, expected) => { + expect(buildErrorBlock(input)).toEqual(expected); + }); + + it("captures Node-style error.code as a string", () => { + expect( + buildErrorBlock( + Object.assign(new Error("connect failed"), { code: "ECONNREFUSED" }), + ), + ).toEqual({ message: "connect failed", code: "ECONNREFUSED" }); + }); + + it("stringifies numeric codes (HTTP status)", () => { + expect( + buildErrorBlock(Object.assign(new Error("bad"), { code: 401 })).code, + ).toBe("401"); + }); + + it("omits type for generic Error instances", () => { + expect(buildErrorBlock(new Error("plain"))).toEqual({ message: "plain" }); + }); +}); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts new file mode 100644 index 0000000000..4928e9940c --- /dev/null +++ b/test/unit/telemetry/service.test.ts @@ -0,0 +1,316 @@ +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; + +import { TelemetryService } from "@/telemetry/service"; + +import { TestSink } from "../../mocks/telemetry"; +import { + createMockLogger, + MockConfigurationProvider, +} from "../../mocks/testHelpers"; + +import type * as vscode from "vscode"; + +import type { Logger } from "@/logging/logger"; +import type { TelemetrySink } from "@/telemetry/event"; + +function fakeContext(): vscode.ExtensionContext { + return { + extension: { packageJSON: { version: "1.2.3-test" } }, + } as unknown as vscode.ExtensionContext; +} + +interface Harness { + service: TelemetryService; + sink: TestSink; + logger: Logger; + config: MockConfigurationProvider; +} + +function makeHarness(level: "off" | "local" = "local"): Harness { + const config = new MockConfigurationProvider(); + config.set("coder.telemetry.level", level); + const logger = createMockLogger(); + const sink = new TestSink(); + const service = new TelemetryService(fakeContext(), [sink], logger); + return { service, sink, logger, config }; +} + +function makeService(sinks: TelemetrySink[]): TelemetryService { + new MockConfigurationProvider().set("coder.telemetry.level", "local"); + return new TelemetryService(fakeContext(), sinks, createMockLogger()); +} + +describe("TelemetryService", () => { + let h: Harness; + beforeEach(() => { + h = makeHarness(); + }); + afterEach(() => { + vi.useRealTimers(); + }); + + describe("log", () => { + it("emits an event with auto-injected context, properties, and measurements", () => { + h.service.log("activation", { result: "success" }, { durationMs: 12 }); + + expect(h.sink.events).toHaveLength(1); + const event = h.sink.events[0]; + expect(event).toMatchObject({ + eventName: "activation", + eventSequence: 0, + properties: { result: "success" }, + measurements: { durationMs: 12 }, + context: { + extensionVersion: "1.2.3-test", + machineId: "test-machine-id", + sessionId: "test-session-id", + deploymentUrl: "", + }, + }); + expect(event.eventId).toMatch( + /^[0-9a-f]{8}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{4}-[0-9a-f]{12}$/, + ); + expect(event.timestamp).toMatch(/^\d{4}-\d{2}-\d{2}T/); + }); + + it("issues unique eventIds and monotonic eventSequence per emission", () => { + h.service.log("a"); + h.service.log("b"); + h.service.log("c"); + + const ids = h.sink.events.map((e) => e.eventId); + expect(new Set(ids).size).toBe(3); + expect(h.sink.events.map((e) => e.eventSequence)).toEqual([0, 1, 2]); + }); + + it("defaults properties and measurements to empty objects", () => { + h.service.log("nothing"); + expect(h.sink.events[0].properties).toEqual({}); + expect(h.sink.events[0].measurements).toEqual({}); + }); + }); + + describe("logError", () => { + it("attaches the error block to the event", () => { + h.service.logError("activation", new TypeError("nope"), { + phase: "init", + }); + + expect(h.sink.events[0]).toMatchObject({ + properties: { phase: "init" }, + error: { message: "nope", type: "TypeError" }, + }); + }); + }); + + describe("time", () => { + it("returns the wrapped value and emits a success event with durationMs", async () => { + vi.useFakeTimers(); + const promise = h.service.time( + "activation", + async () => { + await new Promise((r) => setTimeout(r, 250)); + return 42; + }, + { phase: "init" }, + ); + await vi.advanceTimersByTimeAsync(250); + + expect(await promise).toBe(42); + expect(h.sink.events[0]).toMatchObject({ + properties: { phase: "init", result: "success" }, + }); + expect(h.sink.events[0].measurements.durationMs).toBeCloseTo(250, 0); + }); + + it("emits an error event and rethrows on failure", async () => { + const err = new Error("boom"); + await expect( + h.service.time("activation", () => Promise.reject(err)), + ).rejects.toBe(err); + + expect(h.sink.events[0]).toMatchObject({ + properties: { result: "error" }, + error: { message: "boom" }, + }); + }); + }); + + describe("trace", () => { + it("parent and child phase events share one traceId on success", async () => { + const result = await h.service.trace("remote.setup", async (trace) => { + await trace.phase("workspace_lookup", () => Promise.resolve("ws")); + await trace.phase("ssh_config", () => Promise.resolve("cfg")); + return "done"; + }); + + expect(result).toBe("done"); + const [phase1, phase2, parent] = h.sink.events; + expect(phase1.eventName).toBe("remote.setup.phase"); + expect(phase2.eventName).toBe("remote.setup.phase"); + expect(parent).toMatchObject({ + eventName: "remote.setup", + properties: { result: "success" }, + }); + expect(parent.traceId).toBeDefined(); + expect(phase1.traceId).toBe(parent.traceId); + expect(phase2.traceId).toBe(parent.traceId); + }); + + it("on phase failure: completed phases emit success, parent emits error summary, error rethrown", async () => { + const boom = new Error("phase-2-broke"); + const neverRuns = vi.fn(() => Promise.resolve("x")); + + await expect( + h.service.trace("remote.setup", async (trace) => { + await trace.phase("ok_phase", () => Promise.resolve("ok")); + await trace.phase("bad_phase", () => Promise.reject(boom)); + await trace.phase("never_runs", neverRuns); + }), + ).rejects.toBe(boom); + + expect(neverRuns).not.toHaveBeenCalled(); + const [okPhase, badPhase, parent] = h.sink.events; + expect(okPhase.properties).toMatchObject({ result: "success" }); + expect(badPhase.properties).toMatchObject({ result: "error" }); + expect(parent).toMatchObject({ + eventName: "remote.setup", + properties: { result: "error" }, + error: { message: "phase-2-broke" }, + }); + expect( + [okPhase, badPhase, parent].every((e) => e.traceId === parent.traceId), + ).toBe(true); + }); + }); + + describe("setDeploymentUrl", () => { + it("propagates to subsequent events and can be reset", () => { + h.service.log("a"); + h.service.setDeploymentUrl("https://coder.example.com"); + h.service.log("b"); + h.service.setDeploymentUrl(""); + h.service.log("c"); + + expect(h.sink.events.map((e) => e.context.deploymentUrl)).toEqual([ + "", + "https://coder.example.com", + "", + ]); + }); + + it("captures the URL as of the moment each event in a trace is emitted", async () => { + await h.service.trace("op", async (trace) => { + await trace.phase("first", () => Promise.resolve("")); + h.service.setDeploymentUrl("https://coder.example.com"); + await trace.phase("second", () => Promise.resolve("")); + }); + + const [first, second, parent] = h.sink.events; + expect(first.context.deploymentUrl).toBe(""); + expect(second.context.deploymentUrl).toBe("https://coder.example.com"); + expect(parent.context.deploymentUrl).toBe("https://coder.example.com"); + }); + }); + + describe("level off", () => { + beforeEach(() => { + h = makeHarness("off"); + }); + + it("suppresses log and logError emissions", () => { + h.service.log("a"); + h.service.logError("b", new Error("ignored")); + expect(h.sink.events).toHaveLength(0); + }); + + it("still runs the wrapped functions of time and trace but emits nothing", async () => { + const timeFn = vi.fn(() => Promise.resolve(99)); + const phaseFn = vi.fn(() => Promise.resolve("x")); + + expect(await h.service.time("a", timeFn)).toBe(99); + expect( + await h.service.trace("b", async (t) => { + await t.phase("p", phaseFn); + return "done"; + }), + ).toBe("done"); + + expect(timeFn).toHaveBeenCalled(); + expect(phaseFn).toHaveBeenCalled(); + expect(h.sink.events).toHaveLength(0); + }); + }); + + describe("reactive level", () => { + it("flushes sinks on local → off, suppresses while off, and resumes on off → local", () => { + h.service.log("first"); + expect(h.sink.events).toHaveLength(1); + + h.config.set("coder.telemetry.level", "off"); + expect(h.sink.flush).toHaveBeenCalledTimes(1); + + h.service.log("second"); + expect(h.sink.events).toHaveLength(1); + + h.config.set("coder.telemetry.level", "local"); + h.service.log("third"); + expect(h.sink.events).toHaveLength(2); + }); + + it("treats unknown values (e.g. future deployment) as local", () => { + h.config.set("coder.telemetry.level", "deployment"); + h.service.log("evt"); + expect(h.sink.events).toHaveLength(1); + }); + }); + + describe("multiple sinks", () => { + it("a throwing sink does not block other sinks from receiving events", () => { + const bad: TelemetrySink = { + name: "bad", + write: () => { + throw new Error("boom"); + }, + flush: vi.fn(() => Promise.resolve()), + dispose: vi.fn(() => Promise.resolve()), + }; + const good = new TestSink("good"); + const service = makeService([bad, good]); + + service.log("activation"); + expect(good.events).toHaveLength(1); + }); + }); + + describe("dispose", () => { + it("flushes and disposes every sink", async () => { + await h.service.dispose(); + expect(h.sink.flush).toHaveBeenCalledTimes(1); + expect(h.sink.dispose).toHaveBeenCalledTimes(1); + }); + + it("unsubscribes the config watcher so later level changes are ignored", async () => { + await h.service.dispose(); + h.sink.flush.mockClear(); + + h.config.set("coder.telemetry.level", "off"); + expect(h.sink.flush).not.toHaveBeenCalled(); + }); + + it("resolves even when sinks reject in flush or dispose", async () => { + const bad: TelemetrySink = { + name: "bad", + write: () => {}, + flush: () => Promise.reject(new Error("flush fail")), + dispose: () => Promise.reject(new Error("dispose fail")), + }; + const good = new TestSink("good"); + const service = makeService([bad, good]); + + await expect(service.dispose()).resolves.toBeUndefined(); + expect(good.flush).toHaveBeenCalled(); + expect(good.dispose).toHaveBeenCalled(); + }); + }); +}); diff --git a/test/unit/telemetry/trace.test.ts b/test/unit/telemetry/trace.test.ts new file mode 100644 index 0000000000..d686913ad7 --- /dev/null +++ b/test/unit/telemetry/trace.test.ts @@ -0,0 +1,92 @@ +import { describe, expect, it, vi } from "vitest"; + +import { type EmitFn, Trace } from "@/telemetry/trace"; + +interface RecordedCall { + eventName: string; + properties: Record; + measurements: Record; + traceId?: string; + error?: unknown; +} + +function makeRecorder(): { emit: EmitFn; calls: RecordedCall[] } { + const calls: RecordedCall[] = []; + const emit: EmitFn = ( + eventName, + properties, + measurements, + traceId, + error, + ) => { + calls.push({ eventName, properties, measurements, traceId, error }); + }; + return { emit, calls }; +} + +describe("Trace.phase", () => { + it("emits a child '.phase' event with the parent's traceId on success", async () => { + const { emit, calls } = makeRecorder(); + const trace = new Trace("remote.setup", "trace-1", emit); + + const result = await trace.phase("workspace_lookup", () => + Promise.resolve("ws"), + ); + + expect(result).toBe("ws"); + expect(calls).toHaveLength(1); + expect(calls[0]).toMatchObject({ + eventName: "remote.setup.phase", + properties: { phase: "workspace_lookup", result: "success" }, + traceId: "trace-1", + error: undefined, + }); + expect(calls[0].measurements.durationMs).toBeGreaterThanOrEqual(0); + }); + + it("merges caller properties without overwriting phase or result", async () => { + const { emit, calls } = makeRecorder(); + const trace = new Trace("op", "tid", emit); + + await trace.phase("p", () => Promise.resolve(0), { extra: "yes" }); + + expect(calls[0].properties).toEqual({ + extra: "yes", + phase: "p", + result: "success", + }); + }); + + it("emits an error event and rethrows when the wrapped fn rejects", async () => { + const { emit, calls } = makeRecorder(); + const trace = new Trace("op", "tid", emit); + const boom = new Error("nope"); + + await expect(trace.phase("p", () => Promise.reject(boom))).rejects.toBe( + boom, + ); + + expect(calls).toHaveLength(1); + expect(calls[0]).toMatchObject({ + eventName: "op.phase", + properties: { phase: "p", result: "error" }, + traceId: "tid", + error: boom, + }); + }); + + it("does not run subsequent code after a phase rejection inside the caller", async () => { + const { emit } = makeRecorder(); + const trace = new Trace("op", "tid", emit); + const after = vi.fn(); + + await expect( + (async () => { + await trace.phase("bad", () => Promise.reject(new Error("x"))); + after(); + })(), + ).rejects.toThrow("x"); + + expect(after).not.toHaveBeenCalled(); + }); +}); From 9926465f667ebcf384abdc79f7f0c6fdeb25bc5e Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 27 Apr 2026 17:45:35 +0300 Subject: [PATCH 2/8] refactor(telemetry): tighten event/service/trace and tests event.ts: - Use raw vscode.env.appName for platformType to keep granularity (Visual Studio Code, Visual Studio Code - Insiders, Cursor, etc.). - Use 'unknown' sentinel for extensionVersion when packageJSON.version is missing or non-string, instead of misleading empty string. - Drop overly defensive ?? '' on platformVersion (vscode.version is always defined). Add a comment on the win32 -> windows mapping. service.ts: - Inline noopEmit into the NOOP_TRACE constructor. - Convert coerceLevel to a switch so future Phase B 'deployment' lands cleanly. - Have the watcher callback coerce the new value once and pass a TelemetryLevel directly to #applyLevelChange. - Extract a #safeCall(sink, action) helper that dedupes the catch+log pattern shared by dispose and the level-off flush. trace.ts: - Dedupe emitTimed's two emit calls via a small send closure. Tests: - event.test.ts: cover raw appName granularity (Insiders, Cursor) and the 'unknown' sentinel. - trace.test.ts: drop the JS-semantics test that wasn't really about Trace. - service.test.ts: combine redundant log and level-off cases, replace vi.fn 'was called' assertions with return-value assertions where the wrapped function ran. --- src/telemetry/event.ts | 43 +++++++----------- src/telemetry/service.ts | 68 +++++++++++++--------------- src/telemetry/trace.ts | 19 ++++---- test/unit/telemetry/event.test.ts | 40 ++++++++--------- test/unit/telemetry/service.test.ts | 69 +++++++++++++---------------- test/unit/telemetry/trace.test.ts | 17 +------ 6 files changed, 107 insertions(+), 149 deletions(-) diff --git a/src/telemetry/event.ts b/src/telemetry/event.ts index fc39f60cde..afa50ae26d 100644 --- a/src/telemetry/event.ts +++ b/src/telemetry/event.ts @@ -55,14 +55,14 @@ export interface TelemetrySink { /** * Build the session-stable context attached to every event. `deploymentUrl` - * starts empty and is updated once the deployment is known. + * starts empty per the RFC and is updated once the deployment is known. + * `extensionVersion` falls back to `"unknown"` if the package.json is missing + * a version (should not happen in practice). */ export function buildContext(ctx: vscode.ExtensionContext): TelemetryContext { - const packageJson = ctx.extension.packageJSON as - | { version?: unknown } - | undefined; - const rawVersion = packageJson?.version; - const extensionVersion = typeof rawVersion === "string" ? rawVersion : ""; + const packageJson = ctx.extension.packageJSON as { version?: unknown }; + const extensionVersion = + typeof packageJson.version === "string" ? packageJson.version : "unknown"; return { extensionVersion, @@ -72,8 +72,8 @@ export function buildContext(ctx: vscode.ExtensionContext): TelemetryContext { osType: detectOsType(), osVersion: os.release(), hostArch: process.arch, - platformType: detectPlatformType(vscode.env.appName ?? ""), - platformVersion: vscode.version ?? "", + platformType: vscode.env.appName, + platformVersion: vscode.version, }; } @@ -97,26 +97,13 @@ export function buildErrorBlock( return block; } -function detectPlatformType(appName: string): string { - const lower = appName.toLowerCase(); - if (lower.includes("cursor")) { - return "cursor"; - } - if (lower.includes("vscodium")) { - return "vscodium"; - } - return "vscode"; -} - +/** + * Node returns `"win32"` on Windows; OTel's `os.type` semantic convention + * uses `"windows"`. Other Node values (`"linux"`, `"darwin"`) already match. + */ function detectOsType(): string { - switch (process.platform) { - case "linux": - return "linux"; - case "darwin": - return "darwin"; - case "win32": - return "windows"; - default: - return process.platform; + if (process.platform === "win32") { + return "windows"; } + return process.platform; } diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index b5900e1142..bc5bdf6dbb 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -12,15 +12,14 @@ import { } from "./event"; import { emitTimed, Trace, type EmitFn } from "./trace"; -const noopEmit: EmitFn = () => { - // Intentionally empty: used by NOOP_TRACE when telemetry is off. -}; -const NOOP_TRACE = new Trace("", "", noopEmit); - type TelemetryLevel = "off" | "local"; const TELEMETRY_LEVEL_SETTING = "coder.telemetry.level"; +const NOOP_TRACE = new Trace("", "", () => { + // Off-mode tracer; no events are emitted. +}); + /** * Emits structured telemetry events to a fan-out of sinks. * @@ -45,7 +44,7 @@ export class TelemetryService implements vscode.Disposable { private readonly logger: Logger, ) { this.#context = buildContext(ctx); - this.#level = readTelemetryLevel(); + this.#level = readLevel(); this.#configWatcher = watchConfigurationChanges( [ { @@ -57,11 +56,10 @@ export class TelemetryService implements vscode.Disposable { }, ], (changes) => { - this.#applyLevelChange(changes.get(TELEMETRY_LEVEL_SETTING)).catch( - (err) => { - this.logger.warn("Telemetry level change failed", err); - }, - ); + const newLevel = coerceLevel(changes.get(TELEMETRY_LEVEL_SETTING)); + this.#applyLevelChange(newLevel).catch((err) => { + this.logger.warn("Telemetry level change failed", err); + }); }, ); } @@ -130,19 +128,8 @@ export class TelemetryService implements vscode.Disposable { this.#configWatcher.dispose(); await Promise.allSettled( this.sinks.map(async (sink) => { - try { - await sink.flush(); - } catch (err) { - this.logger.warn( - `Telemetry sink '${sink.name}' flush failed during dispose`, - err, - ); - } - try { - await sink.dispose(); - } catch (err) { - this.logger.warn(`Telemetry sink '${sink.name}' dispose failed`, err); - } + await this.#safeCall(sink, "flush"); + await this.#safeCall(sink, "dispose"); }), ); } @@ -185,32 +172,41 @@ export class TelemetryService implements vscode.Disposable { this.logger.trace(`[telemetry] ${eventName}`, event); } - async #applyLevelChange(rawValue: unknown): Promise { - const newLevel = coerceLevel(rawValue); + async #applyLevelChange(newLevel: TelemetryLevel): Promise { if (newLevel === this.#level) { return; } this.#level = newLevel; if (newLevel === "off") { await Promise.allSettled( - this.sinks.map((sink) => - sink.flush().catch((err) => { - this.logger.warn(`Telemetry sink '${sink.name}' flush failed`, err); - }), - ), + this.sinks.map((sink) => this.#safeCall(sink, "flush")), ); } } + + async #safeCall( + sink: TelemetrySink, + action: "flush" | "dispose", + ): Promise { + try { + await sink[action](); + } catch (err) { + this.logger.warn(`Telemetry sink '${sink.name}' ${action} failed`, err); + } + } } -function readTelemetryLevel(): TelemetryLevel { +function readLevel(): TelemetryLevel { return coerceLevel( - vscode.workspace - .getConfiguration() - .get(TELEMETRY_LEVEL_SETTING, "local"), + vscode.workspace.getConfiguration().get(TELEMETRY_LEVEL_SETTING), ); } function coerceLevel(value: unknown): TelemetryLevel { - return value === "off" ? "off" : "local"; + switch (value) { + case "off": + return "off"; + default: + return "local"; + } } diff --git a/src/telemetry/trace.ts b/src/telemetry/trace.ts index d21a3d9fcc..fb70a9708b 100644 --- a/src/telemetry/trace.ts +++ b/src/telemetry/trace.ts @@ -23,23 +23,20 @@ export async function emitTimed( traceId?: string, ): Promise { const start = performance.now(); - try { - const result = await fn(); + const send = (result: "success" | "error", error?: unknown): void => emit( eventName, - { ...properties, result: "success" }, + { ...properties, result }, { durationMs: performance.now() - start }, traceId, + error, ); - return result; + try { + const value = await fn(); + send("success"); + return value; } catch (err) { - emit( - eventName, - { ...properties, result: "error" }, - { durationMs: performance.now() - start }, - traceId, - err, - ); + send("error", err); throw err; } } diff --git a/test/unit/telemetry/event.test.ts b/test/unit/telemetry/event.test.ts index 45d55a3e68..201e73ee37 100644 --- a/test/unit/telemetry/event.test.ts +++ b/test/unit/telemetry/event.test.ts @@ -26,34 +26,35 @@ describe("buildContext", () => { machineId: "test-machine-id", sessionId: "test-session-id", deploymentUrl: "", - platformType: "vscode", + platformType: "Visual Studio Code", platformVersion: "1.106.0-test", }); }); - it("returns truthy values for runtime os/host fields", () => { + it("derives os/host fields from process and os", () => { const ctx = buildContext(fakeContext()); - expect(ctx.osType).toBeTruthy(); + expect(ctx.hostArch).toBe(process.arch); + expect(ctx.osType).toBe( + process.platform === "win32" ? "windows" : process.platform, + ); expect(ctx.osVersion).toBeTruthy(); - expect(ctx.hostArch).toBeTruthy(); }); - it.each([ - ["Cursor", "cursor"], - ["VSCodium", "vscodium"], - ["Visual Studio Code", "vscode"], - ["Some Unknown Fork", "vscode"], - ])("derives platformType %s -> %s", (appName, expected) => { - env.appName = appName; - expect(buildContext(fakeContext()).platformType).toBe(expected); + it("preserves the raw vscode.env.appName so we keep granularity", () => { + env.appName = "Visual Studio Code - Insiders"; + expect(buildContext(fakeContext()).platformType).toBe( + "Visual Studio Code - Insiders", + ); + env.appName = "Cursor"; + expect(buildContext(fakeContext()).platformType).toBe("Cursor"); }); - it("falls back to empty string when packageJSON.version is missing or not a string", () => { + it("uses the 'unknown' sentinel when packageJSON.version is missing or non-string", () => { const noVersion = { extension: { packageJSON: {} }, } as unknown as vscodeTypes.ExtensionContext; - expect(buildContext(noVersion).extensionVersion).toBe(""); - expect(buildContext(fakeContext(123)).extensionVersion).toBe(""); + expect(buildContext(noVersion).extensionVersion).toBe("unknown"); + expect(buildContext(fakeContext(123)).extensionVersion).toBe("unknown"); }); }); @@ -75,15 +76,12 @@ describe("buildErrorBlock", () => { expect(buildErrorBlock(input)).toEqual(expected); }); - it("captures Node-style error.code as a string", () => { + it("captures Node-style and HTTP-style codes as strings", () => { expect( buildErrorBlock( Object.assign(new Error("connect failed"), { code: "ECONNREFUSED" }), - ), - ).toEqual({ message: "connect failed", code: "ECONNREFUSED" }); - }); - - it("stringifies numeric codes (HTTP status)", () => { + ).code, + ).toBe("ECONNREFUSED"); expect( buildErrorBlock(Object.assign(new Error("bad"), { code: 401 })).code, ).toBe("401"); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index 4928e9940c..77ae0b9f7b 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -54,7 +54,7 @@ describe("TelemetryService", () => { h.service.log("activation", { result: "success" }, { durationMs: 12 }); expect(h.sink.events).toHaveLength(1); - const event = h.sink.events[0]; + const [event] = h.sink.events; expect(event).toMatchObject({ eventName: "activation", eventSequence: 0, @@ -73,25 +73,18 @@ describe("TelemetryService", () => { expect(event.timestamp).toMatch(/^\d{4}-\d{2}-\d{2}T/); }); - it("issues unique eventIds and monotonic eventSequence per emission", () => { + it("emits unique eventIds and monotonic eventSequence", () => { h.service.log("a"); h.service.log("b"); h.service.log("c"); - const ids = h.sink.events.map((e) => e.eventId); - expect(new Set(ids).size).toBe(3); + expect(new Set(h.sink.events.map((e) => e.eventId)).size).toBe(3); expect(h.sink.events.map((e) => e.eventSequence)).toEqual([0, 1, 2]); }); - - it("defaults properties and measurements to empty objects", () => { - h.service.log("nothing"); - expect(h.sink.events[0].properties).toEqual({}); - expect(h.sink.events[0].measurements).toEqual({}); - }); }); describe("logError", () => { - it("attaches the error block to the event", () => { + it("attaches the normalized error block to the event", () => { h.service.logError("activation", new TypeError("nope"), { phase: "init", }); @@ -104,7 +97,7 @@ describe("TelemetryService", () => { }); describe("time", () => { - it("returns the wrapped value and emits a success event with durationMs", async () => { + it("returns the wrapped value and records durationMs on success", async () => { vi.useFakeTimers(); const promise = h.service.time( "activation", @@ -123,7 +116,7 @@ describe("TelemetryService", () => { expect(h.sink.events[0].measurements.durationMs).toBeCloseTo(250, 0); }); - it("emits an error event and rethrows on failure", async () => { + it("emits an error event with the cause and rethrows on failure", async () => { const err = new Error("boom"); await expect( h.service.time("activation", () => Promise.reject(err)), @@ -157,22 +150,29 @@ describe("TelemetryService", () => { expect(phase2.traceId).toBe(parent.traceId); }); - it("on phase failure: completed phases emit success, parent emits error summary, error rethrown", async () => { + it("on phase failure: completed phases emit success, parent emits error summary, error rethrown, later phases never run", async () => { const boom = new Error("phase-2-broke"); - const neverRuns = vi.fn(() => Promise.resolve("x")); await expect( h.service.trace("remote.setup", async (trace) => { await trace.phase("ok_phase", () => Promise.resolve("ok")); await trace.phase("bad_phase", () => Promise.reject(boom)); - await trace.phase("never_runs", neverRuns); + await trace.phase("never_runs", () => Promise.resolve("x")); }), ).rejects.toBe(boom); - expect(neverRuns).not.toHaveBeenCalled(); + // Only ok_phase, bad_phase, and the parent emitted; never_runs would have added a 4th event. + expect(h.sink.events).toHaveLength(3); const [okPhase, badPhase, parent] = h.sink.events; - expect(okPhase.properties).toMatchObject({ result: "success" }); - expect(badPhase.properties).toMatchObject({ result: "error" }); + expect(okPhase.properties).toMatchObject({ + phase: "ok_phase", + result: "success", + }); + expect(badPhase.properties).toMatchObject({ + phase: "bad_phase", + result: "error", + }); + expect(badPhase.error?.message).toBe("phase-2-broke"); expect(parent).toMatchObject({ eventName: "remote.setup", properties: { result: "error" }, @@ -218,32 +218,27 @@ describe("TelemetryService", () => { h = makeHarness("off"); }); - it("suppresses log and logError emissions", () => { + it("suppresses emissions but still runs the wrapped functions of time and trace", async () => { h.service.log("a"); h.service.logError("b", new Error("ignored")); - expect(h.sink.events).toHaveLength(0); - }); - it("still runs the wrapped functions of time and trace but emits nothing", async () => { - const timeFn = vi.fn(() => Promise.resolve(99)); - const phaseFn = vi.fn(() => Promise.resolve("x")); + expect(await h.service.time("c", () => Promise.resolve(42))).toBe(42); - expect(await h.service.time("a", timeFn)).toBe(99); - expect( - await h.service.trace("b", async (t) => { - await t.phase("p", phaseFn); - return "done"; - }), - ).toBe("done"); + const traceResult = await h.service.trace("d", async (trace) => { + const phaseValue = await trace.phase("p", () => + Promise.resolve("inner"), + ); + expect(phaseValue).toBe("inner"); + return "outer"; + }); + expect(traceResult).toBe("outer"); - expect(timeFn).toHaveBeenCalled(); - expect(phaseFn).toHaveBeenCalled(); expect(h.sink.events).toHaveLength(0); }); }); describe("reactive level", () => { - it("flushes sinks on local → off, suppresses while off, and resumes on off → local", () => { + it("local → off flushes sinks and suppresses; off → local resumes emission", () => { h.service.log("first"); expect(h.sink.events).toHaveLength(1); @@ -272,8 +267,8 @@ describe("TelemetryService", () => { write: () => { throw new Error("boom"); }, - flush: vi.fn(() => Promise.resolve()), - dispose: vi.fn(() => Promise.resolve()), + flush: () => Promise.resolve(), + dispose: () => Promise.resolve(), }; const good = new TestSink("good"); const service = makeService([bad, good]); diff --git a/test/unit/telemetry/trace.test.ts b/test/unit/telemetry/trace.test.ts index d686913ad7..61b3aea239 100644 --- a/test/unit/telemetry/trace.test.ts +++ b/test/unit/telemetry/trace.test.ts @@ -1,4 +1,4 @@ -import { describe, expect, it, vi } from "vitest"; +import { describe, expect, it } from "vitest"; import { type EmitFn, Trace } from "@/telemetry/trace"; @@ -74,19 +74,4 @@ describe("Trace.phase", () => { error: boom, }); }); - - it("does not run subsequent code after a phase rejection inside the caller", async () => { - const { emit } = makeRecorder(); - const trace = new Trace("op", "tid", emit); - const after = vi.fn(); - - await expect( - (async () => { - await trace.phase("bad", () => Promise.reject(new Error("x"))); - after(); - })(), - ).rejects.toThrow("x"); - - expect(after).not.toHaveBeenCalled(); - }); }); From 73a5a3abde2d22ff5940b6c4e47ca0edb34bc4ae Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 27 Apr 2026 18:41:24 +0300 Subject: [PATCH 3/8] refactor(telemetry): split context, move emit utilities, tighten descriptions Structural changes: - TelemetryContext now extends a readonly SessionContext. The service stores #session as readonly and tracks #deploymentUrl separately, combining them at emit time. - EmitFn and emitTimed move to a new emit.ts so the timed-emit pattern has a clear home (was previously in trace.ts alongside the Trace class). trace.ts now contains only the Trace class. - Watcher's getValue calls readLevel directly so the watcher fires only on effective level changes (e.g., toggling between unknown values that all coerce to local does not fire). Tests: - buildSession (renamed from buildContext) tests no longer mutate vscode.env.appName since platformType is now a raw passthrough. - trace.test.ts imports EmitFn from emit.ts. - Drop the unused logger field from the service test harness. package.json: - Tighten the coder.telemetry.level descriptions. --- package.json | 6 +-- src/telemetry/emit.ts | 35 +++++++++++++++++ src/telemetry/event.ts | 60 ++++++++++------------------- src/telemetry/service.ts | 53 ++++++++----------------- src/telemetry/trace.ts | 48 +---------------------- test/unit/telemetry/event.test.ts | 51 ++++++++---------------- test/unit/telemetry/service.test.ts | 20 +++++----- test/unit/telemetry/trace.test.ts | 4 +- 8 files changed, 105 insertions(+), 172 deletions(-) create mode 100644 src/telemetry/emit.ts diff --git a/package.json b/package.json index 8ab010fc0d..a836a5438f 100644 --- a/package.json +++ b/package.json @@ -191,15 +191,15 @@ "default": "basic" }, "coder.telemetry.level": { - "markdownDescription": "Controls Coder-owned telemetry collection. Local telemetry never leaves your machine and is used to diagnose issues with the extension.", + "markdownDescription": "Controls Coder extension telemetry collection. Used to diagnose extension issues.", "type": "string", "enum": [ "off", "local" ], "markdownEnumDescriptions": [ - "Disables telemetry collection entirely. No events are recorded and no files are written.", - "Records telemetry events to a local file under the extension's storage directory. Nothing is transmitted off the machine." + "Disable telemetry collection.", + "Record events on this machine only." ], "default": "local" } diff --git a/src/telemetry/emit.ts b/src/telemetry/emit.ts new file mode 100644 index 0000000000..32f5ed682c --- /dev/null +++ b/src/telemetry/emit.ts @@ -0,0 +1,35 @@ +/** Push an event into the telemetry pipeline. @internal */ +export type EmitFn = ( + eventName: string, + properties: Record, + measurements: Record, + traceId?: string, + error?: unknown, +) => void; + +/** Run an async fn and emit one event recording its outcome and `durationMs`. */ +export async function emitTimed( + emit: EmitFn, + eventName: string, + fn: () => Promise, + properties: Record, + traceId?: string, +): Promise { + const start = performance.now(); + const send = (result: "success" | "error", error?: unknown): void => + emit( + eventName, + { ...properties, result }, + { durationMs: performance.now() - start }, + traceId, + error, + ); + try { + const value = await fn(); + send("success"); + return value; + } catch (err) { + send("error", err); + throw err; + } +} diff --git a/src/telemetry/event.ts b/src/telemetry/event.ts index afa50ae26d..8e9c1ac84f 100644 --- a/src/telemetry/event.ts +++ b/src/telemetry/event.ts @@ -3,21 +3,21 @@ import * as vscode from "vscode"; import { toError } from "../error/errorUtils"; -/** - * Session-stable resource attributes carried by every event. Field names - * follow OpenTelemetry semantic conventions (`os.type`, `os.version`, - * `host.arch`) so a future OTel collector translation is a rename. - */ -export interface TelemetryContext { - extensionVersion: string; - machineId: string; - sessionId: string; +/** Session-stable resource attributes. Field names follow OTel conventions. */ +export interface SessionContext { + readonly extensionVersion: string; + readonly machineId: string; + readonly sessionId: string; + readonly osType: string; + readonly osVersion: string; + readonly hostArch: string; + readonly platformType: string; + readonly platformVersion: string; +} + +/** Per-event context: session attributes plus the current deployment URL. */ +export interface TelemetryContext extends SessionContext { deploymentUrl: string; - osType: string; - osVersion: string; - hostArch: string; - platformType: string; - platformVersion: string; } export interface TelemetryEvent { @@ -41,10 +41,8 @@ export interface TelemetryEvent { } /** - * Destination for telemetry events. `write` runs on the hot path and must - * buffer in memory; I/O happens in `flush`/`dispose`. Sinks own their own - * gating beyond the service-level kill switch (e.g. a server sink emits only - * when the user opts into deployment telemetry). + * Sink for telemetry events. `write` is sync and must buffer in memory; I/O + * happens in `flush`/`dispose`. Sinks self-gate beyond the service kill switch. */ export interface TelemetrySink { readonly name: string; @@ -53,13 +51,8 @@ export interface TelemetrySink { dispose(): Promise; } -/** - * Build the session-stable context attached to every event. `deploymentUrl` - * starts empty per the RFC and is updated once the deployment is known. - * `extensionVersion` falls back to `"unknown"` if the package.json is missing - * a version (should not happen in practice). - */ -export function buildContext(ctx: vscode.ExtensionContext): TelemetryContext { +/** Build session attributes. `extensionVersion` falls back to `"unknown"`. */ +export function buildSession(ctx: vscode.ExtensionContext): SessionContext { const packageJson = ctx.extension.packageJSON as { version?: unknown }; const extensionVersion = typeof packageJson.version === "string" ? packageJson.version : "unknown"; @@ -68,7 +61,6 @@ export function buildContext(ctx: vscode.ExtensionContext): TelemetryContext { extensionVersion, machineId: vscode.env.machineId, sessionId: vscode.env.sessionId, - deploymentUrl: "", osType: detectOsType(), osVersion: os.release(), hostArch: process.arch, @@ -77,11 +69,7 @@ export function buildContext(ctx: vscode.ExtensionContext): TelemetryContext { }; } -/** - * Normalize any thrown value into the structured `error` block of an event. - * `type` comes from `Error.name` (skipped when generic). `code` captures - * Node's `error.code` for system errors and HTTP statuses for API errors. - */ +/** Normalize a thrown value into the event's `error` block. */ export function buildErrorBlock( value: unknown, ): NonNullable { @@ -97,13 +85,7 @@ export function buildErrorBlock( return block; } -/** - * Node returns `"win32"` on Windows; OTel's `os.type` semantic convention - * uses `"windows"`. Other Node values (`"linux"`, `"darwin"`) already match. - */ +// Node uses "win32" on Windows; OTel's os.type is "windows". function detectOsType(): string { - if (process.platform === "win32") { - return "windows"; - } - return process.platform; + return process.platform === "win32" ? "windows" : process.platform; } diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index bc5bdf6dbb..d004cf865c 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -3,14 +3,15 @@ import * as vscode from "vscode"; import { watchConfigurationChanges } from "../configWatcher"; import { type Logger } from "../logging/logger"; +import { emitTimed, type EmitFn } from "./emit"; import { - buildContext, + buildSession, buildErrorBlock, - type TelemetryContext, + type SessionContext, type TelemetryEvent, type TelemetrySink, } from "./event"; -import { emitTimed, Trace, type EmitFn } from "./trace"; +import { Trace } from "./trace"; type TelemetryLevel = "off" | "local"; @@ -21,20 +22,15 @@ const NOOP_TRACE = new Trace("", "", () => { }); /** - * Emits structured telemetry events to a fan-out of sinks. - * - * Phase A ships with no real sinks; this service is the spine that future - * sinks (`LocalJsonlSink`, `CoderServerSink`, external services) plug into. - * Each sink owns its own gating beyond the service-level - * `coder.telemetry.level` kill switch. - * - * `dispose()` returns `Promise` for explicit awaits; VS Code does not - * await deactivation, so flushes during shutdown are best-effort. + * Emits structured telemetry events to a fan-out of sinks. Sinks self-gate; + * `dispose` flushes are best-effort during deactivation since VS Code does + * not await it. */ export class TelemetryService implements vscode.Disposable { #level: TelemetryLevel; #nextSequence = 0; - #context: TelemetryContext; + #deploymentUrl = ""; + readonly #session: SessionContext; readonly #configWatcher: vscode.Disposable; readonly #emitter: EmitFn = (n, p, m, t, e) => this.#emit(n, p, m, t, e); @@ -43,20 +39,12 @@ export class TelemetryService implements vscode.Disposable { private readonly sinks: readonly TelemetrySink[], private readonly logger: Logger, ) { - this.#context = buildContext(ctx); + this.#session = buildSession(ctx); this.#level = readLevel(); this.#configWatcher = watchConfigurationChanges( - [ - { - setting: TELEMETRY_LEVEL_SETTING, - getValue: () => - vscode.workspace - .getConfiguration() - .get(TELEMETRY_LEVEL_SETTING), - }, - ], + [{ setting: TELEMETRY_LEVEL_SETTING, getValue: readLevel }], (changes) => { - const newLevel = coerceLevel(changes.get(TELEMETRY_LEVEL_SETTING)); + const newLevel = changes.get(TELEMETRY_LEVEL_SETTING) as TelemetryLevel; this.#applyLevelChange(newLevel).catch((err) => { this.logger.warn("Telemetry level change failed", err); }); @@ -65,10 +53,7 @@ export class TelemetryService implements vscode.Disposable { } setDeploymentUrl(url: string): void { - if (url === this.#context.deploymentUrl) { - return; - } - this.#context = { ...this.#context, deploymentUrl: url }; + this.#deploymentUrl = url; } log( @@ -150,7 +135,7 @@ export class TelemetryService implements vscode.Disposable { eventName, timestamp: new Date().toISOString(), eventSequence: this.#nextSequence++, - context: { ...this.#context }, + context: { ...this.#session, deploymentUrl: this.#deploymentUrl }, properties, measurements, }; @@ -197,13 +182,9 @@ export class TelemetryService implements vscode.Disposable { } function readLevel(): TelemetryLevel { - return coerceLevel( - vscode.workspace.getConfiguration().get(TELEMETRY_LEVEL_SETTING), - ); -} - -function coerceLevel(value: unknown): TelemetryLevel { - switch (value) { + switch ( + vscode.workspace.getConfiguration().get(TELEMETRY_LEVEL_SETTING) + ) { case "off": return "off"; default: diff --git a/src/telemetry/trace.ts b/src/telemetry/trace.ts index fb70a9708b..f69b4af457 100644 --- a/src/telemetry/trace.ts +++ b/src/telemetry/trace.ts @@ -1,50 +1,6 @@ -/** - * Internal contract used by `Trace` to push events through the service. - * @internal - */ -export type EmitFn = ( - eventName: string, - properties: Record, - measurements: Record, - traceId?: string, - error?: unknown, -) => void; +import { emitTimed, type EmitFn } from "./emit"; -/** - * Run an async operation and emit a single event recording its outcome and - * `durationMs`. Used by `time`, `trace`, and `Trace.phase` to share the - * success/error reporting pattern. - */ -export async function emitTimed( - emit: EmitFn, - eventName: string, - fn: () => Promise, - properties: Record, - traceId?: string, -): Promise { - const start = performance.now(); - const send = (result: "success" | "error", error?: unknown): void => - emit( - eventName, - { ...properties, result }, - { durationMs: performance.now() - start }, - traceId, - error, - ); - try { - const value = await fn(); - send("success"); - return value; - } catch (err) { - send("error", err); - throw err; - } -} - -/** - * Correlation handle for a multi-phase operation. The same `traceId` is - * shared by the parent event and every child phase event. - */ +/** Correlation handle: parent and all child phase events share one `traceId`. */ export class Trace { constructor( private readonly parentEventName: string, diff --git a/test/unit/telemetry/event.test.ts b/test/unit/telemetry/event.test.ts index 201e73ee37..737f59aa0d 100644 --- a/test/unit/telemetry/event.test.ts +++ b/test/unit/telemetry/event.test.ts @@ -1,60 +1,39 @@ -import { afterEach, describe, expect, it } from "vitest"; -import * as vscode from "vscode"; +import { describe, expect, it } from "vitest"; -import { buildContext, buildErrorBlock } from "@/telemetry/event"; +import { buildErrorBlock, buildSession } from "@/telemetry/event"; -import type * as vscodeTypes from "vscode"; +import type * as vscode from "vscode"; -function fakeContext( - version: unknown = "1.2.3-test", -): vscodeTypes.ExtensionContext { +function fakeContext(version: unknown = "1.2.3-test"): vscode.ExtensionContext { return { extension: { packageJSON: { version } }, - } as unknown as vscodeTypes.ExtensionContext; + } as unknown as vscode.ExtensionContext; } -describe("buildContext", () => { - const env = vscode.env as { appName: string }; - const originalAppName = env.appName; - afterEach(() => { - env.appName = originalAppName; - }); +describe("buildSession", () => { + it("populates session-stable fields from the extension context, vscode env, and host", () => { + const session = buildSession(fakeContext()); - it("populates session-stable fields from the extension context and vscode env", () => { - expect(buildContext(fakeContext())).toMatchObject({ + expect(session).toMatchObject({ extensionVersion: "1.2.3-test", machineId: "test-machine-id", sessionId: "test-session-id", - deploymentUrl: "", platformType: "Visual Studio Code", platformVersion: "1.106.0-test", + hostArch: process.arch, }); - }); - - it("derives os/host fields from process and os", () => { - const ctx = buildContext(fakeContext()); - expect(ctx.hostArch).toBe(process.arch); - expect(ctx.osType).toBe( + expect(session.osType).toBe( process.platform === "win32" ? "windows" : process.platform, ); - expect(ctx.osVersion).toBeTruthy(); - }); - - it("preserves the raw vscode.env.appName so we keep granularity", () => { - env.appName = "Visual Studio Code - Insiders"; - expect(buildContext(fakeContext()).platformType).toBe( - "Visual Studio Code - Insiders", - ); - env.appName = "Cursor"; - expect(buildContext(fakeContext()).platformType).toBe("Cursor"); + expect(session.osVersion).toBeTruthy(); }); it("uses the 'unknown' sentinel when packageJSON.version is missing or non-string", () => { const noVersion = { extension: { packageJSON: {} }, - } as unknown as vscodeTypes.ExtensionContext; - expect(buildContext(noVersion).extensionVersion).toBe("unknown"); - expect(buildContext(fakeContext(123)).extensionVersion).toBe("unknown"); + } as unknown as vscode.ExtensionContext; + expect(buildSession(noVersion).extensionVersion).toBe("unknown"); + expect(buildSession(fakeContext(123)).extensionVersion).toBe("unknown"); }); }); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index 77ae0b9f7b..bc0b4e69e8 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -10,7 +10,6 @@ import { import type * as vscode from "vscode"; -import type { Logger } from "@/logging/logger"; import type { TelemetrySink } from "@/telemetry/event"; function fakeContext(): vscode.ExtensionContext { @@ -22,17 +21,19 @@ function fakeContext(): vscode.ExtensionContext { interface Harness { service: TelemetryService; sink: TestSink; - logger: Logger; config: MockConfigurationProvider; } function makeHarness(level: "off" | "local" = "local"): Harness { const config = new MockConfigurationProvider(); config.set("coder.telemetry.level", level); - const logger = createMockLogger(); const sink = new TestSink(); - const service = new TelemetryService(fakeContext(), [sink], logger); - return { service, sink, logger, config }; + const service = new TelemetryService( + fakeContext(), + [sink], + createMockLogger(), + ); + return { service, sink, config }; } function makeService(sinks: TelemetrySink[]): TelemetryService { @@ -53,7 +54,6 @@ describe("TelemetryService", () => { it("emits an event with auto-injected context, properties, and measurements", () => { h.service.log("activation", { result: "success" }, { durationMs: 12 }); - expect(h.sink.events).toHaveLength(1); const [event] = h.sink.events; expect(event).toMatchObject({ eventName: "activation", @@ -150,7 +150,7 @@ describe("TelemetryService", () => { expect(phase2.traceId).toBe(parent.traceId); }); - it("on phase failure: completed phases emit success, parent emits error summary, error rethrown, later phases never run", async () => { + 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"); await expect( @@ -161,7 +161,6 @@ describe("TelemetryService", () => { }), ).rejects.toBe(boom); - // Only ok_phase, bad_phase, and the parent emitted; never_runs would have added a 4th event. expect(h.sink.events).toHaveLength(3); const [okPhase, badPhase, parent] = h.sink.events; expect(okPhase.properties).toMatchObject({ @@ -172,7 +171,6 @@ describe("TelemetryService", () => { phase: "bad_phase", result: "error", }); - expect(badPhase.error?.message).toBe("phase-2-broke"); expect(parent).toMatchObject({ eventName: "remote.setup", properties: { result: "error" }, @@ -218,7 +216,7 @@ describe("TelemetryService", () => { h = makeHarness("off"); }); - it("suppresses emissions but still runs the wrapped functions of time and trace", async () => { + it("suppresses emissions but still runs wrapped functions of time and trace", async () => { h.service.log("a"); h.service.logError("b", new Error("ignored")); @@ -238,7 +236,7 @@ describe("TelemetryService", () => { }); describe("reactive level", () => { - it("local → off flushes sinks and suppresses; off → local resumes emission", () => { + it("local → off flushes sinks and suppresses; off → local resumes", () => { h.service.log("first"); expect(h.sink.events).toHaveLength(1); diff --git a/test/unit/telemetry/trace.test.ts b/test/unit/telemetry/trace.test.ts index 61b3aea239..5322841fd6 100644 --- a/test/unit/telemetry/trace.test.ts +++ b/test/unit/telemetry/trace.test.ts @@ -1,6 +1,8 @@ import { describe, expect, it } from "vitest"; -import { type EmitFn, Trace } from "@/telemetry/trace"; +import { Trace } from "@/telemetry/trace"; + +import type { EmitFn } from "@/telemetry/emit"; interface RecordedCall { eventName: string; From 79cd3f61f1026d78685a8fd664c6bfeb88a0e8e3 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Tue, 28 Apr 2026 19:31:59 +0300 Subject: [PATCH 4/8] Address review comments --- src/telemetry/event.ts | 8 +++++++- src/telemetry/service.ts | 26 +++++++++++++------------- src/telemetry/trace.ts | 4 ++++ test/mocks/telemetry.ts | 10 ++++++++-- test/unit/telemetry/service.test.ts | 2 ++ 5 files changed, 34 insertions(+), 16 deletions(-) diff --git a/src/telemetry/event.ts b/src/telemetry/event.ts index 8e9c1ac84f..0a6c51c932 100644 --- a/src/telemetry/event.ts +++ b/src/telemetry/event.ts @@ -3,6 +3,9 @@ import * as vscode from "vscode"; import { toError } from "../error/errorUtils"; +/** Telemetry level, mirrors `coder.telemetry.level`. Ordered: off < local. */ +export type TelemetryLevel = "off" | "local"; + /** Session-stable resource attributes. Field names follow OTel conventions. */ export interface SessionContext { readonly extensionVersion: string; @@ -42,10 +45,12 @@ export interface TelemetryEvent { /** * Sink for telemetry events. `write` is sync and must buffer in memory; I/O - * happens in `flush`/`dispose`. Sinks self-gate beyond the service kill switch. + * happens in `flush`/`dispose`. The service filters by `minLevel`; sinks can + * still self-gate on other signals (e.g. deployment URL). */ export interface TelemetrySink { readonly name: string; + readonly minLevel: TelemetryLevel; write(event: TelemetryEvent): void; flush(): Promise; dispose(): Promise; @@ -53,6 +58,7 @@ export interface TelemetrySink { /** Build session attributes. `extensionVersion` falls back to `"unknown"`. */ export function buildSession(ctx: vscode.ExtensionContext): SessionContext { + // "unknown" only for malformed package.json or test fixtures missing `version`. const packageJson = ctx.extension.packageJSON as { version?: unknown }; const extensionVersion = typeof packageJson.version === "string" ? packageJson.version : "unknown"; diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index d004cf865c..1682ca5c71 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -9,22 +9,22 @@ import { buildErrorBlock, type SessionContext, type TelemetryEvent, + type TelemetryLevel, type TelemetrySink, } from "./event"; import { Trace } from "./trace"; -type TelemetryLevel = "off" | "local"; - const TELEMETRY_LEVEL_SETTING = "coder.telemetry.level"; -const NOOP_TRACE = new Trace("", "", () => { - // Off-mode tracer; no events are emitted. -}); +const LEVEL_ORDER: Readonly> = { + off: 0, + local: 1, +}; /** - * Emits structured telemetry events to a fan-out of sinks. Sinks self-gate; - * `dispose` flushes are best-effort during deactivation since VS Code does - * not await it. + * Emits structured telemetry events to a fan-out of sinks. The service filters + * sinks by `minLevel`; sinks may self-gate further. `dispose` flushes are + * best-effort during deactivation since VS Code does not await it. */ export class TelemetryService implements vscode.Disposable { #level: TelemetryLevel; @@ -96,7 +96,7 @@ export class TelemetryService implements vscode.Disposable { properties: Record = {}, ): Promise { if (this.#level === "off") { - return fn(NOOP_TRACE); + return fn(Trace.NOOP); } const traceId = crypto.randomUUID(); const tracer = new Trace(eventName, traceId, this.#emitter); @@ -126,10 +126,6 @@ export class TelemetryService implements vscode.Disposable { traceId?: string, error?: unknown, ): void { - if (this.#level === "off") { - return; - } - const event: TelemetryEvent = { eventId: crypto.randomUUID(), eventName, @@ -146,7 +142,11 @@ export class TelemetryService implements vscode.Disposable { event.error = buildErrorBlock(error); } + const currentOrder = LEVEL_ORDER[this.#level]; for (const sink of this.sinks) { + if (currentOrder < LEVEL_ORDER[sink.minLevel]) { + continue; + } try { sink.write(event); } catch (err) { diff --git a/src/telemetry/trace.ts b/src/telemetry/trace.ts index f69b4af457..217f8ffbf7 100644 --- a/src/telemetry/trace.ts +++ b/src/telemetry/trace.ts @@ -2,6 +2,10 @@ import { emitTimed, type EmitFn } from "./emit"; /** Correlation handle: parent and all child phase events share one `traceId`. */ export class Trace { + public static readonly NOOP = new Trace("", "", () => { + /* Off-mode tracer; phases run their fn but emit nothing. */ + }); + constructor( private readonly parentEventName: string, public readonly traceId: string, diff --git a/test/mocks/telemetry.ts b/test/mocks/telemetry.ts index 0a8f160c2e..4a9c188683 100644 --- a/test/mocks/telemetry.ts +++ b/test/mocks/telemetry.ts @@ -1,6 +1,10 @@ import { vi } from "vitest"; -import type { TelemetryEvent, TelemetrySink } from "@/telemetry/event"; +import type { + TelemetryEvent, + TelemetryLevel, + TelemetrySink, +} from "@/telemetry/event"; /** * In-memory `TelemetrySink` for tests. Captures every written event and @@ -8,12 +12,14 @@ import type { TelemetryEvent, TelemetrySink } from "@/telemetry/event"; */ export class TestSink implements TelemetrySink { readonly name: string; + readonly minLevel: TelemetryLevel; readonly events: TelemetryEvent[] = []; readonly flush = vi.fn(() => Promise.resolve()); readonly dispose = vi.fn(() => Promise.resolve()); - constructor(name = "test") { + constructor(name = "test", minLevel: TelemetryLevel = "local") { this.name = name; + this.minLevel = minLevel; } write(event: TelemetryEvent): void { diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index bc0b4e69e8..df00e72b52 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -262,6 +262,7 @@ describe("TelemetryService", () => { it("a throwing sink does not block other sinks from receiving events", () => { const bad: TelemetrySink = { name: "bad", + minLevel: "local", write: () => { throw new Error("boom"); }, @@ -294,6 +295,7 @@ describe("TelemetryService", () => { it("resolves even when sinks reject in flush or dispose", async () => { const bad: TelemetrySink = { name: "bad", + minLevel: "local", write: () => {}, flush: () => Promise.reject(new Error("flush fail")), dispose: () => Promise.reject(new Error("dispose fail")), From 3ab123ce2a62058aa148fd2944e4acf42ebab0ba Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Thu, 30 Apr 2026 11:46:26 +0300 Subject: [PATCH 5/8] refactor(telemetry): OTel-Traces shape and error isolation - Phase events compose hierarchical eventNames; new parentEventId encodes parent/child unambiguously under retries. time also carries a traceId so every timed event maps to an OTel span. - Trace -> Span; phase callback receives a child Span, so grandchildren are just recursion. time/trace/phase accept caller measurements. - All emission routed through #safeEmit so telemetry failures never reach callers; per-sink try/catch isolates writes. - Address review fixes: logger.dispose last, readonly fields, isTelemetryLevel guard, platformType -> platformName, telemetry tag on the setting, setDeploymentUrl test assertions, reactive-level test fix. --- package.json | 5 +- src/core/container.ts | 3 +- src/telemetry/emit.ts | 35 --- src/telemetry/event.ts | 46 ++-- src/telemetry/service.ts | 186 ++++++++++++---- src/telemetry/span.ts | 31 +++ src/telemetry/trace.ts | 28 --- .../unit/deployment/deploymentManager.test.ts | 28 +++ test/unit/telemetry/event.test.ts | 2 +- test/unit/telemetry/service.test.ts | 203 ++++++++++++++++-- test/unit/telemetry/trace.test.ts | 79 ------- 11 files changed, 417 insertions(+), 229 deletions(-) delete mode 100644 src/telemetry/emit.ts create mode 100644 src/telemetry/span.ts delete mode 100644 src/telemetry/trace.ts delete mode 100644 test/unit/telemetry/trace.test.ts diff --git a/package.json b/package.json index a836a5438f..b3193f14c7 100644 --- a/package.json +++ b/package.json @@ -201,7 +201,10 @@ "Disable telemetry collection.", "Record events on this machine only." ], - "default": "local" + "default": "local", + "tags": [ + "telemetry" + ] } } }, diff --git a/src/core/container.ts b/src/core/container.ts index 92cc800c14..7506502fe8 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -146,9 +146,10 @@ export class ServiceContainer implements vscode.Disposable { */ dispose(): void { this.contextManager.dispose(); - this.logger.dispose(); this.loginCoordinator.dispose(); // Fire-and-forget: VS Code does not await deactivation. void this.telemetryService.dispose(); + // Logger last so telemetry teardown can still log warnings. + this.logger.dispose(); } } diff --git a/src/telemetry/emit.ts b/src/telemetry/emit.ts deleted file mode 100644 index 32f5ed682c..0000000000 --- a/src/telemetry/emit.ts +++ /dev/null @@ -1,35 +0,0 @@ -/** Push an event into the telemetry pipeline. @internal */ -export type EmitFn = ( - eventName: string, - properties: Record, - measurements: Record, - traceId?: string, - error?: unknown, -) => void; - -/** Run an async fn and emit one event recording its outcome and `durationMs`. */ -export async function emitTimed( - emit: EmitFn, - eventName: string, - fn: () => Promise, - properties: Record, - traceId?: string, -): Promise { - const start = performance.now(); - const send = (result: "success" | "error", error?: unknown): void => - emit( - eventName, - { ...properties, result }, - { durationMs: performance.now() - start }, - traceId, - error, - ); - try { - const value = await fn(); - send("success"); - return value; - } catch (err) { - send("error", err); - throw err; - } -} diff --git a/src/telemetry/event.ts b/src/telemetry/event.ts index 0a6c51c932..8f90ee23be 100644 --- a/src/telemetry/event.ts +++ b/src/telemetry/event.ts @@ -6,7 +6,8 @@ import { toError } from "../error/errorUtils"; /** Telemetry level, mirrors `coder.telemetry.level`. Ordered: off < local. */ export type TelemetryLevel = "off" | "local"; -/** Session-stable resource attributes. Field names follow OTel conventions. */ +/** Session-stable resource attributes. Field names are inspired by OTel + * resource attributes; they are camelCase TypeScript and not a 1:1 mapping. */ export interface SessionContext { readonly extensionVersion: string; readonly machineId: string; @@ -14,33 +15,36 @@ export interface SessionContext { readonly osType: string; readonly osVersion: string; readonly hostArch: string; - readonly platformType: string; + readonly platformName: string; readonly platformVersion: string; } /** Per-event context: session attributes plus the current deployment URL. */ export interface TelemetryContext extends SessionContext { - deploymentUrl: string; + readonly deploymentUrl: string; } export interface TelemetryEvent { - eventId: string; - eventName: string; - timestamp: string; - eventSequence: number; + readonly eventId: string; + readonly eventName: string; + readonly timestamp: string; + readonly eventSequence: number; - context: TelemetryContext; + readonly context: TelemetryContext; - properties: Record; - measurements: Record; + readonly properties: Readonly>; + readonly measurements: Readonly>; - traceId?: string; + /** Shared by all events in a trace. Maps to OTel `trace_id`. */ + readonly traceId?: string; + /** Set on phase children only. Equals the parent event's `eventId`. Maps to OTel `parent_span_id`. */ + readonly parentEventId?: string; - error?: { + readonly error?: Readonly<{ message: string; type?: string; code?: string; - }; + }>; } /** @@ -70,7 +74,7 @@ export function buildSession(ctx: vscode.ExtensionContext): SessionContext { osType: detectOsType(), osVersion: os.release(), hostArch: process.arch, - platformType: vscode.env.appName, + platformName: vscode.env.appName, platformVersion: vscode.version, }; } @@ -80,15 +84,13 @@ export function buildErrorBlock( value: unknown, ): NonNullable { const err = toError(value); - const block: NonNullable = { message: err.message }; - if (err.name && err.name !== "Error") { - block.type = err.name; - } const rawCode = (value as { code?: unknown } | null | undefined)?.code; - if (typeof rawCode === "string" || typeof rawCode === "number") { - block.code = String(rawCode); - } - return block; + const hasCode = typeof rawCode === "string" || typeof rawCode === "number"; + return { + message: err.message, + ...(err.name && err.name !== "Error" && { type: err.name }), + ...(hasCode && { code: String(rawCode) }), + }; } // Node uses "win32" on Windows; OTel's os.type is "windows". diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index 1682ca5c71..709e9dc6bf 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -3,7 +3,6 @@ import * as vscode from "vscode"; import { watchConfigurationChanges } from "../configWatcher"; import { type Logger } from "../logging/logger"; -import { emitTimed, type EmitFn } from "./emit"; import { buildSession, buildErrorBlock, @@ -12,7 +11,7 @@ import { type TelemetryLevel, type TelemetrySink, } from "./event"; -import { Trace } from "./trace"; +import { NOOP_SPAN, type Span } from "./span"; const TELEMETRY_LEVEL_SETTING = "coder.telemetry.level"; @@ -21,10 +20,16 @@ const LEVEL_ORDER: Readonly> = { local: 1, }; +interface EmitOptions { + traceId?: string; + parentEventId?: string; + error?: unknown; +} + /** - * Emits structured telemetry events to a fan-out of sinks. The service filters - * sinks by `minLevel`; sinks may self-gate further. `dispose` flushes are - * best-effort during deactivation since VS Code does not await it. + * Emits structured telemetry events to a fan-out of sinks. Sinks are filtered + * by `minLevel` and may self-gate. `dispose` flushes are best-effort since + * VS Code does not await deactivation. */ export class TelemetryService implements vscode.Disposable { #level: TelemetryLevel; @@ -32,9 +37,8 @@ export class TelemetryService implements vscode.Disposable { #deploymentUrl = ""; readonly #session: SessionContext; readonly #configWatcher: vscode.Disposable; - readonly #emitter: EmitFn = (n, p, m, t, e) => this.#emit(n, p, m, t, e); - constructor( + public constructor( ctx: vscode.ExtensionContext, private readonly sinks: readonly TelemetrySink[], private readonly logger: Logger, @@ -44,19 +48,22 @@ export class TelemetryService implements vscode.Disposable { this.#configWatcher = watchConfigurationChanges( [{ setting: TELEMETRY_LEVEL_SETTING, getValue: readLevel }], (changes) => { - const newLevel = changes.get(TELEMETRY_LEVEL_SETTING) as TelemetryLevel; - this.#applyLevelChange(newLevel).catch((err) => { + const raw = changes.get(TELEMETRY_LEVEL_SETTING); + if (!isTelemetryLevel(raw)) { + return; + } + this.#applyLevelChange(raw).catch((err) => { this.logger.warn("Telemetry level change failed", err); }); }, ); } - setDeploymentUrl(url: string): void { + public setDeploymentUrl(url: string): void { this.#deploymentUrl = url; } - log( + public log( eventName: string, properties: Record = {}, measurements: Record = {}, @@ -64,10 +71,10 @@ export class TelemetryService implements vscode.Disposable { if (this.#level === "off") { return; } - this.#emit(eventName, properties, measurements); + this.#safeEmit(crypto.randomUUID(), eventName, properties, measurements); } - logError( + public logError( eventName: string, error: unknown, properties: Record = {}, @@ -76,40 +83,44 @@ export class TelemetryService implements vscode.Disposable { if (this.#level === "off") { return; } - this.#emit(eventName, properties, measurements, undefined, error); + this.#safeEmit(crypto.randomUUID(), eventName, properties, measurements, { + error, + }); } - time( + /** Time `fn` and emit one event with `durationMs` and `result`. */ + public time( eventName: string, fn: () => Promise, properties: Record = {}, + measurements: Record = {}, ): Promise { - if (this.#level === "off") { - return fn(); - } - return emitTimed(this.#emitter, eventName, fn, properties); + return this.trace(eventName, fn, properties, measurements); } - trace( + /** + * Run a multi-phase operation. All events share a `traceId`; each non-root + * carries `parentEventId`. Framework sets `result` and `durationMs`. + */ + public trace( eventName: string, - fn: (trace: Trace) => Promise, + fn: (span: Span) => Promise, properties: Record = {}, + measurements: Record = {}, ): Promise { if (this.#level === "off") { - return fn(Trace.NOOP); + return fn(NOOP_SPAN); } - const traceId = crypto.randomUUID(); - const tracer = new Trace(eventName, traceId, this.#emitter); - return emitTimed( - this.#emitter, + return this.#startSpan( + crypto.randomUUID(), eventName, - () => fn(tracer), + fn, properties, - traceId, + measurements, ); } - async dispose(): Promise { + public async dispose(): Promise { this.#configWatcher.dispose(); await Promise.allSettled( this.sinks.map(async (sink) => { @@ -119,28 +130,119 @@ export class TelemetryService implements vscode.Disposable { ); } + #startSpan( + traceId: string, + eventName: string, + fn: (span: Span) => Promise, + properties: Record, + measurements: Record, + parentEventId?: string, + ): Promise { + const eventId = crypto.randomUUID(); + const span: Span = { + traceId, + eventId, + eventName, + phase: ( + phaseName: string, + phaseFn: (childSpan: Span) => Promise, + phaseProps: Record = {}, + phaseMeasurements: Record = {}, + ): Promise => { + const safeName = this.#sanitizePhaseName(phaseName); + return this.#startSpan( + traceId, + `${eventName}.${safeName}`, + phaseFn, + phaseProps, + phaseMeasurements, + eventId, + ); + }, + }; + return this.#emitTimed( + eventId, + eventName, + () => fn(span), + properties, + measurements, + { traceId, parentEventId }, + ); + } + + #sanitizePhaseName(name: string): string { + if (!name.includes(".")) { + return name; + } + const sanitized = name.replaceAll(".", "_"); + this.logger.warn( + `Telemetry phase name '${name}' contains '.', sanitized to '${sanitized}'`, + ); + return sanitized; + } + + async #emitTimed( + eventId: string, + eventName: string, + fn: () => Promise, + properties: Record, + measurements: Record, + options: Omit = {}, + ): Promise { + const start = performance.now(); + const send = (result: "success" | "error", error?: unknown): void => + this.#safeEmit( + eventId, + eventName, + { ...properties, result }, + { ...measurements, durationMs: performance.now() - start }, + { ...options, error }, + ); + try { + const value = await fn(); + send("success"); + return value; + } catch (err) { + send("error", err); + throw err; + } + } + + /** Catch-all wrapper around `#emit`: telemetry failures never reach callers. */ + #safeEmit( + eventId: string, + eventName: string, + properties: Record, + measurements: Record, + options: EmitOptions = {}, + ): void { + try { + this.#emit(eventId, eventName, properties, measurements, options); + } catch (err) { + this.logger.warn("Telemetry emit failed", err); + } + } + #emit( + eventId: string, eventName: string, properties: Record, measurements: Record, - traceId?: string, - error?: unknown, + options: EmitOptions = {}, ): void { + const { traceId, parentEventId, error } = options; const event: TelemetryEvent = { - eventId: crypto.randomUUID(), + eventId, eventName, timestamp: new Date().toISOString(), eventSequence: this.#nextSequence++, context: { ...this.#session, deploymentUrl: this.#deploymentUrl }, - properties, - measurements, + properties: { ...properties }, + measurements: { ...measurements }, + ...(traceId !== undefined && { traceId }), + ...(parentEventId !== undefined && { parentEventId }), + ...(error !== undefined && { error: buildErrorBlock(error) }), }; - if (traceId !== undefined) { - event.traceId = traceId; - } - if (error !== undefined) { - event.error = buildErrorBlock(error); - } const currentOrder = LEVEL_ORDER[this.#level]; for (const sink of this.sinks) { @@ -191,3 +293,7 @@ function readLevel(): TelemetryLevel { return "local"; } } + +function isTelemetryLevel(value: unknown): value is TelemetryLevel { + return value === "off" || value === "local"; +} diff --git a/src/telemetry/span.ts b/src/telemetry/span.ts new file mode 100644 index 0000000000..898bcdf84c --- /dev/null +++ b/src/telemetry/span.ts @@ -0,0 +1,31 @@ +/** + * Parent span handle. Children's `eventName` composes as `${parent.eventName}.${phaseName}`; + * phase names must not contain `.`. Recurse via `phase` for grandchildren. + */ +export interface Span { + readonly traceId: string; + readonly eventId: string; + readonly eventName: string; + /** Emit a child phase event. Framework sets `result` and `durationMs`. */ + phase( + phaseName: string, + fn: (span: Span) => Promise, + properties?: Record, + measurements?: Record, + ): Promise; +} + +/** No-op `Span` used when telemetry is off. Runs phase fns but emits nothing. */ +export const NOOP_SPAN: Span = { + traceId: "", + eventId: "", + eventName: "", + phase( + _phaseName: string, + fn: (span: Span) => Promise, + _properties?: Record, + _measurements?: Record, + ): Promise { + return fn(this); + }, +}; diff --git a/src/telemetry/trace.ts b/src/telemetry/trace.ts deleted file mode 100644 index 217f8ffbf7..0000000000 --- a/src/telemetry/trace.ts +++ /dev/null @@ -1,28 +0,0 @@ -import { emitTimed, type EmitFn } from "./emit"; - -/** Correlation handle: parent and all child phase events share one `traceId`. */ -export class Trace { - public static readonly NOOP = new Trace("", "", () => { - /* Off-mode tracer; phases run their fn but emit nothing. */ - }); - - constructor( - private readonly parentEventName: string, - public readonly traceId: string, - private readonly emit: EmitFn, - ) {} - - phase( - phaseName: string, - fn: () => Promise, - properties: Record = {}, - ): Promise { - return emitTimed( - this.emit, - `${this.parentEventName}.phase`, - fn, - { ...properties, phase: phaseName }, - this.traceId, - ); - } -} diff --git a/test/unit/deployment/deploymentManager.test.ts b/test/unit/deployment/deploymentManager.test.ts index d2830a5655..87b4872e2e 100644 --- a/test/unit/deployment/deploymentManager.test.ts +++ b/test/unit/deployment/deploymentManager.test.ts @@ -92,6 +92,7 @@ function createTestContext() { contextManager, mockOAuthSessionManager, mockWorkspaceProvider, + telemetryService, manager, }; } @@ -163,6 +164,19 @@ describe("DeploymentManager", () => { expect(persisted?.url).toBe(TEST_URL); }); + it("notifies telemetry of the deployment URL", async () => { + const { telemetryService, manager } = createTestContext(); + + await manager.setDeployment({ + url: TEST_URL, + safeHostname: TEST_HOSTNAME, + token: "test-token", + user: createMockUser(), + }); + + expect(telemetryService.setDeploymentUrl).toHaveBeenCalledWith(TEST_URL); + }); + it("sets isOwner context when user has owner role", async () => { const { contextManager, manager } = createTestContext(); const ownerUser = createMockUser({ @@ -389,6 +403,20 @@ describe("DeploymentManager", () => { expect(contextManager.get("coder.authenticated")).toBe(false); expect(contextManager.get("coder.isOwner")).toBe(false); }); + + it("resets the telemetry deployment URL on clearDeployment", async () => { + const { telemetryService, manager } = createTestContext(); + + await manager.setDeployment({ + url: TEST_URL, + safeHostname: TEST_HOSTNAME, + token: "test-token", + user: createMockUser(), + }); + await manager.clearDeployment(); + + expect(telemetryService.setDeploymentUrl).toHaveBeenLastCalledWith(""); + }); }); describe("suspendSession", () => { diff --git a/test/unit/telemetry/event.test.ts b/test/unit/telemetry/event.test.ts index 737f59aa0d..1ad5d455af 100644 --- a/test/unit/telemetry/event.test.ts +++ b/test/unit/telemetry/event.test.ts @@ -18,7 +18,7 @@ describe("buildSession", () => { extensionVersion: "1.2.3-test", machineId: "test-machine-id", sessionId: "test-session-id", - platformType: "Visual Studio Code", + platformName: "Visual Studio Code", platformVersion: "1.106.0-test", hostArch: process.arch, }); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index df00e72b52..4837f64c18 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -127,20 +127,45 @@ describe("TelemetryService", () => { error: { message: "boom" }, }); }); + + it("forwards caller measurements alongside the framework-set durationMs", async () => { + await h.service.time( + "auth.token_refresh", + () => Promise.resolve(), + {}, + { attempts: 2 }, + ); + + const [event] = h.sink.events; + expect(event.measurements.attempts).toBe(2); + expect(event.measurements.durationMs).toBeGreaterThanOrEqual(0); + }); + + it("emits with a fresh traceId so it maps to a single-span trace", async () => { + await h.service.time("a", () => Promise.resolve(1)); + await h.service.time("b", () => Promise.resolve(2)); + + const [a, b] = h.sink.events; + expect(a.traceId).toBeDefined(); + expect(b.traceId).toBeDefined(); + expect(a.traceId).not.toBe(b.traceId); + expect(a.parentEventId).toBeUndefined(); + expect(b.parentEventId).toBeUndefined(); + }); }); describe("trace", () => { it("parent and child phase events share one traceId on success", async () => { - const result = await h.service.trace("remote.setup", async (trace) => { - await trace.phase("workspace_lookup", () => Promise.resolve("ws")); - await trace.phase("ssh_config", () => Promise.resolve("cfg")); + const result = await h.service.trace("remote.setup", async (span) => { + await span.phase("workspace_lookup", () => Promise.resolve("ws")); + await span.phase("ssh_config", () => Promise.resolve("cfg")); return "done"; }); expect(result).toBe("done"); const [phase1, phase2, parent] = h.sink.events; - expect(phase1.eventName).toBe("remote.setup.phase"); - expect(phase2.eventName).toBe("remote.setup.phase"); + expect(phase1.eventName).toBe("remote.setup.workspace_lookup"); + expect(phase2.eventName).toBe("remote.setup.ssh_config"); expect(parent).toMatchObject({ eventName: "remote.setup", properties: { result: "success" }, @@ -150,27 +175,113 @@ describe("TelemetryService", () => { expect(phase2.traceId).toBe(parent.traceId); }); + it("phase children carry parentEventId pointing at the parent's eventId; logs do not", async () => { + h.service.log("plain"); + await h.service.trace("op", async (span) => { + await span.phase("p1", () => Promise.resolve()); + await span.phase("p2", () => Promise.resolve()); + }); + + const [plain, p1, p2, parent] = h.sink.events; + // log/logError/time events have no parentEventId field. + expect(plain.parentEventId).toBeUndefined(); + // Parent (root) has no parentEventId either. + expect(parent.parentEventId).toBeUndefined(); + // Phase children point at the parent's eventId. + expect(p1.parentEventId).toBe(parent.eventId); + expect(p2.parentEventId).toBe(parent.eventId); + // All eventIds are still globally unique. + expect( + new Set([plain.eventId, p1.eventId, p2.eventId, parent.eventId]).size, + ).toBe(4); + }); + + it("phase eventName composes as '.' and records durationMs", async () => { + await h.service.trace("remote.setup", async (span) => { + await span.phase("workspace_lookup", () => Promise.resolve("ws")); + }); + + const [phase] = h.sink.events; + expect(phase.eventName).toBe("remote.setup.workspace_lookup"); + expect(phase.measurements.durationMs).toBeGreaterThanOrEqual(0); + }); + + it("supports grandchildren via the child span's phase method", async () => { + await h.service.trace("remote.setup", async (span) => { + await span.phase("workspace_lookup", async (childSpan) => { + await childSpan.phase("dns_resolve", () => Promise.resolve()); + }); + }); + + const [grandchild, child, parent] = h.sink.events; + expect(parent.eventName).toBe("remote.setup"); + expect(child.eventName).toBe("remote.setup.workspace_lookup"); + expect(grandchild.eventName).toBe( + "remote.setup.workspace_lookup.dns_resolve", + ); + // All three share one traceId. + expect(child.traceId).toBe(parent.traceId); + expect(grandchild.traceId).toBe(parent.traceId); + // Hierarchy via parentEventId. + expect(parent.parentEventId).toBeUndefined(); + expect(child.parentEventId).toBe(parent.eventId); + expect(grandchild.parentEventId).toBe(child.eventId); + }); + + it("phase forwards caller properties unchanged except for the framework-set result", async () => { + await h.service.trace("op", async (span) => { + await span.phase("p", () => Promise.resolve(0), { extra: "yes" }); + }); + + const [phase] = h.sink.events; + expect(phase.properties).toEqual({ + extra: "yes", + result: "success", + }); + }); + + it("phase emits error event with cause and rethrows on failure", async () => { + const boom = new Error("nope"); + await expect( + h.service.trace("op", async (span) => { + await span.phase("p", () => Promise.reject(boom)); + }), + ).rejects.toBe(boom); + + const [phase] = h.sink.events; + expect(phase).toMatchObject({ + eventName: "op.p", + properties: { result: "error" }, + error: { message: "nope" }, + }); + }); + + it("phase with a name containing '.' is sanitized and the call succeeds", async () => { + await h.service.trace("op", async (span) => { + await span.phase("bad.name", () => Promise.resolve()); + }); + + const [phase] = h.sink.events; + expect(phase.eventName).toBe("op.bad_name"); + }); + 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"); await expect( - h.service.trace("remote.setup", async (trace) => { - await trace.phase("ok_phase", () => Promise.resolve("ok")); - await trace.phase("bad_phase", () => Promise.reject(boom)); - await trace.phase("never_runs", () => Promise.resolve("x")); + h.service.trace("remote.setup", async (span) => { + await span.phase("ok_phase", () => Promise.resolve("ok")); + await span.phase("bad_phase", () => Promise.reject(boom)); + await span.phase("never_runs", () => Promise.resolve("x")); }), ).rejects.toBe(boom); expect(h.sink.events).toHaveLength(3); const [okPhase, badPhase, parent] = h.sink.events; - expect(okPhase.properties).toMatchObject({ - phase: "ok_phase", - result: "success", - }); - expect(badPhase.properties).toMatchObject({ - phase: "bad_phase", - result: "error", - }); + expect(okPhase.eventName).toBe("remote.setup.ok_phase"); + expect(okPhase.properties).toMatchObject({ result: "success" }); + expect(badPhase.eventName).toBe("remote.setup.bad_phase"); + expect(badPhase.properties).toMatchObject({ result: "error" }); expect(parent).toMatchObject({ eventName: "remote.setup", properties: { result: "error" }, @@ -198,10 +309,10 @@ describe("TelemetryService", () => { }); it("captures the URL as of the moment each event in a trace is emitted", async () => { - await h.service.trace("op", async (trace) => { - await trace.phase("first", () => Promise.resolve("")); + await h.service.trace("op", async (span) => { + await span.phase("first", () => Promise.resolve("")); h.service.setDeploymentUrl("https://coder.example.com"); - await trace.phase("second", () => Promise.resolve("")); + await span.phase("second", () => Promise.resolve("")); }); const [first, second, parent] = h.sink.events; @@ -222,8 +333,8 @@ describe("TelemetryService", () => { expect(await h.service.time("c", () => Promise.resolve(42))).toBe(42); - const traceResult = await h.service.trace("d", async (trace) => { - const phaseValue = await trace.phase("p", () => + const traceResult = await h.service.trace("d", async (span) => { + const phaseValue = await span.phase("p", () => Promise.resolve("inner"), ); expect(phaseValue).toBe("inner"); @@ -252,6 +363,7 @@ describe("TelemetryService", () => { }); it("treats unknown values (e.g. future deployment) as local", () => { + h = makeHarness("off"); h.config.set("coder.telemetry.level", "deployment"); h.service.log("evt"); expect(h.sink.events).toHaveLength(1); @@ -277,6 +389,53 @@ describe("TelemetryService", () => { }); }); + describe("errors never propagate to the caller", () => { + const throwingSink: TelemetrySink = { + name: "throws", + minLevel: "local", + write: () => { + throw new Error("sink write failed"); + }, + flush: () => Promise.resolve(), + dispose: () => Promise.resolve(), + }; + + it("log/logError do not throw when the only sink throws", () => { + const service = makeService([throwingSink]); + expect(() => service.log("a")).not.toThrow(); + expect(() => + service.logError("b", new Error("user-error")), + ).not.toThrow(); + }); + + it("time returns the user fn's value when the sink throws", async () => { + const service = makeService([throwingSink]); + await expect(service.time("op", () => Promise.resolve(42))).resolves.toBe( + 42, + ); + }); + + it("time rethrows the user fn's error (not any telemetry error)", async () => { + const service = makeService([throwingSink]); + const userErr = new Error("user-error"); + await expect( + service.time("op", () => Promise.reject(userErr)), + ).rejects.toBe(userErr); + }); + + it("trace and span.phase complete normally when the sink throws", async () => { + const service = makeService([throwingSink]); + const result = await service.trace("op", async (span) => { + const phaseValue = await span.phase("p", () => + Promise.resolve("phase"), + ); + expect(phaseValue).toBe("phase"); + return "trace"; + }); + expect(result).toBe("trace"); + }); + }); + describe("dispose", () => { it("flushes and disposes every sink", async () => { await h.service.dispose(); diff --git a/test/unit/telemetry/trace.test.ts b/test/unit/telemetry/trace.test.ts deleted file mode 100644 index 5322841fd6..0000000000 --- a/test/unit/telemetry/trace.test.ts +++ /dev/null @@ -1,79 +0,0 @@ -import { describe, expect, it } from "vitest"; - -import { Trace } from "@/telemetry/trace"; - -import type { EmitFn } from "@/telemetry/emit"; - -interface RecordedCall { - eventName: string; - properties: Record; - measurements: Record; - traceId?: string; - error?: unknown; -} - -function makeRecorder(): { emit: EmitFn; calls: RecordedCall[] } { - const calls: RecordedCall[] = []; - const emit: EmitFn = ( - eventName, - properties, - measurements, - traceId, - error, - ) => { - calls.push({ eventName, properties, measurements, traceId, error }); - }; - return { emit, calls }; -} - -describe("Trace.phase", () => { - it("emits a child '.phase' event with the parent's traceId on success", async () => { - const { emit, calls } = makeRecorder(); - const trace = new Trace("remote.setup", "trace-1", emit); - - const result = await trace.phase("workspace_lookup", () => - Promise.resolve("ws"), - ); - - expect(result).toBe("ws"); - expect(calls).toHaveLength(1); - expect(calls[0]).toMatchObject({ - eventName: "remote.setup.phase", - properties: { phase: "workspace_lookup", result: "success" }, - traceId: "trace-1", - error: undefined, - }); - expect(calls[0].measurements.durationMs).toBeGreaterThanOrEqual(0); - }); - - it("merges caller properties without overwriting phase or result", async () => { - const { emit, calls } = makeRecorder(); - const trace = new Trace("op", "tid", emit); - - await trace.phase("p", () => Promise.resolve(0), { extra: "yes" }); - - expect(calls[0].properties).toEqual({ - extra: "yes", - phase: "p", - result: "success", - }); - }); - - it("emits an error event and rethrows when the wrapped fn rejects", async () => { - const { emit, calls } = makeRecorder(); - const trace = new Trace("op", "tid", emit); - const boom = new Error("nope"); - - await expect(trace.phase("p", () => Promise.reject(boom))).rejects.toBe( - boom, - ); - - expect(calls).toHaveLength(1); - expect(calls[0]).toMatchObject({ - eventName: "op.phase", - properties: { phase: "p", result: "error" }, - traceId: "tid", - error: boom, - }); - }); -}); From 81ee22f0fa315c44fcf3eece50f3a67951e0d40d Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 4 May 2026 13:49:29 +0300 Subject: [PATCH 6/8] refactor(telemetry): hide setting, drop time() alias Remove coder.telemetry.level from package.json until a sink ships. The service still reads it internally and defaults to local. Drop time() since it just delegated to trace() with a mismatched signature. --- package.json | 16 --------------- src/telemetry/service.ts | 27 +++++++----------------- test/unit/telemetry/service.test.ts | 32 ++++++++++++++--------------- 3 files changed, 22 insertions(+), 53 deletions(-) diff --git a/package.json b/package.json index b3193f14c7..66e4c87e44 100644 --- a/package.json +++ b/package.json @@ -189,22 +189,6 @@ "Logs everything from *headers* plus request and response bodies (may include sensitive data)" ], "default": "basic" - }, - "coder.telemetry.level": { - "markdownDescription": "Controls Coder extension telemetry collection. Used to diagnose extension issues.", - "type": "string", - "enum": [ - "off", - "local" - ], - "markdownEnumDescriptions": [ - "Disable telemetry collection.", - "Record events on this machine only." - ], - "default": "local", - "tags": [ - "telemetry" - ] } } }, diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index 709e9dc6bf..708e536032 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -88,19 +88,10 @@ export class TelemetryService implements vscode.Disposable { }); } - /** Time `fn` and emit one event with `durationMs` and `result`. */ - public time( - eventName: string, - fn: () => Promise, - properties: Record = {}, - measurements: Record = {}, - ): Promise { - return this.trace(eventName, fn, properties, measurements); - } - /** - * Run a multi-phase operation. All events share a `traceId`; each non-root - * carries `parentEventId`. Framework sets `result` and `durationMs`. + * Run a timed operation. The emitted event carries `durationMs` and a + * `result` of `success` or `error`. All events from one call share a + * `traceId`; phase children carry `parentEventId`. */ public trace( eventName: string, @@ -284,14 +275,10 @@ export class TelemetryService implements vscode.Disposable { } function readLevel(): TelemetryLevel { - switch ( - vscode.workspace.getConfiguration().get(TELEMETRY_LEVEL_SETTING) - ) { - case "off": - return "off"; - default: - return "local"; - } + const value = vscode.workspace + .getConfiguration() + .get(TELEMETRY_LEVEL_SETTING); + return isTelemetryLevel(value) ? value : "local"; } function isTelemetryLevel(value: unknown): value is TelemetryLevel { diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index 4837f64c18..8d3647e365 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -96,10 +96,10 @@ describe("TelemetryService", () => { }); }); - describe("time", () => { + describe("trace", () => { it("returns the wrapped value and records durationMs on success", async () => { vi.useFakeTimers(); - const promise = h.service.time( + const promise = h.service.trace( "activation", async () => { await new Promise((r) => setTimeout(r, 250)); @@ -119,7 +119,7 @@ describe("TelemetryService", () => { it("emits an error event with the cause and rethrows on failure", async () => { const err = new Error("boom"); await expect( - h.service.time("activation", () => Promise.reject(err)), + h.service.trace("activation", () => Promise.reject(err)), ).rejects.toBe(err); expect(h.sink.events[0]).toMatchObject({ @@ -129,7 +129,7 @@ describe("TelemetryService", () => { }); it("forwards caller measurements alongside the framework-set durationMs", async () => { - await h.service.time( + await h.service.trace( "auth.token_refresh", () => Promise.resolve(), {}, @@ -141,9 +141,9 @@ describe("TelemetryService", () => { expect(event.measurements.durationMs).toBeGreaterThanOrEqual(0); }); - it("emits with a fresh traceId so it maps to a single-span trace", async () => { - await h.service.time("a", () => Promise.resolve(1)); - await h.service.time("b", () => Promise.resolve(2)); + 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)); const [a, b] = h.sink.events; expect(a.traceId).toBeDefined(); @@ -152,9 +152,7 @@ describe("TelemetryService", () => { expect(a.parentEventId).toBeUndefined(); expect(b.parentEventId).toBeUndefined(); }); - }); - describe("trace", () => { it("parent and child phase events share one traceId on success", async () => { const result = await h.service.trace("remote.setup", async (span) => { await span.phase("workspace_lookup", () => Promise.resolve("ws")); @@ -327,11 +325,11 @@ describe("TelemetryService", () => { h = makeHarness("off"); }); - it("suppresses emissions but still runs wrapped functions of time and trace", async () => { + it("suppresses emissions but still runs wrapped fns for trace", async () => { h.service.log("a"); h.service.logError("b", new Error("ignored")); - expect(await h.service.time("c", () => Promise.resolve(42))).toBe(42); + expect(await h.service.trace("c", () => Promise.resolve(42))).toBe(42); const traceResult = await h.service.trace("d", async (span) => { const phaseValue = await span.phase("p", () => @@ -408,18 +406,18 @@ describe("TelemetryService", () => { ).not.toThrow(); }); - it("time returns the user fn's value when the sink throws", async () => { + it("trace returns the user fn's value when the sink throws", async () => { const service = makeService([throwingSink]); - await expect(service.time("op", () => Promise.resolve(42))).resolves.toBe( - 42, - ); + await expect( + service.trace("op", () => Promise.resolve(42)), + ).resolves.toBe(42); }); - it("time rethrows the user fn's error (not any telemetry error)", async () => { + it("trace rethrows the user fn's error (not any telemetry error)", async () => { const service = makeService([throwingSink]); const userErr = new Error("user-error"); await expect( - service.time("op", () => Promise.reject(userErr)), + service.trace("op", () => Promise.reject(userErr)), ).rejects.toBe(userErr); }); From 5b9184b1d71f1502c8b773f09e5bab24b58da82b Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 4 May 2026 14:33:43 +0300 Subject: [PATCH 7/8] refactor(telemetry): reserve framework keys, await dispose Reserve result and durationMs as framework-managed keys so callers cannot pass them and have them silently overwritten. ServiceContainer.dispose() is async and awaits telemetry teardown so the logger survives any sink flush warnings. --- src/core/container.ts | 15 +++++++-------- src/telemetry/event.ts | 8 ++++++++ src/telemetry/service.ts | 14 ++++++++------ src/telemetry/span.ts | 6 ++++-- test/unit/telemetry/service.test.ts | 6 +++--- 5 files changed, 30 insertions(+), 19 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index 7506502fe8..8593460521 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -141,15 +141,14 @@ export class ServiceContainer implements vscode.Disposable { return this.telemetryService; } - /** - * Dispose of all services and clean up resources. - */ - dispose(): void { + /** Dispose logger last so telemetry teardown warnings still reach it. */ + async dispose(): Promise { this.contextManager.dispose(); this.loginCoordinator.dispose(); - // Fire-and-forget: VS Code does not await deactivation. - void this.telemetryService.dispose(); - // Logger last so telemetry teardown can still log warnings. - this.logger.dispose(); + try { + await this.telemetryService.dispose(); + } finally { + this.logger.dispose(); + } } } diff --git a/src/telemetry/event.ts b/src/telemetry/event.ts index 8f90ee23be..068b6c0148 100644 --- a/src/telemetry/event.ts +++ b/src/telemetry/event.ts @@ -6,6 +6,14 @@ import { toError } from "../error/errorUtils"; /** Telemetry level, mirrors `coder.telemetry.level`. Ordered: off < local. */ export type TelemetryLevel = "off" | "local"; +/** Caller properties. `result` is framework-managed on traced events. */ +export type CallerProperties = Record & { result?: never }; + +/** Caller measurements. `durationMs` is framework-managed on traced events. */ +export type CallerMeasurements = Record & { + durationMs?: never; +}; + /** Session-stable resource attributes. Field names are inspired by OTel * resource attributes; they are camelCase TypeScript and not a 1:1 mapping. */ export interface SessionContext { diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index 708e536032..4b843b97fa 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -6,6 +6,8 @@ import { type Logger } from "../logging/logger"; import { buildSession, buildErrorBlock, + type CallerMeasurements, + type CallerProperties, type SessionContext, type TelemetryEvent, type TelemetryLevel, @@ -65,8 +67,8 @@ export class TelemetryService implements vscode.Disposable { public log( eventName: string, - properties: Record = {}, - measurements: Record = {}, + properties: CallerProperties = {}, + measurements: CallerMeasurements = {}, ): void { if (this.#level === "off") { return; @@ -77,8 +79,8 @@ export class TelemetryService implements vscode.Disposable { public logError( eventName: string, error: unknown, - properties: Record = {}, - measurements: Record = {}, + properties: CallerProperties = {}, + measurements: CallerMeasurements = {}, ): void { if (this.#level === "off") { return; @@ -96,8 +98,8 @@ export class TelemetryService implements vscode.Disposable { public trace( eventName: string, fn: (span: Span) => Promise, - properties: Record = {}, - measurements: Record = {}, + properties: CallerProperties = {}, + measurements: CallerMeasurements = {}, ): Promise { if (this.#level === "off") { return fn(NOOP_SPAN); diff --git a/src/telemetry/span.ts b/src/telemetry/span.ts index 898bcdf84c..a802891469 100644 --- a/src/telemetry/span.ts +++ b/src/telemetry/span.ts @@ -1,3 +1,5 @@ +import { type CallerProperties } from "./event"; + /** * Parent span handle. Children's `eventName` composes as `${parent.eventName}.${phaseName}`; * phase names must not contain `.`. Recurse via `phase` for grandchildren. @@ -10,7 +12,7 @@ export interface Span { phase( phaseName: string, fn: (span: Span) => Promise, - properties?: Record, + properties?: CallerProperties, measurements?: Record, ): Promise; } @@ -23,7 +25,7 @@ export const NOOP_SPAN: Span = { phase( _phaseName: string, fn: (span: Span) => Promise, - _properties?: Record, + _properties?: CallerProperties, _measurements?: Record, ): Promise { return fn(this); diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index 8d3647e365..cc2ba5593d 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -52,14 +52,14 @@ describe("TelemetryService", () => { describe("log", () => { it("emits an event with auto-injected context, properties, and measurements", () => { - h.service.log("activation", { result: "success" }, { durationMs: 12 }); + h.service.log("activation", { outcome: "success" }, { latencyMs: 12 }); const [event] = h.sink.events; expect(event).toMatchObject({ eventName: "activation", eventSequence: 0, - properties: { result: "success" }, - measurements: { durationMs: 12 }, + properties: { outcome: "success" }, + measurements: { latencyMs: 12 }, context: { extensionVersion: "1.2.3-test", machineId: "test-machine-id", From 91007732d5e9f3d27e081c55ae7dce3e41e000ad Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 4 May 2026 14:45:57 +0300 Subject: [PATCH 8/8] fix(telemetry): freeze trace level, harden NOOP_SPAN, share span options - NOOP_SPAN.phase now passes NOOP_SPAN explicitly so detaching the method cannot strip the receiver - Trace level is captured at trace start and threaded through SpanOptions so a mid-trace level toggle no longer drops phases or the parent and leaves dangling parentEventId references - Pull a SpanOptions type out of EmitOptions so #startSpan and #emitTimed share the trace-context shape - Soften the phase-name docstring to match the sanitize-with-warning behavior --- src/telemetry/service.ts | 38 +++++++++++++++-------------- src/telemetry/span.ts | 7 +++--- test/unit/telemetry/service.test.ts | 20 +++++++++++++++ 3 files changed, 44 insertions(+), 21 deletions(-) diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index 4b843b97fa..78803668fb 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -22,9 +22,15 @@ const LEVEL_ORDER: Readonly> = { local: 1, }; -interface EmitOptions { - traceId?: string; +/** Trace context shared by all events in one trace. */ +interface SpanOptions { + traceId: string; parentEventId?: string; + /** Level frozen at trace start so a mid-trace toggle does not orphan events. */ + traceLevel: TelemetryLevel; +} + +interface EmitOptions extends Partial { error?: unknown; } @@ -104,13 +110,10 @@ export class TelemetryService implements vscode.Disposable { if (this.#level === "off") { return fn(NOOP_SPAN); } - return this.#startSpan( - crypto.randomUUID(), - eventName, - fn, - properties, - measurements, - ); + return this.#startSpan(eventName, fn, properties, measurements, { + traceId: crypto.randomUUID(), + traceLevel: this.#level, + }); } public async dispose(): Promise { @@ -124,14 +127,14 @@ export class TelemetryService implements vscode.Disposable { } #startSpan( - traceId: string, eventName: string, fn: (span: Span) => Promise, properties: Record, measurements: Record, - parentEventId?: string, + spanOpts: SpanOptions, ): Promise { const eventId = crypto.randomUUID(); + const { traceId, traceLevel } = spanOpts; const span: Span = { traceId, eventId, @@ -144,12 +147,11 @@ export class TelemetryService implements vscode.Disposable { ): Promise => { const safeName = this.#sanitizePhaseName(phaseName); return this.#startSpan( - traceId, `${eventName}.${safeName}`, phaseFn, phaseProps, phaseMeasurements, - eventId, + { traceId, parentEventId: eventId, traceLevel }, ); }, }; @@ -159,7 +161,7 @@ export class TelemetryService implements vscode.Disposable { () => fn(span), properties, measurements, - { traceId, parentEventId }, + spanOpts, ); } @@ -180,7 +182,7 @@ export class TelemetryService implements vscode.Disposable { fn: () => Promise, properties: Record, measurements: Record, - options: Omit = {}, + spanOpts: SpanOptions, ): Promise { const start = performance.now(); const send = (result: "success" | "error", error?: unknown): void => @@ -189,7 +191,7 @@ export class TelemetryService implements vscode.Disposable { eventName, { ...properties, result }, { ...measurements, durationMs: performance.now() - start }, - { ...options, error }, + { ...spanOpts, error }, ); try { const value = await fn(); @@ -223,7 +225,7 @@ export class TelemetryService implements vscode.Disposable { measurements: Record, options: EmitOptions = {}, ): void { - const { traceId, parentEventId, error } = options; + const { traceId, parentEventId, error, traceLevel } = options; const event: TelemetryEvent = { eventId, eventName, @@ -237,7 +239,7 @@ export class TelemetryService implements vscode.Disposable { ...(error !== undefined && { error: buildErrorBlock(error) }), }; - const currentOrder = LEVEL_ORDER[this.#level]; + const currentOrder = LEVEL_ORDER[traceLevel ?? this.#level]; for (const sink of this.sinks) { if (currentOrder < LEVEL_ORDER[sink.minLevel]) { continue; diff --git a/src/telemetry/span.ts b/src/telemetry/span.ts index a802891469..626c4bb450 100644 --- a/src/telemetry/span.ts +++ b/src/telemetry/span.ts @@ -1,8 +1,9 @@ import { type CallerProperties } from "./event"; /** - * Parent span handle. Children's `eventName` composes as `${parent.eventName}.${phaseName}`; - * phase names must not contain `.`. Recurse via `phase` for grandchildren. + * Parent span handle. Children's `eventName` composes as `${parent.eventName}.${phaseName}`. + * Phase names should not contain `.`; if they do, dots are replaced with `_` and a warning is logged. + * Recurse via `phase` for grandchildren. */ export interface Span { readonly traceId: string; @@ -28,6 +29,6 @@ export const NOOP_SPAN: Span = { _properties?: CallerProperties, _measurements?: Record, ): Promise { - return fn(this); + return fn(NOOP_SPAN); }, }; diff --git a/test/unit/telemetry/service.test.ts b/test/unit/telemetry/service.test.ts index cc2ba5593d..8bcafae25f 100644 --- a/test/unit/telemetry/service.test.ts +++ b/test/unit/telemetry/service.test.ts @@ -360,6 +360,26 @@ describe("TelemetryService", () => { expect(h.sink.events).toHaveLength(2); }); + it("a mid-trace level → off does not orphan child phases or drop the parent", async () => { + let toggled = false; + await h.service.trace("op", async (span) => { + await span.phase("p1", () => Promise.resolve()); + if (!toggled) { + h.config.set("coder.telemetry.level", "off"); + toggled = true; + } + await span.phase("p2", () => Promise.resolve()); + }); + + expect(h.sink.events).toHaveLength(3); + const [p1, p2, parent] = h.sink.events; + expect(p1.eventName).toBe("op.p1"); + expect(p2.eventName).toBe("op.p2"); + expect(parent.eventName).toBe("op"); + expect(p1.traceId).toBe(parent.traceId); + expect(p2.traceId).toBe(parent.traceId); + }); + it("treats unknown values (e.g. future deployment) as local", () => { h = makeHarness("off"); h.config.set("coder.telemetry.level", "deployment");