From 71eafd5df6e6bb8b46e34b61d0d6ac56de044ad4 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Fri, 8 May 2026 13:55:55 +0000 Subject: [PATCH 1/5] feat(telemetry): roll up http requests --- CHANGELOG.md | 2 + package.json | 23 +- src/api/coderApi.ts | 36 +- src/extension.ts | 2 + src/logging/httpRequestsTelemetry.ts | 325 ++++++++++++++++++ src/remote/remote.ts | 7 +- src/settings/telemetry.ts | 52 ++- src/telemetry/reporter.ts | 29 ++ src/telemetry/service.ts | 4 +- test/unit/api/coderApi.test.ts | 41 ++- .../logging/httpRequestsTelemetry.test.ts | 169 +++++++++ test/unit/settings/telemetry.test.ts | 53 +++ 12 files changed, 725 insertions(+), 18 deletions(-) create mode 100644 src/logging/httpRequestsTelemetry.ts create mode 100644 src/telemetry/reporter.ts create mode 100644 test/unit/logging/httpRequestsTelemetry.test.ts diff --git a/CHANGELOG.md b/CHANGELOG.md index 32e8e137..80ee1b0f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -21,6 +21,8 @@ binary download/verify now emit local telemetry events with their duration and outcome, so startup latency and failures are captured alongside other local telemetry. +- Local telemetry now records aggregated `http.requests` rollups for per-route + HTTP health without emitting one event per request. ### Fixed diff --git a/package.json b/package.json index 1066eb9e..f34502ef 100644 --- a/package.json +++ b/package.json @@ -211,7 +211,7 @@ ] }, "coder.telemetry.local": { - "markdownDescription": "Tunables for the local telemetry sink, which writes events as JSON Lines under the extension's global storage. Used when `#coder.telemetry.level#` is `local`. Missing or invalid fields fall back to defaults.", + "markdownDescription": "Advanced tunables for local telemetry collection. The local sink writes events as JSON Lines under the extension's global storage. Used when `#coder.telemetry.level#` is `local`. Missing or invalid fields fall back to defaults.", "type": "object", "additionalProperties": false, "properties": { @@ -250,6 +250,22 @@ "minimum": 4096, "default": 104857600, "markdownDescription": "Cap, in bytes, on the combined size of telemetry files. Oldest files are deleted on activation until the total is under the cap." + }, + "httpRequests": { + "type": "object", + "additionalProperties": false, + "markdownDescription": "Tunables for HTTP request rollup telemetry.", + "properties": { + "windowSeconds": { + "type": "number", + "minimum": 1, + "default": 60, + "markdownDescription": "Tumbling window length, in seconds, for aggregated `http.requests` events." + } + }, + "default": { + "windowSeconds": 60 + } } }, "default": { @@ -258,7 +274,10 @@ "bufferLimit": 500, "maxFileBytes": 5242880, "maxAgeDays": 30, - "maxTotalBytes": 104857600 + "maxTotalBytes": 104857600, + "httpRequests": { + "windowSeconds": 60 + } }, "tags": [ "telemetry" diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index 57e27117..3397f10f 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -29,6 +29,7 @@ import { logError, logResponse, } from "../logging/httpLogger"; +import { HttpRequestsTelemetry } from "../logging/httpRequestsTelemetry"; import { type Logger } from "../logging/logger"; import { type RequestConfigWithMeta, @@ -36,6 +37,7 @@ import { } from "../logging/types"; import { sizeOf } from "../logging/utils"; import { getHeaderCommand } from "../settings/headers"; +import { type TelemetryReporter } from "../telemetry/reporter"; import { HttpStatusCode, WebSocketCloseCode } from "../websocket/codes"; import { type UnidirectionalStream, @@ -86,7 +88,10 @@ export class CoderApi extends Api implements vscode.Disposable { >(); private readonly configWatcher: vscode.Disposable; - private constructor(private readonly output: Logger) { + private constructor( + private readonly output: Logger, + private readonly httpRequestsTelemetry?: HttpRequestsTelemetry, + ) { super(); this.configWatcher = this.watchConfigChanges(); } @@ -99,11 +104,15 @@ export class CoderApi extends Api implements vscode.Disposable { baseUrl: string, token: string | undefined, output: Logger, + telemetry?: TelemetryReporter, ): CoderApi { - const client = new CoderApi(output); + const httpRequestsTelemetry = telemetry + ? HttpRequestsTelemetry.start(telemetry) + : undefined; + const client = new CoderApi(output, httpRequestsTelemetry); client.setCredentials(baseUrl, token); - setupInterceptors(client, output); + setupInterceptors(client, output, httpRequestsTelemetry); return client; } @@ -155,6 +164,7 @@ export class CoderApi extends Api implements vscode.Disposable { */ dispose(): void { this.configWatcher.dispose(); + this.httpRequestsTelemetry?.dispose(); for (const socket of this.reconnectingSockets) { socket.close(); } @@ -473,8 +483,16 @@ export class CoderApi extends Api implements vscode.Disposable { /** * Set up logging and request interceptors for the CoderApi instance. */ -function setupInterceptors(client: CoderApi, output: Logger): void { - addLoggingInterceptors(client.getAxiosInstance(), output); +function setupInterceptors( + client: CoderApi, + output: Logger, + httpRequestsTelemetry: HttpRequestsTelemetry | undefined, +): void { + addLoggingInterceptors( + client.getAxiosInstance(), + output, + httpRequestsTelemetry, + ); client.getAxiosInstance().interceptors.request.use(async (config) => { const baseUrl = client.getAxiosInstance().defaults.baseURL; @@ -522,7 +540,11 @@ function setupInterceptors(client: CoderApi, output: Logger): void { ); } -function addLoggingInterceptors(client: AxiosInstance, logger: Logger) { +function addLoggingInterceptors( + client: AxiosInstance, + logger: Logger, + httpRequestsTelemetry: HttpRequestsTelemetry | undefined, +) { client.interceptors.request.use( (config) => { const configWithMeta = config as RequestConfigWithMeta; @@ -555,10 +577,12 @@ function addLoggingInterceptors(client: AxiosInstance, logger: Logger) { client.interceptors.response.use( (response) => { + httpRequestsTelemetry?.recordResponse(response); logResponse(logger, response, getLogLevel()); return response; }, (error: unknown) => { + httpRequestsTelemetry?.recordError(error); logError(logger, error, getLogLevel()); throw error; }, diff --git a/src/extension.ts b/src/extension.ts index cf310bce..3067014c 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -84,6 +84,7 @@ async function doActivate( const secretsManager = serviceContainer.getSecretsManager(); const contextManager = serviceContainer.getContextManager(); const commandManager = serviceContainer.getCommandManager(); + const telemetryService = serviceContainer.getTelemetryService(); // Migrate auth storage from old flat format to new label-based format await migrateAuthStorage(serviceContainer); @@ -137,6 +138,7 @@ async function doActivate( deployment?.url || "", deploymentSessionAuth?.token, output, + telemetryService, ); ctx.subscriptions.push(client); diff --git a/src/logging/httpRequestsTelemetry.ts b/src/logging/httpRequestsTelemetry.ts new file mode 100644 index 00000000..7c19609a --- /dev/null +++ b/src/logging/httpRequestsTelemetry.ts @@ -0,0 +1,325 @@ +import { isAxiosError, type AxiosResponse } from "axios"; +import * as vscode from "vscode"; + +import { watchConfigurationChanges } from "../configWatcher"; +import { + LOCAL_TELEMETRY_SETTING, + readHttpRequestsTelemetryConfig, + type HttpRequestsTelemetryConfig, +} from "../settings/telemetry"; +import { type TelemetryReporter } from "../telemetry/reporter"; + +import { formatMethod } from "./formatters"; + +import type { RequestConfigWithMeta } from "./types"; + +const EVENT_NAME = "http.requests"; +const UNKNOWN_ROUTE = ""; + +interface RouteNormalizationRule { + readonly pattern: RegExp; + readonly replacement: string; +} + +const ID_RESOURCES = [ + "aibridge/sessions", + "files", + "groups", + "licenses", + "oauth2-provider/apps", + "templates", + "templateversions", + "workspaceagents", + "workspacebuilds", + "workspaces", +] as const; + +export const ROUTE_NORMALIZATION_RULES: readonly RouteNormalizationRule[] = [ + { + pattern: /^(\/api\/v2\/users\/)[^/]+(\/workspace\/)[^/]+(?=$|\/)/, + replacement: "$1{name}$2{name}", + }, + { + pattern: /^(\/api\/v2\/users\/)[^/]+(?=$|\/)/, + replacement: "$1{name}", + }, + { + pattern: /^(\/api\/v2\/tasks\/)[^/]+(?=$|\/)/, + replacement: "$1{name}", + }, + { + pattern: + /^(\/api\/v2\/organizations\/)[^/]+(\/templates\/)[^/]+(\/versions\/)[^/]+(?=$|\/)/, + replacement: "$1{id}$2{name}$3{name}", + }, + { + pattern: /^(\/api\/v2\/organizations\/)[^/]+(\/templates\/)[^/]+(?=$|\/)/, + replacement: "$1{id}$2{name}", + }, + { + pattern: /^(\/api\/v2\/organizations\/)[^/]+(\/groups\/)[^/]+(?=$|\/)/, + replacement: "$1{id}$2{name}", + }, + { + pattern: /^(\/api\/v2\/organizations\/)[^/]+(?=$|\/)/, + replacement: "$1{id}", + }, + ...ID_RESOURCES.map((resource) => ({ + pattern: new RegExp(`^(\\/api\\/v2\\/${resource}\\/)[^/]+(?=$|\\/)`), + replacement: "$1{id}", + })), +]; + +const UUID_SEGMENT = + /\/[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}(?=$|\/)/gi; +const NUMERIC_SEGMENT = /\/\d+(?=$|\/)/g; + +export interface HttpRequestTelemetrySample { + readonly method?: string; + readonly url?: string; + readonly baseURL?: string; + readonly statusCode?: number; + readonly networkError?: boolean; + readonly durationMs?: number; +} + +interface HttpRequestBucket { + count2xx: number; + count3xx: number; + count4xx: number; + count5xx: number; + countNetworkError: number; + durationsMs: number[]; +} + +export class HttpRequestsTelemetry implements vscode.Disposable { + readonly #telemetry: TelemetryReporter; + #config: HttpRequestsTelemetryConfig; + #timer: NodeJS.Timeout | null = null; + #configWatcher: vscode.Disposable | null = null; + #disposed = false; + readonly #buckets = new Map(); + + private constructor( + telemetry: TelemetryReporter, + config: HttpRequestsTelemetryConfig, + ) { + this.#telemetry = telemetry; + this.#config = config; + } + + public static start(telemetry: TelemetryReporter): HttpRequestsTelemetry { + const rollup = new HttpRequestsTelemetry( + telemetry, + readHttpRequestsTelemetryConfig(vscode.workspace.getConfiguration()), + ); + rollup.#configWatcher = rollup.#watchConfig(); + rollup.#scheduleNextWindow(); + return rollup; + } + + public recordResponse(response: AxiosResponse): void { + this.record({ + method: response.config.method, + url: response.config.url, + baseURL: response.config.baseURL, + statusCode: response.status, + durationMs: durationFromConfig(response.config), + }); + } + + public recordError(error: unknown): void { + if (!isAxiosError(error)) { + return; + } + + const config = error.config as RequestConfigWithMeta | undefined; + if (!config) { + return; + } + + this.record({ + method: config.method, + url: config.url, + baseURL: config.baseURL, + statusCode: error.response?.status, + networkError: !error.response, + durationMs: durationFromConfig(config), + }); + } + + public record(sample: HttpRequestTelemetrySample): void { + if (this.#disposed) { + return; + } + + const method = formatMethod(sample.method); + const route = normalizeHttpRoute(sample.url, sample.baseURL); + const key = bucketKey(method, route); + const bucket = this.#buckets.get(key) ?? createBucket(); + this.#buckets.set(key, bucket); + + const durationMs = sanitizeDuration(sample.durationMs); + bucket.durationsMs.push(durationMs); + + if (sample.networkError) { + bucket.countNetworkError += 1; + return; + } + + const statusCode = sample.statusCode; + if (statusCode === undefined) { + bucket.countNetworkError += 1; + return; + } + + if (statusCode >= 200 && statusCode < 300) { + bucket.count2xx += 1; + } else if (statusCode >= 300 && statusCode < 400) { + bucket.count3xx += 1; + } else if (statusCode >= 400 && statusCode < 500) { + bucket.count4xx += 1; + } else if (statusCode >= 500 && statusCode < 600) { + bucket.count5xx += 1; + } else { + bucket.countNetworkError += 1; + } + } + + public flush(): void { + const buckets = [...this.#buckets.entries()]; + this.#buckets.clear(); + for (const [key, bucket] of buckets) { + const { method, route } = parseBucketKey(key); + this.#telemetry.log( + EVENT_NAME, + { method, route }, + { + window_seconds: this.#config.windowSeconds, + count_2xx: bucket.count2xx, + count_3xx: bucket.count3xx, + count_4xx: bucket.count4xx, + count_5xx: bucket.count5xx, + count_network_error: bucket.countNetworkError, + avg_duration_ms: average(bucket.durationsMs), + p95_duration_ms: percentile95(bucket.durationsMs), + }, + ); + } + } + + public dispose(): void { + this.#disposed = true; + this.#configWatcher?.dispose(); + this.#configWatcher = null; + if (this.#timer) { + clearTimeout(this.#timer); + this.#timer = null; + } + this.#buckets.clear(); + } + + #watchConfig(): vscode.Disposable { + return watchConfigurationChanges( + [ + { + setting: LOCAL_TELEMETRY_SETTING, + getValue: () => + readHttpRequestsTelemetryConfig( + vscode.workspace.getConfiguration(), + ), + }, + ], + (changes) => { + const next = changes.get(LOCAL_TELEMETRY_SETTING) as + | HttpRequestsTelemetryConfig + | undefined; + if (!next) { + return; + } + this.flush(); + this.#config = next; + this.#scheduleNextWindow(); + }, + ); + } + + #scheduleNextWindow(): void { + if (this.#timer) { + clearTimeout(this.#timer); + this.#timer = null; + } + if (this.#disposed) { + return; + } + this.#timer = setTimeout(() => { + this.flush(); + this.#scheduleNextWindow(); + }, this.#config.windowSeconds * 1000); + } +} + +export function normalizeHttpRoute( + url: string | undefined, + baseURL?: string, +): string { + if (!url) { + return UNKNOWN_ROUTE; + } + + let route = parsePathname(url, baseURL); + for (const rule of ROUTE_NORMALIZATION_RULES) { + route = route.replace(rule.pattern, rule.replacement); + } + return route.replace(UUID_SEGMENT, "/{id}").replace(NUMERIC_SEGMENT, "/{id}"); +} + +function parsePathname(url: string, baseURL?: string): string { + try { + return new URL(url, baseURL ?? "http://coder.invalid").pathname; + } catch { + const withoutQuery = url.split("?", 1)[0] || UNKNOWN_ROUTE; + return withoutQuery.startsWith("/") ? withoutQuery : `/${withoutQuery}`; + } +} + +function durationFromConfig(config: RequestConfigWithMeta | undefined): number { + const startedAt = config?.metadata?.startedAt; + return typeof startedAt === "number" ? Date.now() - startedAt : 0; +} + +function sanitizeDuration(durationMs: number | undefined): number { + return typeof durationMs === "number" && Number.isFinite(durationMs) + ? Math.max(0, durationMs) + : 0; +} + +function createBucket(): HttpRequestBucket { + return { + count2xx: 0, + count3xx: 0, + count4xx: 0, + count5xx: 0, + countNetworkError: 0, + durationsMs: [], + }; +} + +function average(values: readonly number[]): number { + return values.reduce((sum, value) => sum + value, 0) / values.length; +} + +function percentile95(values: readonly number[]): number { + const sorted = [...values].sort((a, b) => a - b); + const index = Math.ceil(sorted.length * 0.95) - 1; + return sorted[Math.max(0, index)]; +} + +function bucketKey(method: string, route: string): string { + return `${method}\n${route}`; +} + +function parseBucketKey(key: string): { method: string; route: string } { + const [method, route] = key.split("\n", 2); + return { method, route }; +} diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 0a63973c..69fdd006 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -212,7 +212,12 @@ export class Remote { // break this connection. We could force close the remote session or // disallow logging out/in altogether, but for now just use a separate // client to remain unaffected by whatever the plugin is doing. - const workspaceClient = CoderApi.create(baseUrl, token, this.logger); + const workspaceClient = CoderApi.create( + baseUrl, + token, + this.logger, + this.serviceContainer.getTelemetryService(), + ); disposables.push(workspaceClient); // Create 401 interceptor - handles auth failures with re-login dialog diff --git a/src/settings/telemetry.ts b/src/settings/telemetry.ts index e082c615..08178641 100644 --- a/src/settings/telemetry.ts +++ b/src/settings/telemetry.ts @@ -3,7 +3,8 @@ import type { WorkspaceConfiguration } from "vscode"; import type { TelemetryLevel } from "../telemetry/event"; export const TELEMETRY_LEVEL_SETTING = "coder.telemetry.level"; -export const LOCAL_SINK_SETTING = "coder.telemetry.local"; +export const LOCAL_TELEMETRY_SETTING = "coder.telemetry.local"; +export const LOCAL_SINK_SETTING = LOCAL_TELEMETRY_SETTING; /** Telemetry level. Falls back to `local` for unknown or invalid values. */ export function readTelemetryLevel( @@ -22,6 +23,10 @@ export interface LocalSinkConfig { readonly maxTotalBytes: number; } +export interface HttpRequestsTelemetryConfig { + readonly windowSeconds: number; +} + export const LOCAL_SINK_DEFAULTS: LocalSinkConfig = { flushIntervalMs: 15_000, flushBatchSize: 100, @@ -31,6 +36,10 @@ export const LOCAL_SINK_DEFAULTS: LocalSinkConfig = { maxTotalBytes: 100 * 1024 * 1024, }; +export const HTTP_REQUESTS_TELEMETRY_DEFAULTS: HttpRequestsTelemetryConfig = { + windowSeconds: 60, +}; + // Defense in depth: VS Code does not enforce JSON schema at runtime, so users // can drop in any value via settings.json. Mirrors the minimums in package.json. const LOCAL_SINK_MINIMUMS: LocalSinkConfig = { @@ -42,15 +51,15 @@ const LOCAL_SINK_MINIMUMS: LocalSinkConfig = { maxTotalBytes: 4096, }; +const HTTP_REQUESTS_TELEMETRY_MINIMUMS: HttpRequestsTelemetryConfig = { + windowSeconds: 1, +}; + /** Per-field: missing, non-numeric, or below-minimum values fall back to defaults. */ export function readLocalSinkConfig( cfg: Pick, ): LocalSinkConfig { - const raw = cfg.get(LOCAL_SINK_SETTING); - const obj = - raw && typeof raw === "object" && !Array.isArray(raw) - ? (raw as Record) - : {}; + const obj = readLocalTelemetryObject(cfg); const read = (key: keyof LocalSinkConfig): number => { const value = obj[key]; return typeof value === "number" && value >= LOCAL_SINK_MINIMUMS[key] @@ -66,3 +75,34 @@ export function readLocalSinkConfig( maxTotalBytes: read("maxTotalBytes"), }; } + +export function readHttpRequestsTelemetryConfig( + cfg: Pick, +): HttpRequestsTelemetryConfig { + const obj = readLocalTelemetryObject(cfg); + const httpRequests = + obj.httpRequests && + typeof obj.httpRequests === "object" && + !Array.isArray(obj.httpRequests) + ? (obj.httpRequests as Record) + : {}; + const read = (key: keyof HttpRequestsTelemetryConfig): number => { + const value = httpRequests[key]; + return typeof value === "number" && + value >= HTTP_REQUESTS_TELEMETRY_MINIMUMS[key] + ? value + : HTTP_REQUESTS_TELEMETRY_DEFAULTS[key]; + }; + return { + windowSeconds: read("windowSeconds"), + }; +} + +function readLocalTelemetryObject( + cfg: Pick, +): Record { + const raw = cfg.get(LOCAL_TELEMETRY_SETTING); + return raw && typeof raw === "object" && !Array.isArray(raw) + ? (raw as Record) + : {}; +} diff --git a/src/telemetry/reporter.ts b/src/telemetry/reporter.ts new file mode 100644 index 00000000..e46811b4 --- /dev/null +++ b/src/telemetry/reporter.ts @@ -0,0 +1,29 @@ +import { NOOP_SPAN, type Span } from "./span"; + +import type { CallerMeasurements, CallerProperties } from "./event"; + +export interface TelemetryReporter { + log( + eventName: string, + properties?: CallerProperties, + measurements?: CallerMeasurements, + ): void; + logError( + eventName: string, + error: unknown, + properties?: CallerProperties, + measurements?: CallerMeasurements, + ): void; + trace( + eventName: string, + fn: (span: Span) => Promise, + properties?: CallerProperties, + measurements?: CallerMeasurements, + ): Promise; +} + +export const NOOP_TELEMETRY_REPORTER: TelemetryReporter = { + log: () => undefined, + logError: () => undefined, + trace: (_eventName, fn) => fn(NOOP_SPAN), +}; diff --git a/src/telemetry/service.ts b/src/telemetry/service.ts index a3dd0a45..05ac1482 100644 --- a/src/telemetry/service.ts +++ b/src/telemetry/service.ts @@ -19,6 +19,8 @@ import { import { newSpanId, newTraceId } from "./ids"; import { NOOP_SPAN, type Span } from "./span"; +import type { TelemetryReporter } from "./reporter"; + const LEVEL_ORDER: Readonly> = { off: 0, local: 1, @@ -44,7 +46,7 @@ interface EmitOptions extends Partial { * by `minLevel` and may self-gate. `dispose` flushes are best-effort since * VS Code does not await deactivation. */ -export class TelemetryService implements vscode.Disposable { +export class TelemetryService implements vscode.Disposable, TelemetryReporter { #level: TelemetryLevel; #nextSequence = 0; #deploymentUrl = ""; diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index b6eab26b..b0c12a14 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -28,6 +28,11 @@ import { ClientCertificateError } from "@/error/clientCertificateError"; import { ServerCertificateError } from "@/error/serverCertificateError"; import { getHeaders } from "@/headers"; import { type RequestConfigWithMeta } from "@/logging/types"; +import { LOCAL_SINK_SETTING } from "@/settings/telemetry"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "@/telemetry/reporter"; import { ReconnectingWebSocket } from "@/websocket/reconnectingWebSocket"; import { @@ -93,8 +98,12 @@ describe("CoderApi", () => { >; let api: CoderApi; - const createApi = (url = CODER_URL, token = AXIOS_TOKEN) => { - return CoderApi.create(url, token, mockLogger); + const createApi = ( + url = CODER_URL, + token = AXIOS_TOKEN, + telemetry?: TelemetryReporter, + ) => { + return CoderApi.create(url, token, mockLogger, telemetry); }; beforeEach(() => { @@ -229,6 +238,34 @@ describe("CoderApi", () => { ); }); + it("rolls HTTP responses into telemetry when telemetry is provided", async () => { + vi.useFakeTimers(); + mockConfig.set(LOCAL_SINK_SETTING, { + httpRequests: { windowSeconds: 1 }, + }); + const log = vi.fn(); + api = createApi(CODER_URL, AXIOS_TOKEN, { + ...NOOP_TELEMETRY_REPORTER, + log, + }); + + try { + await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + window_seconds: 1, + count_2xx: 1, + }), + ); + } finally { + vi.useRealTimers(); + } + }); + describe("certificate refresh and retry", () => { const rejectWithCertError = ( config: InternalAxiosRequestConfig, diff --git a/test/unit/logging/httpRequestsTelemetry.test.ts b/test/unit/logging/httpRequestsTelemetry.test.ts new file mode 100644 index 00000000..71af1f4b --- /dev/null +++ b/test/unit/logging/httpRequestsTelemetry.test.ts @@ -0,0 +1,169 @@ +import { afterEach, describe, expect, it, vi } from "vitest"; + +import { + HttpRequestsTelemetry, + normalizeHttpRoute, +} from "@/logging/httpRequestsTelemetry"; +import { LOCAL_SINK_SETTING } from "@/settings/telemetry"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "@/telemetry/reporter"; + +import { MockConfigurationProvider } from "../../mocks/testHelpers"; + +interface Harness { + rollup: HttpRequestsTelemetry; + log: ReturnType; +} + +function makeHarness(windowSeconds = 60): Harness { + vi.useFakeTimers(); + const config = new MockConfigurationProvider(); + config.set("coder.telemetry.level", "local"); + config.set(LOCAL_SINK_SETTING, { + httpRequests: { windowSeconds }, + }); + + const log = vi.fn(); + const reporter: TelemetryReporter = { + ...NOOP_TELEMETRY_REPORTER, + log, + }; + return { + rollup: HttpRequestsTelemetry.start(reporter), + log, + }; +} + +describe("HttpRequestsTelemetry", () => { + let h: Harness | undefined; + + afterEach(() => { + h?.rollup.dispose(); + h = undefined; + vi.useRealTimers(); + }); + + it("rolls several requests for the same method and route into one event", async () => { + h = makeHarness(2); + + h.rollup.record({ + method: "get", + url: "/api/v2/workspaces/abc-123?owner=danny", + statusCode: 200, + durationMs: 100, + }); + h.rollup.record({ + method: "GET", + url: "/api/v2/workspaces/abc-123?owner=someone-else", + statusCode: 204, + durationMs: 200, + }); + h.rollup.record({ + method: "GET", + url: "/api/v2/workspaces/abc-123", + statusCode: 200, + durationMs: 300, + }); + + await vi.advanceTimersByTimeAsync(2000); + + expect(h.log).toHaveBeenCalledTimes(1); + expect(h.log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + { + window_seconds: 2, + count_2xx: 3, + count_3xx: 0, + count_4xx: 0, + count_5xx: 0, + count_network_error: 0, + avg_duration_ms: 200, + p95_duration_ms: 300, + }, + ); + }); + + it("counts status code classes and network errors in the right buckets", async () => { + h = makeHarness(1); + const baseSample = { + method: "POST", + url: "/api/v2/users/danny/workspaces", + }; + + h.rollup.record({ ...baseSample, statusCode: 201, durationMs: 10 }); + h.rollup.record({ ...baseSample, statusCode: 302, durationMs: 20 }); + h.rollup.record({ ...baseSample, statusCode: 404, durationMs: 30 }); + h.rollup.record({ ...baseSample, statusCode: 500, durationMs: 40 }); + h.rollup.record({ ...baseSample, networkError: true, durationMs: 50 }); + + await vi.advanceTimersByTimeAsync(1000); + + expect(h.log).toHaveBeenCalledWith( + "http.requests", + { method: "POST", route: "/api/v2/users/{name}/workspaces" }, + expect.objectContaining({ + count_2xx: 1, + count_3xx: 1, + count_4xx: 1, + count_5xx: 1, + count_network_error: 1, + }), + ); + }); + + it("does not emit for an empty window", async () => { + h = makeHarness(1); + + await vi.advanceTimersByTimeAsync(1000); + + expect(h.log).not.toHaveBeenCalled(); + }); + + it("calculates p95 with the sorted nearest-rank reference", async () => { + h = makeHarness(1); + const durations = [ + 10, 20, 30, 40, 50, 60, 70, 80, 90, 100, 110, 120, 130, 140, 150, 160, + 170, 180, 190, 200, + ]; + + for (const durationMs of durations) { + h.rollup.record({ + method: "GET", + url: "/api/v2/workspaces/ws-id", + statusCode: 200, + durationMs, + }); + } + + await vi.advanceTimersByTimeAsync(1000); + + expect(h.log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + avg_duration_ms: 105, + p95_duration_ms: 190, + }), + ); + }); + + it("normalizes routes without preserving query strings or identifiers", () => { + expect(normalizeHttpRoute("/api/v2/workspaces/abc-123?foo=bar")).toBe( + "/api/v2/workspaces/{id}", + ); + expect(normalizeHttpRoute("/api/v2/users/danny/workspaces")).toBe( + "/api/v2/users/{name}/workspaces", + ); + expect( + normalizeHttpRoute( + "/api/v2/workspaceagents/9f0f7f37-dfb7-4f4b-bcb8-c7062c7550fc/logs", + ), + ).toBe("/api/v2/workspaceagents/{id}/logs"); + expect(normalizeHttpRoute("/api/v2/workspaces/123/builds/456")).toBe( + "/api/v2/workspaces/{id}/builds/{id}", + ); + }); +}); diff --git a/test/unit/settings/telemetry.test.ts b/test/unit/settings/telemetry.test.ts index cfc7f2c6..d7a056e0 100644 --- a/test/unit/settings/telemetry.test.ts +++ b/test/unit/settings/telemetry.test.ts @@ -1,9 +1,11 @@ import { beforeEach, describe, expect, it } from "vitest"; import { + HTTP_REQUESTS_TELEMETRY_DEFAULTS, LOCAL_SINK_DEFAULTS, LOCAL_SINK_SETTING, TELEMETRY_LEVEL_SETTING, + readHttpRequestsTelemetryConfig, readLocalSinkConfig, readTelemetryLevel, } from "@/settings/telemetry"; @@ -96,4 +98,55 @@ describe("telemetry settings", () => { }); }); }); + + describe("readHttpRequestsTelemetryConfig", () => { + it("returns defaults when unset", () => { + expect(readHttpRequestsTelemetryConfig(config)).toEqual( + HTTP_REQUESTS_TELEMETRY_DEFAULTS, + ); + }); + + it.each([ + ["a string", "nope"], + ["a boolean", true], + ["null", null], + ["an array", [1, 2]], + ])("returns defaults when the raw value is %s", (_, raw) => { + config.set(LOCAL_SINK_SETTING, raw); + expect(readHttpRequestsTelemetryConfig(config)).toEqual( + HTTP_REQUESTS_TELEMETRY_DEFAULTS, + ); + }); + + it("accepts a fully-specified object", () => { + config.set(LOCAL_SINK_SETTING, { + httpRequests: { windowSeconds: 10 }, + }); + expect(readHttpRequestsTelemetryConfig(config)).toEqual({ + windowSeconds: 10, + }); + }); + + it.each([ + ["zero", 0], + ["a negative", -1], + ["NaN", Number.NaN], + ["a numeric string", "100"], + ["a boolean", true], + ])("falls back per-field when a value is %s", (_, bad) => { + config.set(LOCAL_SINK_SETTING, { + httpRequests: { windowSeconds: bad }, + }); + expect(readHttpRequestsTelemetryConfig(config).windowSeconds).toBe( + HTTP_REQUESTS_TELEMETRY_DEFAULTS.windowSeconds, + ); + }); + + it("ignores invalid httpRequests values", () => { + config.set(LOCAL_SINK_SETTING, { httpRequests: "nope" }); + expect(readHttpRequestsTelemetryConfig(config)).toEqual( + HTTP_REQUESTS_TELEMETRY_DEFAULTS, + ); + }); + }); }); From 277681bab061b7da959d070e220d144495d3f543 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Fri, 8 May 2026 14:52:45 +0000 Subject: [PATCH 2/5] fix(telemetry): simplify http request rollup wiring --- src/api/coderApi.ts | 122 +++++-- src/logging/httpRequestsTelemetry.ts | 300 +++++++++------- src/settings/telemetry.ts | 51 +-- test/unit/api/coderApi.test.ts | 61 +++- .../logging/httpRequestsTelemetry.test.ts | 336 +++++++++++------- test/unit/settings/telemetry.test.ts | 20 +- 6 files changed, 534 insertions(+), 356 deletions(-) diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index 3397f10f..3c93b4f5 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -1,21 +1,12 @@ import { - type AxiosResponseHeaders, - type AxiosInstance, + isAxiosError, type AxiosHeaders, + type AxiosInstance, + type AxiosResponseHeaders, type AxiosResponseTransformer, - isAxiosError, } from "axios"; import { Api } from "coder/site/src/api/api"; -import { - type ServerSentEvent, - type GetInboxNotificationResponse, - type ProvisionerJobLog, - type Workspace, - type WorkspaceAgent, - type WorkspaceAgentLog, -} from "coder/site/src/api/typesGenerated"; import * as vscode from "vscode"; -import { type ClientOptions } from "ws"; import { watchConfigurationChanges } from "../configWatcher"; import { ClientCertificateError } from "../error/clientCertificateError"; @@ -25,25 +16,31 @@ import { getHeaders } from "../headers"; import { EventStreamLogger } from "../logging/eventStreamLogger"; import { createRequestMeta, - logRequest, logError, + logRequest, logResponse, } from "../logging/httpLogger"; -import { HttpRequestsTelemetry } from "../logging/httpRequestsTelemetry"; -import { type Logger } from "../logging/logger"; import { - type RequestConfigWithMeta, + HttpRequestsTelemetry, + NOOP_HTTP_REQUESTS_TELEMETRY, + type HttpRequestsTelemetryRecorder, +} from "../logging/httpRequestsTelemetry"; +import { HttpClientLogLevel, + type RequestConfigWithMeta, } from "../logging/types"; import { sizeOf } from "../logging/utils"; import { getHeaderCommand } from "../settings/headers"; -import { type TelemetryReporter } from "../telemetry/reporter"; -import { HttpStatusCode, WebSocketCloseCode } from "../websocket/codes"; import { - type UnidirectionalStream, - type CloseEvent, - type ErrorEvent, -} from "../websocket/eventStreamConnection"; + LOCAL_TELEMETRY_SETTING, + readHttpRequestsTelemetryConfig, + type HttpRequestsTelemetryConfig, +} from "../settings/telemetry"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; +import { HttpStatusCode, WebSocketCloseCode } from "../websocket/codes"; import { OneWayWebSocket, type OneWayWebSocketInit, @@ -58,8 +55,29 @@ import { SseConnection } from "../websocket/sseConnection"; import { getRefreshCommand, refreshCertificates } from "./certificateRefresh"; import { createHttpAgent } from "./utils"; +import type { + GetInboxNotificationResponse, + ProvisionerJobLog, + ServerSentEvent, + Workspace, + WorkspaceAgent, + WorkspaceAgentLog, +} from "coder/site/src/api/typesGenerated"; +import type { ClientOptions } from "ws"; + +import type { Logger } from "../logging/logger"; +import type { + CloseEvent, + ErrorEvent, + UnidirectionalStream, +} from "../websocket/eventStreamConnection"; + const coderSessionTokenHeader = "Coder-Session-Token"; +const NOOP_DISPOSABLE: vscode.Disposable = { + dispose: () => undefined, +}; + /** * Configuration settings that affect WebSocket connections. * Changes to these settings will trigger WebSocket reconnection. @@ -87,13 +105,15 @@ export class CoderApi extends Api implements vscode.Disposable { ReconnectingWebSocket >(); private readonly configWatcher: vscode.Disposable; + private readonly httpRequestsConfigWatcher: vscode.Disposable; private constructor( private readonly output: Logger, - private readonly httpRequestsTelemetry?: HttpRequestsTelemetry, + private readonly httpRequestsTelemetry: HttpRequestsTelemetryRecorder, ) { super(); this.configWatcher = this.watchConfigChanges(); + this.httpRequestsConfigWatcher = this.watchHttpRequestsConfigChanges(); } /** @@ -104,11 +124,9 @@ export class CoderApi extends Api implements vscode.Disposable { baseUrl: string, token: string | undefined, output: Logger, - telemetry?: TelemetryReporter, + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ): CoderApi { - const httpRequestsTelemetry = telemetry - ? HttpRequestsTelemetry.start(telemetry) - : undefined; + const httpRequestsTelemetry = createHttpRequestsTelemetry(telemetry); const client = new CoderApi(output, httpRequestsTelemetry); client.setCredentials(baseUrl, token); @@ -164,7 +182,8 @@ export class CoderApi extends Api implements vscode.Disposable { */ dispose(): void { this.configWatcher.dispose(); - this.httpRequestsTelemetry?.dispose(); + this.httpRequestsConfigWatcher.dispose(); + this.httpRequestsTelemetry.dispose(); for (const socket of this.reconnectingSockets) { socket.close(); } @@ -197,6 +216,32 @@ export class CoderApi extends Api implements vscode.Disposable { }); } + private watchHttpRequestsConfigChanges(): vscode.Disposable { + if (this.httpRequestsTelemetry === NOOP_HTTP_REQUESTS_TELEMETRY) { + return NOOP_DISPOSABLE; + } + + return watchConfigurationChanges( + [ + { + setting: LOCAL_TELEMETRY_SETTING, + getValue: () => + readHttpRequestsTelemetryConfig( + vscode.workspace.getConfiguration(), + ), + }, + ], + (changes) => { + const config = changes.get(LOCAL_TELEMETRY_SETTING) as + | HttpRequestsTelemetryConfig + | undefined; + if (config) { + this.httpRequestsTelemetry.updateConfig(config); + } + }, + ); + } + watchInboxNotifications = async ( watchTemplates: string[], watchTargets: string[], @@ -483,10 +528,23 @@ export class CoderApi extends Api implements vscode.Disposable { /** * Set up logging and request interceptors for the CoderApi instance. */ +function createHttpRequestsTelemetry( + telemetry: TelemetryReporter, +): HttpRequestsTelemetryRecorder { + if (telemetry === NOOP_TELEMETRY_REPORTER) { + return NOOP_HTTP_REQUESTS_TELEMETRY; + } + + return new HttpRequestsTelemetry( + telemetry, + readHttpRequestsTelemetryConfig(vscode.workspace.getConfiguration()), + ); +} + function setupInterceptors( client: CoderApi, output: Logger, - httpRequestsTelemetry: HttpRequestsTelemetry | undefined, + httpRequestsTelemetry: HttpRequestsTelemetryRecorder, ): void { addLoggingInterceptors( client.getAxiosInstance(), @@ -543,7 +601,7 @@ function setupInterceptors( function addLoggingInterceptors( client: AxiosInstance, logger: Logger, - httpRequestsTelemetry: HttpRequestsTelemetry | undefined, + httpRequestsTelemetry: HttpRequestsTelemetryRecorder, ) { client.interceptors.request.use( (config) => { @@ -577,12 +635,12 @@ function addLoggingInterceptors( client.interceptors.response.use( (response) => { - httpRequestsTelemetry?.recordResponse(response); + httpRequestsTelemetry.recordResponse(response); logResponse(logger, response, getLogLevel()); return response; }, (error: unknown) => { - httpRequestsTelemetry?.recordError(error); + httpRequestsTelemetry.recordError(error); logError(logger, error, getLogLevel()); throw error; }, diff --git a/src/logging/httpRequestsTelemetry.ts b/src/logging/httpRequestsTelemetry.ts index 7c19609a..1471abea 100644 --- a/src/logging/httpRequestsTelemetry.ts +++ b/src/logging/httpRequestsTelemetry.ts @@ -1,27 +1,26 @@ import { isAxiosError, type AxiosResponse } from "axios"; -import * as vscode from "vscode"; - -import { watchConfigurationChanges } from "../configWatcher"; -import { - LOCAL_TELEMETRY_SETTING, - readHttpRequestsTelemetryConfig, - type HttpRequestsTelemetryConfig, -} from "../settings/telemetry"; -import { type TelemetryReporter } from "../telemetry/reporter"; import { formatMethod } from "./formatters"; +import type { Disposable } from "vscode"; + +import type { HttpRequestsTelemetryConfig } from "../settings/telemetry"; +import type { TelemetryReporter } from "../telemetry/reporter"; + import type { RequestConfigWithMeta } from "./types"; const EVENT_NAME = "http.requests"; const UNKNOWN_ROUTE = ""; -interface RouteNormalizationRule { - readonly pattern: RegExp; - readonly replacement: string; -} +const ID_PLACEHOLDER = "{id}"; +const NAME_PLACEHOLDER = "{name}"; +type Placeholder = typeof ID_PLACEHOLDER | typeof NAME_PLACEHOLDER; +type RouteNormalizationRule = readonly string[]; + +const route = (...segments: RouteNormalizationRule): RouteNormalizationRule => + segments; -const ID_RESOURCES = [ +const ID_RESOURCE_ROUTES = [ "aibridge/sessions", "files", "groups", @@ -35,46 +34,48 @@ const ID_RESOURCES = [ ] as const; export const ROUTE_NORMALIZATION_RULES: readonly RouteNormalizationRule[] = [ - { - pattern: /^(\/api\/v2\/users\/)[^/]+(\/workspace\/)[^/]+(?=$|\/)/, - replacement: "$1{name}$2{name}", - }, - { - pattern: /^(\/api\/v2\/users\/)[^/]+(?=$|\/)/, - replacement: "$1{name}", - }, - { - pattern: /^(\/api\/v2\/tasks\/)[^/]+(?=$|\/)/, - replacement: "$1{name}", - }, - { - pattern: - /^(\/api\/v2\/organizations\/)[^/]+(\/templates\/)[^/]+(\/versions\/)[^/]+(?=$|\/)/, - replacement: "$1{id}$2{name}$3{name}", - }, - { - pattern: /^(\/api\/v2\/organizations\/)[^/]+(\/templates\/)[^/]+(?=$|\/)/, - replacement: "$1{id}$2{name}", - }, - { - pattern: /^(\/api\/v2\/organizations\/)[^/]+(\/groups\/)[^/]+(?=$|\/)/, - replacement: "$1{id}$2{name}", - }, - { - pattern: /^(\/api\/v2\/organizations\/)[^/]+(?=$|\/)/, - replacement: "$1{id}", - }, - ...ID_RESOURCES.map((resource) => ({ - pattern: new RegExp(`^(\\/api\\/v2\\/${resource}\\/)[^/]+(?=$|\\/)`), - replacement: "$1{id}", - })), + route("api", "v2", "users", NAME_PLACEHOLDER, "workspace", NAME_PLACEHOLDER), + route("api", "v2", "users", NAME_PLACEHOLDER, "keys", ID_PLACEHOLDER), + route("api", "v2", "users", NAME_PLACEHOLDER), + route("api", "v2", "tasks", NAME_PLACEHOLDER, ID_PLACEHOLDER), + route("api", "v2", "tasks", NAME_PLACEHOLDER), + route( + "api", + "v2", + "organizations", + ID_PLACEHOLDER, + "templates", + NAME_PLACEHOLDER, + "versions", + NAME_PLACEHOLDER, + ), + route( + "api", + "v2", + "organizations", + ID_PLACEHOLDER, + "templates", + NAME_PLACEHOLDER, + ), + route( + "api", + "v2", + "organizations", + ID_PLACEHOLDER, + "groups", + NAME_PLACEHOLDER, + ), + route("api", "v2", "organizations", ID_PLACEHOLDER), + ...ID_RESOURCE_ROUTES.map((resource) => + route("api", "v2", ...resource.split("/"), ID_PLACEHOLDER), + ), ]; -const UUID_SEGMENT = - /\/[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}(?=$|\/)/gi; -const NUMERIC_SEGMENT = /\/\d+(?=$|\/)/g; +const UUID = + /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i; +const NUMERIC = /^\d+$/; -export interface HttpRequestTelemetrySample { +interface HttpRequestTelemetrySample { readonly method?: string; readonly url?: string; readonly baseURL?: string; @@ -92,34 +93,46 @@ interface HttpRequestBucket { durationsMs: number[]; } -export class HttpRequestsTelemetry implements vscode.Disposable { +export interface HttpRequestsTelemetryRecorder extends Disposable { + recordResponse(response: AxiosResponse): void; + recordError(error: unknown): void; + updateConfig(config: HttpRequestsTelemetryConfig): void; +} + +export const NOOP_HTTP_REQUESTS_TELEMETRY: HttpRequestsTelemetryRecorder = { + recordResponse: () => undefined, + recordError: () => undefined, + updateConfig: () => undefined, + dispose: () => undefined, +}; + +export class HttpRequestsTelemetry implements HttpRequestsTelemetryRecorder { readonly #telemetry: TelemetryReporter; - #config: HttpRequestsTelemetryConfig; + #windowSeconds: number; #timer: NodeJS.Timeout | null = null; - #configWatcher: vscode.Disposable | null = null; #disposed = false; readonly #buckets = new Map(); - private constructor( + public constructor( telemetry: TelemetryReporter, config: HttpRequestsTelemetryConfig, ) { this.#telemetry = telemetry; - this.#config = config; + this.#windowSeconds = config.windowSeconds; + this.#scheduleNextWindow(); } - public static start(telemetry: TelemetryReporter): HttpRequestsTelemetry { - const rollup = new HttpRequestsTelemetry( - telemetry, - readHttpRequestsTelemetryConfig(vscode.workspace.getConfiguration()), - ); - rollup.#configWatcher = rollup.#watchConfig(); - rollup.#scheduleNextWindow(); - return rollup; + public updateConfig(config: HttpRequestsTelemetryConfig): void { + if (config.windowSeconds === this.#windowSeconds) { + return; + } + this.#flush(); + this.#windowSeconds = config.windowSeconds; + this.#scheduleNextWindow(); } public recordResponse(response: AxiosResponse): void { - this.record({ + this.#record({ method: response.config.method, url: response.config.url, baseURL: response.config.baseURL, @@ -138,7 +151,7 @@ export class HttpRequestsTelemetry implements vscode.Disposable { return; } - this.record({ + this.#record({ method: config.method, url: config.url, baseURL: config.baseURL, @@ -148,14 +161,45 @@ export class HttpRequestsTelemetry implements vscode.Disposable { }); } - public record(sample: HttpRequestTelemetrySample): void { + #flush(): void { + const buckets = [...this.#buckets.entries()]; + this.#buckets.clear(); + for (const [key, bucket] of buckets) { + const { method, route: normalizedRoute } = parseBucketKey(key); + this.#telemetry.log( + EVENT_NAME, + { method, route: normalizedRoute }, + { + window_seconds: this.#windowSeconds, + count_2xx: bucket.count2xx, + count_3xx: bucket.count3xx, + count_4xx: bucket.count4xx, + count_5xx: bucket.count5xx, + count_network_error: bucket.countNetworkError, + avg_duration_ms: average(bucket.durationsMs), + p95_duration_ms: percentile95(bucket.durationsMs), + }, + ); + } + } + + public dispose(): void { + this.#disposed = true; + if (this.#timer) { + clearTimeout(this.#timer); + this.#timer = null; + } + this.#buckets.clear(); + } + + #record(sample: HttpRequestTelemetrySample): void { if (this.#disposed) { return; } const method = formatMethod(sample.method); - const route = normalizeHttpRoute(sample.url, sample.baseURL); - const key = bucketKey(method, route); + const normalizedRoute = normalizeHttpRoute(sample.url, sample.baseURL); + const key = bucketKey(method, normalizedRoute); const bucket = this.#buckets.get(key) ?? createBucket(); this.#buckets.set(key, bucket); @@ -186,64 +230,6 @@ export class HttpRequestsTelemetry implements vscode.Disposable { } } - public flush(): void { - const buckets = [...this.#buckets.entries()]; - this.#buckets.clear(); - for (const [key, bucket] of buckets) { - const { method, route } = parseBucketKey(key); - this.#telemetry.log( - EVENT_NAME, - { method, route }, - { - window_seconds: this.#config.windowSeconds, - count_2xx: bucket.count2xx, - count_3xx: bucket.count3xx, - count_4xx: bucket.count4xx, - count_5xx: bucket.count5xx, - count_network_error: bucket.countNetworkError, - avg_duration_ms: average(bucket.durationsMs), - p95_duration_ms: percentile95(bucket.durationsMs), - }, - ); - } - } - - public dispose(): void { - this.#disposed = true; - this.#configWatcher?.dispose(); - this.#configWatcher = null; - if (this.#timer) { - clearTimeout(this.#timer); - this.#timer = null; - } - this.#buckets.clear(); - } - - #watchConfig(): vscode.Disposable { - return watchConfigurationChanges( - [ - { - setting: LOCAL_TELEMETRY_SETTING, - getValue: () => - readHttpRequestsTelemetryConfig( - vscode.workspace.getConfiguration(), - ), - }, - ], - (changes) => { - const next = changes.get(LOCAL_TELEMETRY_SETTING) as - | HttpRequestsTelemetryConfig - | undefined; - if (!next) { - return; - } - this.flush(); - this.#config = next; - this.#scheduleNextWindow(); - }, - ); - } - #scheduleNextWindow(): void { if (this.#timer) { clearTimeout(this.#timer); @@ -253,9 +239,9 @@ export class HttpRequestsTelemetry implements vscode.Disposable { return; } this.#timer = setTimeout(() => { - this.flush(); + this.#flush(); this.#scheduleNextWindow(); - }, this.#config.windowSeconds * 1000); + }, this.#windowSeconds * 1000); } } @@ -267,22 +253,64 @@ export function normalizeHttpRoute( return UNKNOWN_ROUTE; } - let route = parsePathname(url, baseURL); + const segments = parsePathSegments(url, baseURL); + if (segments.length === 0) { + return UNKNOWN_ROUTE; + } + for (const rule of ROUTE_NORMALIZATION_RULES) { - route = route.replace(rule.pattern, rule.replacement); + const normalized = normalizeByRule(segments, rule); + if (normalized) { + return normalized; + } } - return route.replace(UUID_SEGMENT, "/{id}").replace(NUMERIC_SEGMENT, "/{id}"); + return `/${segments.map(normalizeIdSegment).join("/")}`; } -function parsePathname(url: string, baseURL?: string): string { +function normalizeByRule( + segments: readonly string[], + rule: RouteNormalizationRule, +): string | undefined { + if (segments.length < rule.length) { + return undefined; + } + + const normalized: string[] = []; + for (const [index, ruleSegment] of rule.entries()) { + if (isPlaceholder(ruleSegment)) { + normalized.push(ruleSegment); + continue; + } + if (segments[index] !== ruleSegment) { + return undefined; + } + normalized.push(segments[index]); + } + + return `/${[ + ...normalized, + ...segments.slice(rule.length).map(normalizeIdSegment), + ].join("/")}`; +} + +function parsePathSegments(url: string, baseURL?: string): string[] { try { - return new URL(url, baseURL ?? "http://coder.invalid").pathname; + return new URL(url, baseURL ?? "http://coder.invalid").pathname + .split("/") + .filter(Boolean); } catch { - const withoutQuery = url.split("?", 1)[0] || UNKNOWN_ROUTE; - return withoutQuery.startsWith("/") ? withoutQuery : `/${withoutQuery}`; + return []; } } +function isPlaceholder(segment: string): segment is Placeholder { + return segment === ID_PLACEHOLDER || segment === NAME_PLACEHOLDER; +} + +function normalizeIdSegment(segment: string): string { + return UUID.test(segment) || NUMERIC.test(segment) ? ID_PLACEHOLDER : segment; +} + function durationFromConfig(config: RequestConfigWithMeta | undefined): number { const startedAt = config?.metadata?.startedAt; return typeof startedAt === "number" ? Date.now() - startedAt : 0; diff --git a/src/settings/telemetry.ts b/src/settings/telemetry.ts index 08178641..8f1417c1 100644 --- a/src/settings/telemetry.ts +++ b/src/settings/telemetry.ts @@ -60,12 +60,8 @@ export function readLocalSinkConfig( cfg: Pick, ): LocalSinkConfig { const obj = readLocalTelemetryObject(cfg); - const read = (key: keyof LocalSinkConfig): number => { - const value = obj[key]; - return typeof value === "number" && value >= LOCAL_SINK_MINIMUMS[key] - ? value - : LOCAL_SINK_DEFAULTS[key]; - }; + const read = (key: keyof LocalSinkConfig): number => + readNumber(obj, key, LOCAL_SINK_DEFAULTS[key], LOCAL_SINK_MINIMUMS[key]); return { flushIntervalMs: read("flushIntervalMs"), flushBatchSize: read("flushBatchSize"), @@ -79,30 +75,37 @@ export function readLocalSinkConfig( export function readHttpRequestsTelemetryConfig( cfg: Pick, ): HttpRequestsTelemetryConfig { - const obj = readLocalTelemetryObject(cfg); - const httpRequests = - obj.httpRequests && - typeof obj.httpRequests === "object" && - !Array.isArray(obj.httpRequests) - ? (obj.httpRequests as Record) - : {}; - const read = (key: keyof HttpRequestsTelemetryConfig): number => { - const value = httpRequests[key]; - return typeof value === "number" && - value >= HTTP_REQUESTS_TELEMETRY_MINIMUMS[key] - ? value - : HTTP_REQUESTS_TELEMETRY_DEFAULTS[key]; - }; + const httpRequests = readObject(readLocalTelemetryObject(cfg).httpRequests); return { - windowSeconds: read("windowSeconds"), + windowSeconds: readNumber( + httpRequests, + "windowSeconds", + HTTP_REQUESTS_TELEMETRY_DEFAULTS.windowSeconds, + HTTP_REQUESTS_TELEMETRY_MINIMUMS.windowSeconds, + ), }; } function readLocalTelemetryObject( cfg: Pick, ): Record { - const raw = cfg.get(LOCAL_TELEMETRY_SETTING); - return raw && typeof raw === "object" && !Array.isArray(raw) - ? (raw as Record) + return readObject(cfg.get(LOCAL_TELEMETRY_SETTING)); +} + +function readObject(value: unknown): Record { + return value && typeof value === "object" && !Array.isArray(value) + ? (value as Record) : {}; } + +function readNumber( + obj: Record, + key: string, + defaultValue: number, + minimum: number, +): number { + const value = obj[key]; + return typeof value === "number" && Number.isFinite(value) && value >= minimum + ? value + : defaultValue; +} diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index b0c12a14..cb07bcd0 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -4,7 +4,6 @@ import axios, { type CreateAxiosDefaults, type InternalAxiosRequestConfig, } from "axios"; -import { type ProvisionerJobLog } from "coder/site/src/api/typesGenerated"; import { EventSource } from "eventsource"; import { ProxyAgent } from "proxy-agent"; import { @@ -27,8 +26,7 @@ import { createHttpAgent } from "@/api/utils"; import { ClientCertificateError } from "@/error/clientCertificateError"; import { ServerCertificateError } from "@/error/serverCertificateError"; import { getHeaders } from "@/headers"; -import { type RequestConfigWithMeta } from "@/logging/types"; -import { LOCAL_SINK_SETTING } from "@/settings/telemetry"; +import { LOCAL_TELEMETRY_SETTING } from "@/settings/telemetry"; import { NOOP_TELEMETRY_REPORTER, type TelemetryReporter, @@ -40,6 +38,10 @@ import { MockConfigurationProvider, } from "../../mocks/testHelpers"; +import type { ProvisionerJobLog } from "coder/site/src/api/typesGenerated"; + +import type { RequestConfigWithMeta } from "@/logging/types"; + const CODER_URL = "https://coder.example.com"; const AXIOS_TOKEN = "passed-token"; const BUILD_ID = "build-123"; @@ -101,7 +103,7 @@ describe("CoderApi", () => { const createApi = ( url = CODER_URL, token = AXIOS_TOKEN, - telemetry?: TelemetryReporter, + telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ) => { return CoderApi.create(url, token, mockLogger, telemetry); }; @@ -126,6 +128,7 @@ describe("CoderApi", () => { afterEach(() => { // Dispose any api created during the test to clean up config watchers api?.dispose(); + vi.useRealTimers(); }); describe("HTTP Interceptors", () => { @@ -240,7 +243,7 @@ describe("CoderApi", () => { it("rolls HTTP responses into telemetry when telemetry is provided", async () => { vi.useFakeTimers(); - mockConfig.set(LOCAL_SINK_SETTING, { + mockConfig.set(LOCAL_TELEMETRY_SETTING, { httpRequests: { windowSeconds: 1 }, }); const log = vi.fn(); @@ -249,21 +252,41 @@ describe("CoderApi", () => { log, }); - try { - await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); - await vi.advanceTimersByTimeAsync(1000); + await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); + await vi.advanceTimersByTimeAsync(1000); - expect(log).toHaveBeenCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ - window_seconds: 1, - count_2xx: 1, - }), - ); - } finally { - vi.useRealTimers(); - } + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + window_seconds: 1, + count_2xx: 1, + }), + ); + }); + + it("updates HTTP telemetry window from configuration changes", async () => { + vi.useFakeTimers(); + mockConfig.set(LOCAL_TELEMETRY_SETTING, { + httpRequests: { windowSeconds: 10 }, + }); + const log = vi.fn(); + api = createApi(CODER_URL, AXIOS_TOKEN, { + ...NOOP_TELEMETRY_REPORTER, + log, + }); + + mockConfig.set(LOCAL_TELEMETRY_SETTING, { + httpRequests: { windowSeconds: 1 }, + }); + await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ window_seconds: 1 }), + ); }); describe("certificate refresh and retry", () => { diff --git a/test/unit/logging/httpRequestsTelemetry.test.ts b/test/unit/logging/httpRequestsTelemetry.test.ts index 71af1f4b..7a0508a9 100644 --- a/test/unit/logging/httpRequestsTelemetry.test.ts +++ b/test/unit/logging/httpRequestsTelemetry.test.ts @@ -1,169 +1,235 @@ +import { AxiosError, AxiosHeaders, type AxiosResponse } from "axios"; import { afterEach, describe, expect, it, vi } from "vitest"; import { HttpRequestsTelemetry, normalizeHttpRoute, } from "@/logging/httpRequestsTelemetry"; -import { LOCAL_SINK_SETTING } from "@/settings/telemetry"; import { NOOP_TELEMETRY_REPORTER, type TelemetryReporter, } from "@/telemetry/reporter"; -import { MockConfigurationProvider } from "../../mocks/testHelpers"; +import type { RequestConfigWithMeta } from "@/logging/types"; interface Harness { rollup: HttpRequestsTelemetry; log: ReturnType; } -function makeHarness(windowSeconds = 60): Harness { - vi.useFakeTimers(); - const config = new MockConfigurationProvider(); - config.set("coder.telemetry.level", "local"); - config.set(LOCAL_SINK_SETTING, { - httpRequests: { windowSeconds }, - }); - - const log = vi.fn(); - const reporter: TelemetryReporter = { - ...NOOP_TELEMETRY_REPORTER, - log, - }; - return { - rollup: HttpRequestsTelemetry.start(reporter), - log, - }; +interface RequestOptions { + readonly method?: string; + readonly url: string; + readonly status?: number; + readonly durationMs?: number; } describe("HttpRequestsTelemetry", () => { - let h: Harness | undefined; - - afterEach(() => { - h?.rollup.dispose(); - h = undefined; - vi.useRealTimers(); - }); + afterEach(() => vi.useRealTimers()); + + it("emits one event per active method and route at the window boundary", async () => { + const { rollup, log } = createHarness(2); + try { + recordResponse(rollup, { + method: "get", + url: "/api/v2/workspaces/abc-123?owner=danny", + status: 200, + durationMs: 100, + }); + recordResponse(rollup, { + method: "GET", + url: "/api/v2/workspaces/abc-123?owner=someone-else", + status: 204, + durationMs: 200, + }); + recordResponse(rollup, { + method: "POST", + url: "/api/v2/workspaces/abc-123", + status: 201, + durationMs: 300, + }); - it("rolls several requests for the same method and route into one event", async () => { - h = makeHarness(2); - - h.rollup.record({ - method: "get", - url: "/api/v2/workspaces/abc-123?owner=danny", - statusCode: 200, - durationMs: 100, - }); - h.rollup.record({ - method: "GET", - url: "/api/v2/workspaces/abc-123?owner=someone-else", - statusCode: 204, - durationMs: 200, - }); - h.rollup.record({ - method: "GET", - url: "/api/v2/workspaces/abc-123", - statusCode: 200, - durationMs: 300, - }); - - await vi.advanceTimersByTimeAsync(2000); - - expect(h.log).toHaveBeenCalledTimes(1); - expect(h.log).toHaveBeenCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - { - window_seconds: 2, - count_2xx: 3, - count_3xx: 0, - count_4xx: 0, - count_5xx: 0, - count_network_error: 0, - avg_duration_ms: 200, - p95_duration_ms: 300, - }, - ); + await vi.advanceTimersByTimeAsync(2000); + + expect(log).toHaveBeenCalledTimes(2); + expect(log).toHaveBeenNthCalledWith( + 1, + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + { + window_seconds: 2, + count_2xx: 2, + count_3xx: 0, + count_4xx: 0, + count_5xx: 0, + count_network_error: 0, + avg_duration_ms: 150, + p95_duration_ms: 200, + }, + ); + expect(log).toHaveBeenNthCalledWith( + 2, + "http.requests", + { method: "POST", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + window_seconds: 2, + count_2xx: 1, + }), + ); + } finally { + rollup.dispose(); + } }); - it("counts status code classes and network errors in the right buckets", async () => { - h = makeHarness(1); - const baseSample = { - method: "POST", - url: "/api/v2/users/danny/workspaces", - }; - - h.rollup.record({ ...baseSample, statusCode: 201, durationMs: 10 }); - h.rollup.record({ ...baseSample, statusCode: 302, durationMs: 20 }); - h.rollup.record({ ...baseSample, statusCode: 404, durationMs: 30 }); - h.rollup.record({ ...baseSample, statusCode: 500, durationMs: 40 }); - h.rollup.record({ ...baseSample, networkError: true, durationMs: 50 }); - - await vi.advanceTimersByTimeAsync(1000); - - expect(h.log).toHaveBeenCalledWith( - "http.requests", - { method: "POST", route: "/api/v2/users/{name}/workspaces" }, - expect.objectContaining({ - count_2xx: 1, - count_3xx: 1, - count_4xx: 1, - count_5xx: 1, - count_network_error: 1, - }), - ); + it("counts status code classes and network errors", async () => { + const { rollup, log } = createHarness(1); + try { + const route = "/api/v2/users/danny/workspaces"; + recordResponse(rollup, { method: "POST", url: route, status: 201 }); + recordResponse(rollup, { method: "POST", url: route, status: 302 }); + recordAxiosError(rollup, { method: "POST", url: route, status: 404 }); + recordAxiosError(rollup, { method: "POST", url: route, status: 500 }); + recordAxiosError(rollup, { method: "POST", url: route }); + + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "POST", route: "/api/v2/users/{name}/workspaces" }, + expect.objectContaining({ + count_2xx: 1, + count_3xx: 1, + count_4xx: 1, + count_5xx: 1, + count_network_error: 1, + }), + ); + } finally { + rollup.dispose(); + } }); - it("does not emit for an empty window", async () => { - h = makeHarness(1); + it("emits nothing for empty windows", async () => { + const { rollup, log } = createHarness(1); + try { + await vi.advanceTimersByTimeAsync(2000); - await vi.advanceTimersByTimeAsync(1000); - - expect(h.log).not.toHaveBeenCalled(); + expect(log).not.toHaveBeenCalled(); + } finally { + rollup.dispose(); + } }); - it("calculates p95 with the sorted nearest-rank reference", async () => { - h = makeHarness(1); - const durations = [ - 10, 20, 30, 40, 50, 60, 70, 80, 90, 100, 110, 120, 130, 140, 150, 160, - 170, 180, 190, 200, - ]; - - for (const durationMs of durations) { - h.rollup.record({ - method: "GET", - url: "/api/v2/workspaces/ws-id", - statusCode: 200, - durationMs, - }); + it("calculates nearest-rank p95", async () => { + const { rollup, log } = createHarness(1); + try { + for (const durationMs of [ + 10, 20, 30, 40, 50, 60, 70, 80, 90, 100, 110, 120, 130, 140, 150, 160, + 170, 180, 190, 200, + ]) { + recordResponse(rollup, { + method: "GET", + url: "/api/v2/workspaces/ws-id", + status: 200, + durationMs, + }); + } + + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + avg_duration_ms: 105, + p95_duration_ms: 190, + }), + ); + } finally { + rollup.dispose(); } - - await vi.advanceTimersByTimeAsync(1000); - - expect(h.log).toHaveBeenCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ - avg_duration_ms: 105, - p95_duration_ms: 190, - }), - ); }); - it("normalizes routes without preserving query strings or identifiers", () => { - expect(normalizeHttpRoute("/api/v2/workspaces/abc-123?foo=bar")).toBe( - "/api/v2/workspaces/{id}", - ); - expect(normalizeHttpRoute("/api/v2/users/danny/workspaces")).toBe( - "/api/v2/users/{name}/workspaces", - ); - expect( - normalizeHttpRoute( - "/api/v2/workspaceagents/9f0f7f37-dfb7-4f4b-bcb8-c7062c7550fc/logs", - ), - ).toBe("/api/v2/workspaceagents/{id}/logs"); - expect(normalizeHttpRoute("/api/v2/workspaces/123/builds/456")).toBe( + it.each([ + ["/api/v2/workspaces/abc-123?foo=bar", "/api/v2/workspaces/{id}"], + [ + "/api/v2/users/danny/workspace/my-workspace?foo=bar", + "/api/v2/users/{name}/workspace/{name}", + ], + ["/api/v2/users/danny/keys/123", "/api/v2/users/{name}/keys/{id}"], + ["/api/v2/tasks/danny/task-123", "/api/v2/tasks/{name}/{id}"], + [ + "/api/v2/organizations/9f0f7f37-dfb7-4f4b-bcb8-c7062c7550fc/templates/base/versions/v1", + "/api/v2/organizations/{id}/templates/{name}/versions/{name}", + ], + [ + "/api/v2/workspaceagents/9f0f7f37-dfb7-4f4b-bcb8-c7062c7550fc/logs", + "/api/v2/workspaceagents/{id}/logs", + ], + [ + "/api/v2/workspaces/123/builds/456", "/api/v2/workspaces/{id}/builds/{id}", - ); + ], + ["http://%", ""], + ])("normalizes %s", (url, expected) => { + expect(normalizeHttpRoute(url)).toBe(expected); }); }); + +function createHarness(windowSeconds = 60): Harness { + vi.useFakeTimers(); + vi.setSystemTime(new Date("2025-01-01T00:00:00.000Z")); + + const log = vi.fn(); + const reporter: TelemetryReporter = { + ...NOOP_TELEMETRY_REPORTER, + log, + }; + return { + rollup: new HttpRequestsTelemetry(reporter, { windowSeconds }), + log, + }; +} + +function recordResponse( + rollup: HttpRequestsTelemetry, + options: RequestOptions, +): void { + rollup.recordResponse(makeResponse(options)); +} + +function recordAxiosError( + rollup: HttpRequestsTelemetry, + options: RequestOptions, +): void { + const config = makeRequestConfig(options); + const response = options.status + ? makeResponse({ ...options, status: options.status }) + : undefined; + rollup.recordError( + new AxiosError("Request failed", undefined, config, {}, response), + ); +} + +function makeResponse(options: RequestOptions): AxiosResponse { + const status = options.status ?? 200; + return { + data: {}, + status, + statusText: String(status), + headers: {}, + config: makeRequestConfig(options), + }; +} + +function makeRequestConfig(options: RequestOptions): RequestConfigWithMeta { + return { + headers: new AxiosHeaders(), + method: options.method, + url: options.url, + metadata: { + requestId: "test-request", + startedAt: Date.now() - (options.durationMs ?? 0), + }, + } as RequestConfigWithMeta; +} diff --git a/test/unit/settings/telemetry.test.ts b/test/unit/settings/telemetry.test.ts index d7a056e0..df4f7d96 100644 --- a/test/unit/settings/telemetry.test.ts +++ b/test/unit/settings/telemetry.test.ts @@ -3,7 +3,7 @@ import { beforeEach, describe, expect, it } from "vitest"; import { HTTP_REQUESTS_TELEMETRY_DEFAULTS, LOCAL_SINK_DEFAULTS, - LOCAL_SINK_SETTING, + LOCAL_TELEMETRY_SETTING, TELEMETRY_LEVEL_SETTING, readHttpRequestsTelemetryConfig, readLocalSinkConfig, @@ -46,7 +46,7 @@ describe("telemetry settings", () => { ["null", null], ["an array", [1, 2]], ])("returns defaults when the raw value is %s", (_, raw) => { - config.set(LOCAL_SINK_SETTING, raw); + config.set(LOCAL_TELEMETRY_SETTING, raw); expect(readLocalSinkConfig(config)).toEqual(LOCAL_SINK_DEFAULTS); }); @@ -59,7 +59,7 @@ describe("telemetry settings", () => { maxAgeDays: 7, maxTotalBytes: 8192, }; - config.set(LOCAL_SINK_SETTING, custom); + config.set(LOCAL_TELEMETRY_SETTING, custom); expect(readLocalSinkConfig(config)).toEqual(custom); }); @@ -70,14 +70,14 @@ describe("telemetry settings", () => { ["a numeric string", "100"], ["a boolean", true], ])("falls back per-field when a value is %s", (_, bad) => { - config.set(LOCAL_SINK_SETTING, { flushIntervalMs: bad }); + config.set(LOCAL_TELEMETRY_SETTING, { flushIntervalMs: bad }); expect(readLocalSinkConfig(config).flushIntervalMs).toBe( LOCAL_SINK_DEFAULTS.flushIntervalMs, ); }); it("merges valid fields with defaults for invalid ones", () => { - config.set(LOCAL_SINK_SETTING, { + config.set(LOCAL_TELEMETRY_SETTING, { flushIntervalMs: 5_000, flushBatchSize: -1, }); @@ -88,7 +88,7 @@ describe("telemetry settings", () => { }); it("returns bufferLimit and flushBatchSize as written, without clamping", () => { - config.set(LOCAL_SINK_SETTING, { + config.set(LOCAL_TELEMETRY_SETTING, { flushBatchSize: 200, bufferLimit: 50, }); @@ -112,14 +112,14 @@ describe("telemetry settings", () => { ["null", null], ["an array", [1, 2]], ])("returns defaults when the raw value is %s", (_, raw) => { - config.set(LOCAL_SINK_SETTING, raw); + config.set(LOCAL_TELEMETRY_SETTING, raw); expect(readHttpRequestsTelemetryConfig(config)).toEqual( HTTP_REQUESTS_TELEMETRY_DEFAULTS, ); }); it("accepts a fully-specified object", () => { - config.set(LOCAL_SINK_SETTING, { + config.set(LOCAL_TELEMETRY_SETTING, { httpRequests: { windowSeconds: 10 }, }); expect(readHttpRequestsTelemetryConfig(config)).toEqual({ @@ -134,7 +134,7 @@ describe("telemetry settings", () => { ["a numeric string", "100"], ["a boolean", true], ])("falls back per-field when a value is %s", (_, bad) => { - config.set(LOCAL_SINK_SETTING, { + config.set(LOCAL_TELEMETRY_SETTING, { httpRequests: { windowSeconds: bad }, }); expect(readHttpRequestsTelemetryConfig(config).windowSeconds).toBe( @@ -143,7 +143,7 @@ describe("telemetry settings", () => { }); it("ignores invalid httpRequests values", () => { - config.set(LOCAL_SINK_SETTING, { httpRequests: "nope" }); + config.set(LOCAL_TELEMETRY_SETTING, { httpRequests: "nope" }); expect(readHttpRequestsTelemetryConfig(config)).toEqual( HTTP_REQUESTS_TELEMETRY_DEFAULTS, ); From ad0e536971b56cc5c69193e7ca918fffc0709961 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 11 May 2026 15:18:15 +0300 Subject: [PATCH 3/5] refactor(telemetry): simplify http request rollup MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Drop the recorder interface, noop sentinels, and creation helper — construct HttpRequestsTelemetry unconditionally and let the noop reporter swallow .log() calls. Flatten route normalization rules, switch buckets to a nested map (no string key encoding), and stop pushing zero-duration samples when metadata is absent so p95 isn't skewed. Drop the LOCAL_SINK_SETTING backwards-compat alias. --- src/api/coderApi.ts | 41 +-- src/logging/httpRequestsTelemetry.ts | 288 ++++++--------- src/settings/telemetry.ts | 1 - src/telemetry/sinks/localJsonlSink.ts | 6 +- test/unit/api/coderApi.test.ts | 77 ++-- .../logging/httpRequestsTelemetry.test.ts | 335 ++++++++++-------- .../telemetry/sinks/localJsonlSink.test.ts | 9 +- 7 files changed, 350 insertions(+), 407 deletions(-) diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index 3c93b4f5..4cd840ea 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -20,11 +20,7 @@ import { logRequest, logResponse, } from "../logging/httpLogger"; -import { - HttpRequestsTelemetry, - NOOP_HTTP_REQUESTS_TELEMETRY, - type HttpRequestsTelemetryRecorder, -} from "../logging/httpRequestsTelemetry"; +import { HttpRequestsTelemetry } from "../logging/httpRequestsTelemetry"; import { HttpClientLogLevel, type RequestConfigWithMeta, @@ -74,10 +70,6 @@ import type { const coderSessionTokenHeader = "Coder-Session-Token"; -const NOOP_DISPOSABLE: vscode.Disposable = { - dispose: () => undefined, -}; - /** * Configuration settings that affect WebSocket connections. * Changes to these settings will trigger WebSocket reconnection. @@ -109,7 +101,7 @@ export class CoderApi extends Api implements vscode.Disposable { private constructor( private readonly output: Logger, - private readonly httpRequestsTelemetry: HttpRequestsTelemetryRecorder, + private readonly httpRequestsTelemetry: HttpRequestsTelemetry, ) { super(); this.configWatcher = this.watchConfigChanges(); @@ -126,7 +118,10 @@ export class CoderApi extends Api implements vscode.Disposable { output: Logger, telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ): CoderApi { - const httpRequestsTelemetry = createHttpRequestsTelemetry(telemetry); + const httpRequestsTelemetry = new HttpRequestsTelemetry( + telemetry, + readHttpRequestsTelemetryConfig(vscode.workspace.getConfiguration()), + ); const client = new CoderApi(output, httpRequestsTelemetry); client.setCredentials(baseUrl, token); @@ -217,10 +212,6 @@ export class CoderApi extends Api implements vscode.Disposable { } private watchHttpRequestsConfigChanges(): vscode.Disposable { - if (this.httpRequestsTelemetry === NOOP_HTTP_REQUESTS_TELEMETRY) { - return NOOP_DISPOSABLE; - } - return watchConfigurationChanges( [ { @@ -525,26 +516,10 @@ export class CoderApi extends Api implements vscode.Disposable { } } -/** - * Set up logging and request interceptors for the CoderApi instance. - */ -function createHttpRequestsTelemetry( - telemetry: TelemetryReporter, -): HttpRequestsTelemetryRecorder { - if (telemetry === NOOP_TELEMETRY_REPORTER) { - return NOOP_HTTP_REQUESTS_TELEMETRY; - } - - return new HttpRequestsTelemetry( - telemetry, - readHttpRequestsTelemetryConfig(vscode.workspace.getConfiguration()), - ); -} - function setupInterceptors( client: CoderApi, output: Logger, - httpRequestsTelemetry: HttpRequestsTelemetryRecorder, + httpRequestsTelemetry: HttpRequestsTelemetry, ): void { addLoggingInterceptors( client.getAxiosInstance(), @@ -601,7 +576,7 @@ function setupInterceptors( function addLoggingInterceptors( client: AxiosInstance, logger: Logger, - httpRequestsTelemetry: HttpRequestsTelemetryRecorder, + httpRequestsTelemetry: HttpRequestsTelemetry, ) { client.interceptors.request.use( (config) => { diff --git a/src/logging/httpRequestsTelemetry.ts b/src/logging/httpRequestsTelemetry.ts index 1471abea..e0f4cd4c 100644 --- a/src/logging/httpRequestsTelemetry.ts +++ b/src/logging/httpRequestsTelemetry.ts @@ -14,76 +14,33 @@ const UNKNOWN_ROUTE = ""; const ID_PLACEHOLDER = "{id}"; const NAME_PLACEHOLDER = "{name}"; -type Placeholder = typeof ID_PLACEHOLDER | typeof NAME_PLACEHOLDER; -type RouteNormalizationRule = readonly string[]; - -const route = (...segments: RouteNormalizationRule): RouteNormalizationRule => - segments; - -const ID_RESOURCE_ROUTES = [ - "aibridge/sessions", - "files", - "groups", - "licenses", - "oauth2-provider/apps", - "templates", - "templateversions", - "workspaceagents", - "workspacebuilds", - "workspaces", -] as const; - -export const ROUTE_NORMALIZATION_RULES: readonly RouteNormalizationRule[] = [ - route("api", "v2", "users", NAME_PLACEHOLDER, "workspace", NAME_PLACEHOLDER), - route("api", "v2", "users", NAME_PLACEHOLDER, "keys", ID_PLACEHOLDER), - route("api", "v2", "users", NAME_PLACEHOLDER), - route("api", "v2", "tasks", NAME_PLACEHOLDER, ID_PLACEHOLDER), - route("api", "v2", "tasks", NAME_PLACEHOLDER), - route( - "api", - "v2", - "organizations", - ID_PLACEHOLDER, - "templates", - NAME_PLACEHOLDER, - "versions", - NAME_PLACEHOLDER, - ), - route( - "api", - "v2", - "organizations", - ID_PLACEHOLDER, - "templates", - NAME_PLACEHOLDER, - ), - route( - "api", - "v2", - "organizations", - ID_PLACEHOLDER, - "groups", - NAME_PLACEHOLDER, - ), - route("api", "v2", "organizations", ID_PLACEHOLDER), - ...ID_RESOURCE_ROUTES.map((resource) => - route("api", "v2", ...resource.split("/"), ID_PLACEHOLDER), - ), -]; + +export const ROUTE_NORMALIZATION_RULES: ReadonlyArray = [ + "api/v2/users/{name}/workspace/{name}", + "api/v2/users/{name}/keys/{id}", + "api/v2/users/{name}", + "api/v2/tasks/{name}/{id}", + "api/v2/tasks/{name}", + "api/v2/organizations/{id}/templates/{name}/versions/{name}", + "api/v2/organizations/{id}/templates/{name}", + "api/v2/organizations/{id}/groups/{name}", + "api/v2/organizations/{id}", + "api/v2/aibridge/sessions/{id}", + "api/v2/files/{id}", + "api/v2/groups/{id}", + "api/v2/licenses/{id}", + "api/v2/oauth2-provider/apps/{id}", + "api/v2/templates/{id}", + "api/v2/templateversions/{id}", + "api/v2/workspaceagents/{id}", + "api/v2/workspacebuilds/{id}", + "api/v2/workspaces/{id}", +].map((rule) => rule.split("/")); const UUID = /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i; const NUMERIC = /^\d+$/; -interface HttpRequestTelemetrySample { - readonly method?: string; - readonly url?: string; - readonly baseURL?: string; - readonly statusCode?: number; - readonly networkError?: boolean; - readonly durationMs?: number; -} - interface HttpRequestBucket { count2xx: number; count3xx: number; @@ -93,25 +50,12 @@ interface HttpRequestBucket { durationsMs: number[]; } -export interface HttpRequestsTelemetryRecorder extends Disposable { - recordResponse(response: AxiosResponse): void; - recordError(error: unknown): void; - updateConfig(config: HttpRequestsTelemetryConfig): void; -} - -export const NOOP_HTTP_REQUESTS_TELEMETRY: HttpRequestsTelemetryRecorder = { - recordResponse: () => undefined, - recordError: () => undefined, - updateConfig: () => undefined, - dispose: () => undefined, -}; - -export class HttpRequestsTelemetry implements HttpRequestsTelemetryRecorder { +export class HttpRequestsTelemetry implements Disposable { readonly #telemetry: TelemetryReporter; #windowSeconds: number; #timer: NodeJS.Timeout | null = null; #disposed = false; - readonly #buckets = new Map(); + readonly #buckets = new Map>(); public constructor( telemetry: TelemetryReporter, @@ -132,55 +76,22 @@ export class HttpRequestsTelemetry implements HttpRequestsTelemetryRecorder { } public recordResponse(response: AxiosResponse): void { - this.#record({ - method: response.config.method, - url: response.config.url, - baseURL: response.config.baseURL, - statusCode: response.status, - durationMs: durationFromConfig(response.config), - }); + this.#record( + response.config as RequestConfigWithMeta, + response.status, + false, + ); } public recordError(error: unknown): void { - if (!isAxiosError(error)) { + if (!isAxiosError(error) || !error.config) { return; } - - const config = error.config as RequestConfigWithMeta | undefined; - if (!config) { - return; - } - - this.#record({ - method: config.method, - url: config.url, - baseURL: config.baseURL, - statusCode: error.response?.status, - networkError: !error.response, - durationMs: durationFromConfig(config), - }); - } - - #flush(): void { - const buckets = [...this.#buckets.entries()]; - this.#buckets.clear(); - for (const [key, bucket] of buckets) { - const { method, route: normalizedRoute } = parseBucketKey(key); - this.#telemetry.log( - EVENT_NAME, - { method, route: normalizedRoute }, - { - window_seconds: this.#windowSeconds, - count_2xx: bucket.count2xx, - count_3xx: bucket.count3xx, - count_4xx: bucket.count4xx, - count_5xx: bucket.count5xx, - count_network_error: bucket.countNetworkError, - avg_duration_ms: average(bucket.durationsMs), - p95_duration_ms: percentile95(bucket.durationsMs), - }, - ); - } + this.#record( + error.config as RequestConfigWithMeta, + error.response?.status, + !error.response, + ); } public dispose(): void { @@ -192,32 +103,27 @@ export class HttpRequestsTelemetry implements HttpRequestsTelemetryRecorder { this.#buckets.clear(); } - #record(sample: HttpRequestTelemetrySample): void { + #record( + config: RequestConfigWithMeta, + statusCode: number | undefined, + networkError: boolean, + ): void { if (this.#disposed) { return; } - const method = formatMethod(sample.method); - const normalizedRoute = normalizeHttpRoute(sample.url, sample.baseURL); - const key = bucketKey(method, normalizedRoute); - const bucket = this.#buckets.get(key) ?? createBucket(); - this.#buckets.set(key, bucket); - - const durationMs = sanitizeDuration(sample.durationMs); - bucket.durationsMs.push(durationMs); + const method = formatMethod(config.method); + const route = normalizeHttpRoute(config.url, config.baseURL); + const bucket = this.#getOrCreateBucket(method, route); - if (sample.networkError) { - bucket.countNetworkError += 1; - return; + const durationMs = elapsedMs(config); + if (durationMs !== undefined) { + bucket.durationsMs.push(durationMs); } - const statusCode = sample.statusCode; - if (statusCode === undefined) { + if (networkError || statusCode === undefined) { bucket.countNetworkError += 1; - return; - } - - if (statusCode >= 200 && statusCode < 300) { + } else if (statusCode >= 200 && statusCode < 300) { bucket.count2xx += 1; } else if (statusCode >= 300 && statusCode < 400) { bucket.count3xx += 1; @@ -230,6 +136,49 @@ export class HttpRequestsTelemetry implements HttpRequestsTelemetryRecorder { } } + #getOrCreateBucket(method: string, route: string): HttpRequestBucket { + let byRoute = this.#buckets.get(method); + if (!byRoute) { + byRoute = new Map(); + this.#buckets.set(method, byRoute); + } + let bucket = byRoute.get(route); + if (!bucket) { + bucket = { + count2xx: 0, + count3xx: 0, + count4xx: 0, + count5xx: 0, + countNetworkError: 0, + durationsMs: [], + }; + byRoute.set(route, bucket); + } + return bucket; + } + + #flush(): void { + for (const [method, byRoute] of this.#buckets) { + for (const [route, bucket] of byRoute) { + this.#telemetry.log( + EVENT_NAME, + { method, route }, + { + window_seconds: this.#windowSeconds, + count_2xx: bucket.count2xx, + count_3xx: bucket.count3xx, + count_4xx: bucket.count4xx, + count_5xx: bucket.count5xx, + count_network_error: bucket.countNetworkError, + avg_duration_ms: average(bucket.durationsMs), + p95_duration_ms: percentile95(bucket.durationsMs), + }, + ); + } + } + this.#buckets.clear(); + } + #scheduleNextWindow(): void { if (this.#timer) { clearTimeout(this.#timer); @@ -239,8 +188,11 @@ export class HttpRequestsTelemetry implements HttpRequestsTelemetryRecorder { return; } this.#timer = setTimeout(() => { - this.#flush(); - this.#scheduleNextWindow(); + try { + this.#flush(); + } finally { + this.#scheduleNextWindow(); + } }, this.#windowSeconds * 1000); } } @@ -269,7 +221,7 @@ export function normalizeHttpRoute( function normalizeByRule( segments: readonly string[], - rule: RouteNormalizationRule, + rule: readonly string[], ): string | undefined { if (segments.length < rule.length) { return undefined; @@ -277,7 +229,7 @@ function normalizeByRule( const normalized: string[] = []; for (const [index, ruleSegment] of rule.entries()) { - if (isPlaceholder(ruleSegment)) { + if (ruleSegment === ID_PLACEHOLDER || ruleSegment === NAME_PLACEHOLDER) { normalized.push(ruleSegment); continue; } @@ -303,51 +255,31 @@ function parsePathSegments(url: string, baseURL?: string): string[] { } } -function isPlaceholder(segment: string): segment is Placeholder { - return segment === ID_PLACEHOLDER || segment === NAME_PLACEHOLDER; -} - function normalizeIdSegment(segment: string): string { return UUID.test(segment) || NUMERIC.test(segment) ? ID_PLACEHOLDER : segment; } -function durationFromConfig(config: RequestConfigWithMeta | undefined): number { +function elapsedMs( + config: RequestConfigWithMeta | undefined, +): number | undefined { const startedAt = config?.metadata?.startedAt; - return typeof startedAt === "number" ? Date.now() - startedAt : 0; -} - -function sanitizeDuration(durationMs: number | undefined): number { - return typeof durationMs === "number" && Number.isFinite(durationMs) - ? Math.max(0, durationMs) - : 0; -} - -function createBucket(): HttpRequestBucket { - return { - count2xx: 0, - count3xx: 0, - count4xx: 0, - count5xx: 0, - countNetworkError: 0, - durationsMs: [], - }; + return typeof startedAt === "number" + ? Math.max(0, Date.now() - startedAt) + : undefined; } function average(values: readonly number[]): number { + if (values.length === 0) { + return 0; + } return values.reduce((sum, value) => sum + value, 0) / values.length; } function percentile95(values: readonly number[]): number { + if (values.length === 0) { + return 0; + } const sorted = [...values].sort((a, b) => a - b); const index = Math.ceil(sorted.length * 0.95) - 1; return sorted[Math.max(0, index)]; } - -function bucketKey(method: string, route: string): string { - return `${method}\n${route}`; -} - -function parseBucketKey(key: string): { method: string; route: string } { - const [method, route] = key.split("\n", 2); - return { method, route }; -} diff --git a/src/settings/telemetry.ts b/src/settings/telemetry.ts index 8f1417c1..75c9ad1a 100644 --- a/src/settings/telemetry.ts +++ b/src/settings/telemetry.ts @@ -4,7 +4,6 @@ import type { TelemetryLevel } from "../telemetry/event"; export const TELEMETRY_LEVEL_SETTING = "coder.telemetry.level"; export const LOCAL_TELEMETRY_SETTING = "coder.telemetry.local"; -export const LOCAL_SINK_SETTING = LOCAL_TELEMETRY_SETTING; /** Telemetry level. Falls back to `local` for unknown or invalid values. */ export function readTelemetryLevel( diff --git a/src/telemetry/sinks/localJsonlSink.ts b/src/telemetry/sinks/localJsonlSink.ts index 3cfe94ad..5ac7fbb3 100644 --- a/src/telemetry/sinks/localJsonlSink.ts +++ b/src/telemetry/sinks/localJsonlSink.ts @@ -4,7 +4,7 @@ import * as vscode from "vscode"; import { watchConfigurationChanges } from "../../configWatcher"; import { - LOCAL_SINK_SETTING, + LOCAL_TELEMETRY_SETTING, readLocalSinkConfig, type LocalSinkConfig, } from "../../settings/telemetry"; @@ -148,13 +148,13 @@ export class LocalJsonlSink implements TelemetrySink, vscode.Disposable { return watchConfigurationChanges( [ { - setting: LOCAL_SINK_SETTING, + setting: LOCAL_TELEMETRY_SETTING, getValue: () => readLocalSinkConfig(vscode.workspace.getConfiguration()), }, ], (changes) => { - const next = changes.get(LOCAL_SINK_SETTING) as + const next = changes.get(LOCAL_TELEMETRY_SETTING) as | LocalSinkConfig | undefined; if (!next) { diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index cb07bcd0..ccbc7d20 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -126,7 +126,6 @@ describe("CoderApi", () => { }); afterEach(() => { - // Dispose any api created during the test to clean up config watchers api?.dispose(); vi.useRealTimers(); }); @@ -241,53 +240,41 @@ describe("CoderApi", () => { ); }); - it("rolls HTTP responses into telemetry when telemetry is provided", async () => { - vi.useFakeTimers(); - mockConfig.set(LOCAL_TELEMETRY_SETTING, { - httpRequests: { windowSeconds: 1 }, - }); - const log = vi.fn(); - api = createApi(CODER_URL, AXIOS_TOKEN, { - ...NOOP_TELEMETRY_REPORTER, - log, - }); - - await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); - await vi.advanceTimersByTimeAsync(1000); - - expect(log).toHaveBeenCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ - window_seconds: 1, - count_2xx: 1, - }), - ); - }); + it.each([ + ["initial config", 1, undefined], + ["after config change", 10, 1], + ])( + "rolls HTTP responses into telemetry (%s)", + async (_, initialWindow, updatedWindow) => { + vi.useFakeTimers(); + mockConfig.set(LOCAL_TELEMETRY_SETTING, { + httpRequests: { windowSeconds: initialWindow }, + }); + const log = vi.fn(); + api = createApi(CODER_URL, AXIOS_TOKEN, { + ...NOOP_TELEMETRY_REPORTER, + log, + }); - it("updates HTTP telemetry window from configuration changes", async () => { - vi.useFakeTimers(); - mockConfig.set(LOCAL_TELEMETRY_SETTING, { - httpRequests: { windowSeconds: 10 }, - }); - const log = vi.fn(); - api = createApi(CODER_URL, AXIOS_TOKEN, { - ...NOOP_TELEMETRY_REPORTER, - log, - }); + if (updatedWindow !== undefined) { + mockConfig.set(LOCAL_TELEMETRY_SETTING, { + httpRequests: { windowSeconds: updatedWindow }, + }); + } - mockConfig.set(LOCAL_TELEMETRY_SETTING, { - httpRequests: { windowSeconds: 1 }, - }); - await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); - await vi.advanceTimersByTimeAsync(1000); + await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); + await vi.advanceTimersByTimeAsync(1000); - expect(log).toHaveBeenCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ window_seconds: 1 }), - ); - }); + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + window_seconds: updatedWindow ?? initialWindow, + count_2xx: 1, + }), + ); + }, + ); describe("certificate refresh and retry", () => { const rejectWithCertError = ( diff --git a/test/unit/logging/httpRequestsTelemetry.test.ts b/test/unit/logging/httpRequestsTelemetry.test.ts index 7a0508a9..7636b10b 100644 --- a/test/unit/logging/httpRequestsTelemetry.test.ts +++ b/test/unit/logging/httpRequestsTelemetry.test.ts @@ -1,5 +1,13 @@ import { AxiosError, AxiosHeaders, type AxiosResponse } from "axios"; -import { afterEach, describe, expect, it, vi } from "vitest"; +import { + afterEach, + beforeEach, + describe, + expect, + it, + type Mock, + vi, +} from "vitest"; import { HttpRequestsTelemetry, @@ -12,11 +20,6 @@ import { import type { RequestConfigWithMeta } from "@/logging/types"; -interface Harness { - rollup: HttpRequestsTelemetry; - log: ReturnType; -} - interface RequestOptions { readonly method?: string; readonly url: string; @@ -25,129 +28,187 @@ interface RequestOptions { } describe("HttpRequestsTelemetry", () => { - afterEach(() => vi.useRealTimers()); + let log: Mock; + let rollup: HttpRequestsTelemetry; + + const start = (windowSeconds: number) => { + const reporter: TelemetryReporter = { ...NOOP_TELEMETRY_REPORTER, log }; + rollup = new HttpRequestsTelemetry(reporter, { windowSeconds }); + return rollup; + }; + + beforeEach(() => { + vi.useFakeTimers(); + log = vi.fn(); + }); + + afterEach(() => { + rollup?.dispose(); + vi.useRealTimers(); + }); it("emits one event per active method and route at the window boundary", async () => { - const { rollup, log } = createHarness(2); - try { - recordResponse(rollup, { - method: "get", - url: "/api/v2/workspaces/abc-123?owner=danny", - status: 200, - durationMs: 100, - }); - recordResponse(rollup, { - method: "GET", - url: "/api/v2/workspaces/abc-123?owner=someone-else", - status: 204, - durationMs: 200, - }); - recordResponse(rollup, { - method: "POST", - url: "/api/v2/workspaces/abc-123", - status: 201, - durationMs: 300, - }); + start(2); + recordResponse(rollup, { + method: "get", + url: "/api/v2/workspaces/abc-123?owner=danny", + status: 200, + durationMs: 100, + }); + recordResponse(rollup, { + method: "GET", + url: "/api/v2/workspaces/abc-123?owner=someone-else", + status: 204, + durationMs: 200, + }); + recordResponse(rollup, { + method: "POST", + url: "/api/v2/workspaces/abc-123", + status: 201, + durationMs: 300, + }); - await vi.advanceTimersByTimeAsync(2000); - - expect(log).toHaveBeenCalledTimes(2); - expect(log).toHaveBeenNthCalledWith( - 1, - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - { - window_seconds: 2, - count_2xx: 2, - count_3xx: 0, - count_4xx: 0, - count_5xx: 0, - count_network_error: 0, - avg_duration_ms: 150, - p95_duration_ms: 200, - }, - ); - expect(log).toHaveBeenNthCalledWith( - 2, - "http.requests", - { method: "POST", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ - window_seconds: 2, - count_2xx: 1, - }), - ); - } finally { - rollup.dispose(); - } + await vi.advanceTimersByTimeAsync(2000); + + expect(log).toHaveBeenCalledTimes(2); + expect(log).toHaveBeenNthCalledWith( + 1, + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + { + window_seconds: 2, + count_2xx: 2, + count_3xx: 0, + count_4xx: 0, + count_5xx: 0, + count_network_error: 0, + avg_duration_ms: 150, + p95_duration_ms: 200, + }, + ); + expect(log).toHaveBeenNthCalledWith( + 2, + "http.requests", + { method: "POST", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ window_seconds: 2, count_2xx: 1 }), + ); }); it("counts status code classes and network errors", async () => { - const { rollup, log } = createHarness(1); - try { - const route = "/api/v2/users/danny/workspaces"; - recordResponse(rollup, { method: "POST", url: route, status: 201 }); - recordResponse(rollup, { method: "POST", url: route, status: 302 }); - recordAxiosError(rollup, { method: "POST", url: route, status: 404 }); - recordAxiosError(rollup, { method: "POST", url: route, status: 500 }); - recordAxiosError(rollup, { method: "POST", url: route }); - - await vi.advanceTimersByTimeAsync(1000); - - expect(log).toHaveBeenCalledWith( - "http.requests", - { method: "POST", route: "/api/v2/users/{name}/workspaces" }, - expect.objectContaining({ - count_2xx: 1, - count_3xx: 1, - count_4xx: 1, - count_5xx: 1, - count_network_error: 1, - }), - ); - } finally { - rollup.dispose(); - } + start(1); + const route = "/api/v2/users/danny/workspaces"; + recordResponse(rollup, { method: "POST", url: route, status: 201 }); + recordResponse(rollup, { method: "POST", url: route, status: 302 }); + recordAxiosError(rollup, { method: "POST", url: route, status: 404 }); + recordAxiosError(rollup, { method: "POST", url: route, status: 500 }); + recordAxiosError(rollup, { method: "POST", url: route }); + + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "POST", route: "/api/v2/users/{name}/workspaces" }, + expect.objectContaining({ + count_2xx: 1, + count_3xx: 1, + count_4xx: 1, + count_5xx: 1, + count_network_error: 1, + }), + ); }); it("emits nothing for empty windows", async () => { - const { rollup, log } = createHarness(1); - try { - await vi.advanceTimersByTimeAsync(2000); - - expect(log).not.toHaveBeenCalled(); - } finally { - rollup.dispose(); - } + start(1); + await vi.advanceTimersByTimeAsync(2000); + expect(log).not.toHaveBeenCalled(); }); it("calculates nearest-rank p95", async () => { - const { rollup, log } = createHarness(1); - try { - for (const durationMs of [ - 10, 20, 30, 40, 50, 60, 70, 80, 90, 100, 110, 120, 130, 140, 150, 160, - 170, 180, 190, 200, - ]) { - recordResponse(rollup, { - method: "GET", - url: "/api/v2/workspaces/ws-id", - status: 200, - durationMs, - }); - } - - await vi.advanceTimersByTimeAsync(1000); - - expect(log).toHaveBeenCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ - avg_duration_ms: 105, - p95_duration_ms: 190, - }), - ); - } finally { - rollup.dispose(); + start(1); + for (let durationMs = 10; durationMs <= 200; durationMs += 10) { + recordResponse(rollup, { + method: "GET", + url: "/api/v2/workspaces/ws-id", + status: 200, + durationMs, + }); } + + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ avg_duration_ms: 105, p95_duration_ms: 190 }), + ); + }); + + it("skips duration when request metadata is missing", async () => { + start(1); + rollup.recordResponse({ + data: {}, + status: 200, + statusText: "OK", + headers: {}, + config: { + headers: new AxiosHeaders(), + method: "GET", + url: "/api/v2/workspaces/abc", + }, + } as AxiosResponse); + + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + count_2xx: 1, + avg_duration_ms: 0, + p95_duration_ms: 0, + }), + ); + }); + + it("re-flushes and reschedules after updateConfig changes the window", async () => { + start(10); + recordResponse(rollup, { + method: "GET", + url: "/api/v2/workspaces/abc", + status: 200, + }); + + rollup.updateConfig({ windowSeconds: 1 }); + + // updateConfig flushes pending buckets immediately under the old window. + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ window_seconds: 10 }), + ); + + recordResponse(rollup, { + method: "GET", + url: "/api/v2/workspaces/abc", + status: 200, + }); + await vi.advanceTimersByTimeAsync(1000); + + expect(log).toHaveBeenLastCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ window_seconds: 1 }), + ); + }); + + it("ignores non-axios errors", async () => { + start(1); + rollup.recordError(new Error("not an axios error")); + rollup.recordError("string error"); + + await vi.advanceTimersByTimeAsync(1000); + expect(log).not.toHaveBeenCalled(); }); it.each([ @@ -176,26 +237,17 @@ describe("HttpRequestsTelemetry", () => { }); }); -function createHarness(windowSeconds = 60): Harness { - vi.useFakeTimers(); - vi.setSystemTime(new Date("2025-01-01T00:00:00.000Z")); - - const log = vi.fn(); - const reporter: TelemetryReporter = { - ...NOOP_TELEMETRY_REPORTER, - log, - }; - return { - rollup: new HttpRequestsTelemetry(reporter, { windowSeconds }), - log, - }; -} - function recordResponse( rollup: HttpRequestsTelemetry, options: RequestOptions, ): void { - rollup.recordResponse(makeResponse(options)); + rollup.recordResponse({ + data: {}, + status: options.status ?? 200, + statusText: "", + headers: {}, + config: makeRequestConfig(options), + } as AxiosResponse); } function recordAxiosError( @@ -204,24 +256,19 @@ function recordAxiosError( ): void { const config = makeRequestConfig(options); const response = options.status - ? makeResponse({ ...options, status: options.status }) + ? ({ + data: {}, + status: options.status, + statusText: "", + headers: {}, + config, + } as AxiosResponse) : undefined; rollup.recordError( new AxiosError("Request failed", undefined, config, {}, response), ); } -function makeResponse(options: RequestOptions): AxiosResponse { - const status = options.status ?? 200; - return { - data: {}, - status, - statusText: String(status), - headers: {}, - config: makeRequestConfig(options), - }; -} - function makeRequestConfig(options: RequestOptions): RequestConfigWithMeta { return { headers: new AxiosHeaders(), diff --git a/test/unit/telemetry/sinks/localJsonlSink.test.ts b/test/unit/telemetry/sinks/localJsonlSink.test.ts index 55da1ddf..745bac6c 100644 --- a/test/unit/telemetry/sinks/localJsonlSink.test.ts +++ b/test/unit/telemetry/sinks/localJsonlSink.test.ts @@ -2,7 +2,10 @@ import { vol } from "memfs"; import * as fsPromises from "node:fs/promises"; import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; -import { LOCAL_SINK_SETTING, type LocalSinkConfig } from "@/settings/telemetry"; +import { + LOCAL_TELEMETRY_SETTING, + type LocalSinkConfig, +} from "@/settings/telemetry"; import { LocalJsonlSink } from "@/telemetry/sinks/localJsonlSink"; import { @@ -67,7 +70,7 @@ describe("LocalJsonlSink", () => { config: Partial = {}, sessionId = SESSION_ID, ) { - provider.set(LOCAL_SINK_SETTING, { + provider.set(LOCAL_TELEMETRY_SETTING, { flushIntervalMs: 1_000_000, ...config, }); @@ -420,7 +423,7 @@ describe("LocalJsonlSink", () => { sink.write(makeEvent()); expect(vol.existsSync(todaysFile())).toBe(false); - provider.set(LOCAL_SINK_SETTING, { + provider.set(LOCAL_TELEMETRY_SETTING, { flushIntervalMs: 1_000_000, flushBatchSize: 3, }); From 603ec1da274e648fe7be7ef90360d728b2c9ad03 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Mon, 11 May 2026 18:09:11 +0300 Subject: [PATCH 4/5] fix(telemetry): address PR #946 review comments - Drop UUID and numeric heuristics from route normalization. Use explicit rules only; add api/v2/workspaces/{id}/builds/{id} for the main composite path. Trailing literal segments still pass through. - Add a rule for api/v2/organizations/{id}/members/{name}. - Flush the pending bucket on dispose so the last partial window is not lost. Wrap the flush in try/finally so a throw still clears state. - Track the start of each window and emit the actual elapsed seconds in the http.requests event so consumers can compute a real rate. - Skip the timer when constructed with NOOP_TELEMETRY_REPORTER so throwaway CoderApi clients don't leak it. - Drop the coder.telemetry.local.httpRequests.windowSeconds knob and hardcode 60s, removing the schema, reader, watcher, update method, and related tests. - Rename addLoggingInterceptors to addRequestInterceptors. Note that cert-refresh retries re-enter the chain, so each attempt is counted. - toSorted, drop the unused export, document the public surface. - Drop "aggregated" from the CHANGELOG entry. - Tests: dispose-flush, NOOP timer-leak guard, no-rule fallback, undefined / "" inputs. --- CHANGELOG.md | 4 +- package.json | 21 +---- src/api/coderApi.ts | 44 ++-------- src/logging/httpRequestsTelemetry.ts | 85 +++++++++---------- src/settings/telemetry.ts | 34 +------- src/telemetry/reporter.ts | 4 + test/unit/api/coderApi.test.ts | 53 +++++------- .../logging/httpRequestsTelemetry.test.ts | 83 ++++++++++-------- test/unit/settings/telemetry.test.ts | 53 ------------ 9 files changed, 122 insertions(+), 259 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 80ee1b0f..0c556163 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -21,8 +21,8 @@ binary download/verify now emit local telemetry events with their duration and outcome, so startup latency and failures are captured alongside other local telemetry. -- Local telemetry now records aggregated `http.requests` rollups for per-route - HTTP health without emitting one event per request. +- Local telemetry now records `http.requests` rollups for per-route HTTP + health without emitting one event per request. ### Fixed diff --git a/package.json b/package.json index f34502ef..5b5d7df8 100644 --- a/package.json +++ b/package.json @@ -250,22 +250,6 @@ "minimum": 4096, "default": 104857600, "markdownDescription": "Cap, in bytes, on the combined size of telemetry files. Oldest files are deleted on activation until the total is under the cap." - }, - "httpRequests": { - "type": "object", - "additionalProperties": false, - "markdownDescription": "Tunables for HTTP request rollup telemetry.", - "properties": { - "windowSeconds": { - "type": "number", - "minimum": 1, - "default": 60, - "markdownDescription": "Tumbling window length, in seconds, for aggregated `http.requests` events." - } - }, - "default": { - "windowSeconds": 60 - } } }, "default": { @@ -274,10 +258,7 @@ "bufferLimit": 500, "maxFileBytes": 5242880, "maxAgeDays": 30, - "maxTotalBytes": 104857600, - "httpRequests": { - "windowSeconds": 60 - } + "maxTotalBytes": 104857600 }, "tags": [ "telemetry" diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index 4cd840ea..751256f2 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -27,11 +27,6 @@ import { } from "../logging/types"; import { sizeOf } from "../logging/utils"; import { getHeaderCommand } from "../settings/headers"; -import { - LOCAL_TELEMETRY_SETTING, - readHttpRequestsTelemetryConfig, - type HttpRequestsTelemetryConfig, -} from "../settings/telemetry"; import { NOOP_TELEMETRY_REPORTER, type TelemetryReporter, @@ -97,7 +92,6 @@ export class CoderApi extends Api implements vscode.Disposable { ReconnectingWebSocket >(); private readonly configWatcher: vscode.Disposable; - private readonly httpRequestsConfigWatcher: vscode.Disposable; private constructor( private readonly output: Logger, @@ -105,12 +99,12 @@ export class CoderApi extends Api implements vscode.Disposable { ) { super(); this.configWatcher = this.watchConfigChanges(); - this.httpRequestsConfigWatcher = this.watchHttpRequestsConfigChanges(); } /** * Create a new CoderApi instance with the provided configuration. - * Automatically sets up logging interceptors and certificate handling. + * Automatically sets up logging interceptors, certificate handling, + * and HTTP request telemetry that emits via the given reporter. */ static create( baseUrl: string, @@ -118,10 +112,7 @@ export class CoderApi extends Api implements vscode.Disposable { output: Logger, telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, ): CoderApi { - const httpRequestsTelemetry = new HttpRequestsTelemetry( - telemetry, - readHttpRequestsTelemetryConfig(vscode.workspace.getConfiguration()), - ); + const httpRequestsTelemetry = new HttpRequestsTelemetry(telemetry); const client = new CoderApi(output, httpRequestsTelemetry); client.setCredentials(baseUrl, token); @@ -177,7 +168,6 @@ export class CoderApi extends Api implements vscode.Disposable { */ dispose(): void { this.configWatcher.dispose(); - this.httpRequestsConfigWatcher.dispose(); this.httpRequestsTelemetry.dispose(); for (const socket of this.reconnectingSockets) { socket.close(); @@ -211,28 +201,6 @@ export class CoderApi extends Api implements vscode.Disposable { }); } - private watchHttpRequestsConfigChanges(): vscode.Disposable { - return watchConfigurationChanges( - [ - { - setting: LOCAL_TELEMETRY_SETTING, - getValue: () => - readHttpRequestsTelemetryConfig( - vscode.workspace.getConfiguration(), - ), - }, - ], - (changes) => { - const config = changes.get(LOCAL_TELEMETRY_SETTING) as - | HttpRequestsTelemetryConfig - | undefined; - if (config) { - this.httpRequestsTelemetry.updateConfig(config); - } - }, - ); - } - watchInboxNotifications = async ( watchTemplates: string[], watchTargets: string[], @@ -521,7 +489,7 @@ function setupInterceptors( output: Logger, httpRequestsTelemetry: HttpRequestsTelemetry, ): void { - addLoggingInterceptors( + addRequestInterceptors( client.getAxiosInstance(), output, httpRequestsTelemetry, @@ -550,7 +518,7 @@ function setupInterceptors( return config; }); - // Wrap certificate errors and handle client certificate errors with refresh. + // Cert-refresh retries re-enter the chain, so each attempt is recorded. client.getAxiosInstance().interceptors.response.use( (r) => r, async (err: unknown) => { @@ -573,7 +541,7 @@ function setupInterceptors( ); } -function addLoggingInterceptors( +function addRequestInterceptors( client: AxiosInstance, logger: Logger, httpRequestsTelemetry: HttpRequestsTelemetry, diff --git a/src/logging/httpRequestsTelemetry.ts b/src/logging/httpRequestsTelemetry.ts index e0f4cd4c..886c4971 100644 --- a/src/logging/httpRequestsTelemetry.ts +++ b/src/logging/httpRequestsTelemetry.ts @@ -1,21 +1,24 @@ import { isAxiosError, type AxiosResponse } from "axios"; +import { + NOOP_TELEMETRY_REPORTER, + type TelemetryReporter, +} from "../telemetry/reporter"; + import { formatMethod } from "./formatters"; import type { Disposable } from "vscode"; -import type { HttpRequestsTelemetryConfig } from "../settings/telemetry"; -import type { TelemetryReporter } from "../telemetry/reporter"; - import type { RequestConfigWithMeta } from "./types"; const EVENT_NAME = "http.requests"; const UNKNOWN_ROUTE = ""; +const WINDOW_SECONDS = 60; const ID_PLACEHOLDER = "{id}"; const NAME_PLACEHOLDER = "{name}"; -export const ROUTE_NORMALIZATION_RULES: ReadonlyArray = [ +const ROUTE_NORMALIZATION_RULES: ReadonlyArray = [ "api/v2/users/{name}/workspace/{name}", "api/v2/users/{name}/keys/{id}", "api/v2/users/{name}", @@ -24,6 +27,7 @@ export const ROUTE_NORMALIZATION_RULES: ReadonlyArray = [ "api/v2/organizations/{id}/templates/{name}/versions/{name}", "api/v2/organizations/{id}/templates/{name}", "api/v2/organizations/{id}/groups/{name}", + "api/v2/organizations/{id}/members/{name}", "api/v2/organizations/{id}", "api/v2/aibridge/sessions/{id}", "api/v2/files/{id}", @@ -34,13 +38,10 @@ export const ROUTE_NORMALIZATION_RULES: ReadonlyArray = [ "api/v2/templateversions/{id}", "api/v2/workspaceagents/{id}", "api/v2/workspacebuilds/{id}", + "api/v2/workspaces/{id}/builds/{id}", "api/v2/workspaces/{id}", ].map((rule) => rule.split("/")); -const UUID = - /^[0-9a-f]{8}-[0-9a-f]{4}-[1-5][0-9a-f]{3}-[89ab][0-9a-f]{3}-[0-9a-f]{12}$/i; -const NUMERIC = /^\d+$/; - interface HttpRequestBucket { count2xx: number; count3xx: number; @@ -50,29 +51,23 @@ interface HttpRequestBucket { durationsMs: number[]; } +/** + * Rolls up HTTP request counts and latencies into "http.requests" events + * every 60 seconds. Construct with NOOP_TELEMETRY_REPORTER to skip the + * timer so throwaway clients don't leak it. + */ export class HttpRequestsTelemetry implements Disposable { readonly #telemetry: TelemetryReporter; - #windowSeconds: number; #timer: NodeJS.Timeout | null = null; #disposed = false; + #windowStartedAt = Date.now(); readonly #buckets = new Map>(); - public constructor( - telemetry: TelemetryReporter, - config: HttpRequestsTelemetryConfig, - ) { + public constructor(telemetry: TelemetryReporter) { this.#telemetry = telemetry; - this.#windowSeconds = config.windowSeconds; - this.#scheduleNextWindow(); - } - - public updateConfig(config: HttpRequestsTelemetryConfig): void { - if (config.windowSeconds === this.#windowSeconds) { - return; + if (telemetry !== NOOP_TELEMETRY_REPORTER) { + this.#scheduleNextWindow(); } - this.#flush(); - this.#windowSeconds = config.windowSeconds; - this.#scheduleNextWindow(); } public recordResponse(response: AxiosResponse): void { @@ -95,12 +90,18 @@ export class HttpRequestsTelemetry implements Disposable { } public dispose(): void { - this.#disposed = true; - if (this.#timer) { - clearTimeout(this.#timer); - this.#timer = null; + if (this.#disposed) { + return; + } + try { + this.#flush(); + } finally { + this.#disposed = true; + if (this.#timer) { + clearTimeout(this.#timer); + this.#timer = null; + } } - this.#buckets.clear(); } #record( @@ -158,13 +159,17 @@ export class HttpRequestsTelemetry implements Disposable { } #flush(): void { + const elapsedSeconds = Math.max( + 1, + Math.round((Date.now() - this.#windowStartedAt) / 1000), + ); for (const [method, byRoute] of this.#buckets) { for (const [route, bucket] of byRoute) { this.#telemetry.log( EVENT_NAME, { method, route }, { - window_seconds: this.#windowSeconds, + window_seconds: elapsedSeconds, count_2xx: bucket.count2xx, count_3xx: bucket.count3xx, count_4xx: bucket.count4xx, @@ -177,13 +182,10 @@ export class HttpRequestsTelemetry implements Disposable { } } this.#buckets.clear(); + this.#windowStartedAt = Date.now(); } #scheduleNextWindow(): void { - if (this.#timer) { - clearTimeout(this.#timer); - this.#timer = null; - } if (this.#disposed) { return; } @@ -193,7 +195,7 @@ export class HttpRequestsTelemetry implements Disposable { } finally { this.#scheduleNextWindow(); } - }, this.#windowSeconds * 1000); + }, WINDOW_SECONDS * 1000); } } @@ -216,7 +218,8 @@ export function normalizeHttpRoute( return normalized; } } - return `/${segments.map(normalizeIdSegment).join("/")}`; + // No matching rule. Pass through; add a rule above if cardinality grows. + return `/${segments.join("/")}`; } function normalizeByRule( @@ -239,10 +242,8 @@ function normalizeByRule( normalized.push(segments[index]); } - return `/${[ - ...normalized, - ...segments.slice(rule.length).map(normalizeIdSegment), - ].join("/")}`; + // Trailing segments pass through. If a tail can hold an ID, add a rule. + return `/${[...normalized, ...segments.slice(rule.length)].join("/")}`; } function parsePathSegments(url: string, baseURL?: string): string[] { @@ -255,10 +256,6 @@ function parsePathSegments(url: string, baseURL?: string): string[] { } } -function normalizeIdSegment(segment: string): string { - return UUID.test(segment) || NUMERIC.test(segment) ? ID_PLACEHOLDER : segment; -} - function elapsedMs( config: RequestConfigWithMeta | undefined, ): number | undefined { @@ -279,7 +276,7 @@ function percentile95(values: readonly number[]): number { if (values.length === 0) { return 0; } - const sorted = [...values].sort((a, b) => a - b); + const sorted = values.toSorted((a, b) => a - b); const index = Math.ceil(sorted.length * 0.95) - 1; return sorted[Math.max(0, index)]; } diff --git a/src/settings/telemetry.ts b/src/settings/telemetry.ts index 75c9ad1a..b700ccef 100644 --- a/src/settings/telemetry.ts +++ b/src/settings/telemetry.ts @@ -22,10 +22,6 @@ export interface LocalSinkConfig { readonly maxTotalBytes: number; } -export interface HttpRequestsTelemetryConfig { - readonly windowSeconds: number; -} - export const LOCAL_SINK_DEFAULTS: LocalSinkConfig = { flushIntervalMs: 15_000, flushBatchSize: 100, @@ -35,10 +31,6 @@ export const LOCAL_SINK_DEFAULTS: LocalSinkConfig = { maxTotalBytes: 100 * 1024 * 1024, }; -export const HTTP_REQUESTS_TELEMETRY_DEFAULTS: HttpRequestsTelemetryConfig = { - windowSeconds: 60, -}; - // Defense in depth: VS Code does not enforce JSON schema at runtime, so users // can drop in any value via settings.json. Mirrors the minimums in package.json. const LOCAL_SINK_MINIMUMS: LocalSinkConfig = { @@ -50,15 +42,11 @@ const LOCAL_SINK_MINIMUMS: LocalSinkConfig = { maxTotalBytes: 4096, }; -const HTTP_REQUESTS_TELEMETRY_MINIMUMS: HttpRequestsTelemetryConfig = { - windowSeconds: 1, -}; - /** Per-field: missing, non-numeric, or below-minimum values fall back to defaults. */ export function readLocalSinkConfig( cfg: Pick, ): LocalSinkConfig { - const obj = readLocalTelemetryObject(cfg); + const obj = readObject(cfg.get(LOCAL_TELEMETRY_SETTING)); const read = (key: keyof LocalSinkConfig): number => readNumber(obj, key, LOCAL_SINK_DEFAULTS[key], LOCAL_SINK_MINIMUMS[key]); return { @@ -71,26 +59,6 @@ export function readLocalSinkConfig( }; } -export function readHttpRequestsTelemetryConfig( - cfg: Pick, -): HttpRequestsTelemetryConfig { - const httpRequests = readObject(readLocalTelemetryObject(cfg).httpRequests); - return { - windowSeconds: readNumber( - httpRequests, - "windowSeconds", - HTTP_REQUESTS_TELEMETRY_DEFAULTS.windowSeconds, - HTTP_REQUESTS_TELEMETRY_MINIMUMS.windowSeconds, - ), - }; -} - -function readLocalTelemetryObject( - cfg: Pick, -): Record { - return readObject(cfg.get(LOCAL_TELEMETRY_SETTING)); -} - function readObject(value: unknown): Record { return value && typeof value === "object" && !Array.isArray(value) ? (value as Record) diff --git a/src/telemetry/reporter.ts b/src/telemetry/reporter.ts index e46811b4..d721670d 100644 --- a/src/telemetry/reporter.ts +++ b/src/telemetry/reporter.ts @@ -2,6 +2,10 @@ import { NOOP_SPAN, type Span } from "./span"; import type { CallerMeasurements, CallerProperties } from "./event"; +/** + * Narrow reporting surface so callers don't have to depend on the full + * TelemetryService. Pass NOOP_TELEMETRY_REPORTER to opt out. + */ export interface TelemetryReporter { log( eventName: string, diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index ccbc7d20..3a22c6da 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -26,7 +26,6 @@ import { createHttpAgent } from "@/api/utils"; import { ClientCertificateError } from "@/error/clientCertificateError"; import { ServerCertificateError } from "@/error/serverCertificateError"; import { getHeaders } from "@/headers"; -import { LOCAL_TELEMETRY_SETTING } from "@/settings/telemetry"; import { NOOP_TELEMETRY_REPORTER, type TelemetryReporter, @@ -240,41 +239,27 @@ describe("CoderApi", () => { ); }); - it.each([ - ["initial config", 1, undefined], - ["after config change", 10, 1], - ])( - "rolls HTTP responses into telemetry (%s)", - async (_, initialWindow, updatedWindow) => { - vi.useFakeTimers(); - mockConfig.set(LOCAL_TELEMETRY_SETTING, { - httpRequests: { windowSeconds: initialWindow }, - }); - const log = vi.fn(); - api = createApi(CODER_URL, AXIOS_TOKEN, { - ...NOOP_TELEMETRY_REPORTER, - log, - }); - - if (updatedWindow !== undefined) { - mockConfig.set(LOCAL_TELEMETRY_SETTING, { - httpRequests: { windowSeconds: updatedWindow }, - }); - } + it("rolls HTTP responses into telemetry", async () => { + vi.useFakeTimers(); + const log = vi.fn(); + api = createApi(CODER_URL, AXIOS_TOKEN, { + ...NOOP_TELEMETRY_REPORTER, + log, + }); - await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); - await vi.advanceTimersByTimeAsync(1000); + await api.getAxiosInstance().get("/api/v2/workspaces/abc-123"); + // WINDOW_SECONDS is 60 in the implementation. + await vi.advanceTimersByTimeAsync(60_000); - expect(log).toHaveBeenCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ - window_seconds: updatedWindow ?? initialWindow, - count_2xx: 1, - }), - ); - }, - ); + expect(log).toHaveBeenCalledWith( + "http.requests", + { method: "GET", route: "/api/v2/workspaces/{id}" }, + expect.objectContaining({ + window_seconds: 60, + count_2xx: 1, + }), + ); + }); describe("certificate refresh and retry", () => { const rejectWithCertError = ( diff --git a/test/unit/logging/httpRequestsTelemetry.test.ts b/test/unit/logging/httpRequestsTelemetry.test.ts index 7636b10b..00263d7a 100644 --- a/test/unit/logging/httpRequestsTelemetry.test.ts +++ b/test/unit/logging/httpRequestsTelemetry.test.ts @@ -27,13 +27,16 @@ interface RequestOptions { readonly durationMs?: number; } +// Mirrors WINDOW_SECONDS in src/logging/httpRequestsTelemetry.ts. +const WINDOW_SECONDS = 60; + describe("HttpRequestsTelemetry", () => { let log: Mock; let rollup: HttpRequestsTelemetry; - const start = (windowSeconds: number) => { + const start = () => { const reporter: TelemetryReporter = { ...NOOP_TELEMETRY_REPORTER, log }; - rollup = new HttpRequestsTelemetry(reporter, { windowSeconds }); + rollup = new HttpRequestsTelemetry(reporter); return rollup; }; @@ -48,7 +51,7 @@ describe("HttpRequestsTelemetry", () => { }); it("emits one event per active method and route at the window boundary", async () => { - start(2); + start(); recordResponse(rollup, { method: "get", url: "/api/v2/workspaces/abc-123?owner=danny", @@ -68,7 +71,7 @@ describe("HttpRequestsTelemetry", () => { durationMs: 300, }); - await vi.advanceTimersByTimeAsync(2000); + await advanceOneWindow(); expect(log).toHaveBeenCalledTimes(2); expect(log).toHaveBeenNthCalledWith( @@ -76,7 +79,7 @@ describe("HttpRequestsTelemetry", () => { "http.requests", { method: "GET", route: "/api/v2/workspaces/{id}" }, { - window_seconds: 2, + window_seconds: WINDOW_SECONDS, count_2xx: 2, count_3xx: 0, count_4xx: 0, @@ -90,12 +93,12 @@ describe("HttpRequestsTelemetry", () => { 2, "http.requests", { method: "POST", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ window_seconds: 2, count_2xx: 1 }), + expect.objectContaining({ count_2xx: 1 }), ); }); it("counts status code classes and network errors", async () => { - start(1); + start(); const route = "/api/v2/users/danny/workspaces"; recordResponse(rollup, { method: "POST", url: route, status: 201 }); recordResponse(rollup, { method: "POST", url: route, status: 302 }); @@ -103,7 +106,7 @@ describe("HttpRequestsTelemetry", () => { recordAxiosError(rollup, { method: "POST", url: route, status: 500 }); recordAxiosError(rollup, { method: "POST", url: route }); - await vi.advanceTimersByTimeAsync(1000); + await advanceOneWindow(); expect(log).toHaveBeenCalledWith( "http.requests", @@ -119,13 +122,25 @@ describe("HttpRequestsTelemetry", () => { }); it("emits nothing for empty windows", async () => { - start(1); - await vi.advanceTimersByTimeAsync(2000); + start(); + await advanceOneWindow(); expect(log).not.toHaveBeenCalled(); }); + it("is inert when constructed with the NOOP reporter", async () => { + // Throwaway clients pass NOOP and may never dispose, so no timer. + rollup = new HttpRequestsTelemetry(NOOP_TELEMETRY_REPORTER); + recordResponse(rollup, { + method: "GET", + url: "/api/v2/workspaces/abc", + status: 200, + }); + await vi.advanceTimersByTimeAsync(WINDOW_SECONDS * 10 * 1000); + expect(vi.getTimerCount()).toBe(0); + }); + it("calculates nearest-rank p95", async () => { - start(1); + start(); for (let durationMs = 10; durationMs <= 200; durationMs += 10) { recordResponse(rollup, { method: "GET", @@ -135,7 +150,7 @@ describe("HttpRequestsTelemetry", () => { }); } - await vi.advanceTimersByTimeAsync(1000); + await advanceOneWindow(); expect(log).toHaveBeenCalledWith( "http.requests", @@ -145,7 +160,7 @@ describe("HttpRequestsTelemetry", () => { }); it("skips duration when request metadata is missing", async () => { - start(1); + start(); rollup.recordResponse({ data: {}, status: 200, @@ -158,7 +173,7 @@ describe("HttpRequestsTelemetry", () => { }, } as AxiosResponse); - await vi.advanceTimersByTimeAsync(1000); + await advanceOneWindow(); expect(log).toHaveBeenCalledWith( "http.requests", @@ -171,43 +186,29 @@ describe("HttpRequestsTelemetry", () => { ); }); - it("re-flushes and reschedules after updateConfig changes the window", async () => { - start(10); + it("flushes any pending bucket on dispose", () => { + start(); recordResponse(rollup, { method: "GET", url: "/api/v2/workspaces/abc", status: 200, }); - rollup.updateConfig({ windowSeconds: 1 }); + rollup.dispose(); - // updateConfig flushes pending buckets immediately under the old window. expect(log).toHaveBeenCalledWith( "http.requests", { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ window_seconds: 10 }), - ); - - recordResponse(rollup, { - method: "GET", - url: "/api/v2/workspaces/abc", - status: 200, - }); - await vi.advanceTimersByTimeAsync(1000); - - expect(log).toHaveBeenLastCalledWith( - "http.requests", - { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ window_seconds: 1 }), + expect.objectContaining({ count_2xx: 1 }), ); }); it("ignores non-axios errors", async () => { - start(1); + start(); rollup.recordError(new Error("not an axios error")); rollup.recordError("string error"); - await vi.advanceTimersByTimeAsync(1000); + await advanceOneWindow(); expect(log).not.toHaveBeenCalled(); }); @@ -223,20 +224,32 @@ describe("HttpRequestsTelemetry", () => { "/api/v2/organizations/9f0f7f37-dfb7-4f4b-bcb8-c7062c7550fc/templates/base/versions/v1", "/api/v2/organizations/{id}/templates/{name}/versions/{name}", ], + [ + "/api/v2/organizations/9f0f7f37-dfb7-4f4b-bcb8-c7062c7550fc/members/danny", + "/api/v2/organizations/{id}/members/{name}", + ], [ "/api/v2/workspaceagents/9f0f7f37-dfb7-4f4b-bcb8-c7062c7550fc/logs", "/api/v2/workspaceagents/{id}/logs", ], [ - "/api/v2/workspaces/123/builds/456", + "/api/v2/workspaces/0196ac60-0cf9-7c6b-ba8e-925c3e83bb9f/builds/42", "/api/v2/workspaces/{id}/builds/{id}", ], + // No rule match: route is passed through verbatim. + ["/api/v2/buildinfo", "/api/v2/buildinfo"], + [undefined, ""], + ["", ""], ["http://%", ""], ])("normalizes %s", (url, expected) => { expect(normalizeHttpRoute(url)).toBe(expected); }); }); +async function advanceOneWindow(): Promise { + await vi.advanceTimersByTimeAsync(WINDOW_SECONDS * 1000); +} + function recordResponse( rollup: HttpRequestsTelemetry, options: RequestOptions, diff --git a/test/unit/settings/telemetry.test.ts b/test/unit/settings/telemetry.test.ts index df4f7d96..a585613a 100644 --- a/test/unit/settings/telemetry.test.ts +++ b/test/unit/settings/telemetry.test.ts @@ -1,11 +1,9 @@ import { beforeEach, describe, expect, it } from "vitest"; import { - HTTP_REQUESTS_TELEMETRY_DEFAULTS, LOCAL_SINK_DEFAULTS, LOCAL_TELEMETRY_SETTING, TELEMETRY_LEVEL_SETTING, - readHttpRequestsTelemetryConfig, readLocalSinkConfig, readTelemetryLevel, } from "@/settings/telemetry"; @@ -98,55 +96,4 @@ describe("telemetry settings", () => { }); }); }); - - describe("readHttpRequestsTelemetryConfig", () => { - it("returns defaults when unset", () => { - expect(readHttpRequestsTelemetryConfig(config)).toEqual( - HTTP_REQUESTS_TELEMETRY_DEFAULTS, - ); - }); - - it.each([ - ["a string", "nope"], - ["a boolean", true], - ["null", null], - ["an array", [1, 2]], - ])("returns defaults when the raw value is %s", (_, raw) => { - config.set(LOCAL_TELEMETRY_SETTING, raw); - expect(readHttpRequestsTelemetryConfig(config)).toEqual( - HTTP_REQUESTS_TELEMETRY_DEFAULTS, - ); - }); - - it("accepts a fully-specified object", () => { - config.set(LOCAL_TELEMETRY_SETTING, { - httpRequests: { windowSeconds: 10 }, - }); - expect(readHttpRequestsTelemetryConfig(config)).toEqual({ - windowSeconds: 10, - }); - }); - - it.each([ - ["zero", 0], - ["a negative", -1], - ["NaN", Number.NaN], - ["a numeric string", "100"], - ["a boolean", true], - ])("falls back per-field when a value is %s", (_, bad) => { - config.set(LOCAL_TELEMETRY_SETTING, { - httpRequests: { windowSeconds: bad }, - }); - expect(readHttpRequestsTelemetryConfig(config).windowSeconds).toBe( - HTTP_REQUESTS_TELEMETRY_DEFAULTS.windowSeconds, - ); - }); - - it("ignores invalid httpRequests values", () => { - config.set(LOCAL_TELEMETRY_SETTING, { httpRequests: "nope" }); - expect(readHttpRequestsTelemetryConfig(config)).toEqual( - HTTP_REQUESTS_TELEMETRY_DEFAULTS, - ); - }); - }); }); From 19c231d5c6749de58ba6dd83dfc3f97fa8bffdd2 Mon Sep 17 00:00:00 2001 From: Ehab Younes Date: Tue, 12 May 2026 12:20:59 +0300 Subject: [PATCH 5/5] address review comments --- package.json | 2 +- src/logging/httpRequestsTelemetry.ts | 27 +++++++++---------- test/unit/api/coderApi.test.ts | 5 ++++ .../logging/httpRequestsTelemetry.test.ts | 17 +++++++++--- 4 files changed, 32 insertions(+), 19 deletions(-) diff --git a/package.json b/package.json index 5b5d7df8..1e652166 100644 --- a/package.json +++ b/package.json @@ -31,7 +31,7 @@ "package:prerelease": "pnpm build:production && vsce package --pre-release --no-dependencies", "storybook": "storybook dev -p 6006 --config-dir .storybook", "storybook:build": "storybook build --config-dir .storybook", - "storybook:ci": "storybook build --test --config-dir .storybook", + "storybook:ci": "storybook build --test --config-dir .storybook", "test": "cross-env CI=true ELECTRON_RUN_AS_NODE=1 electron node_modules/vitest/vitest.mjs", "test:extension": "cross-env ELECTRON_RUN_AS_NODE=1 electron node_modules/vitest/vitest.mjs --project extension", "test:integration": "pnpm compile-tests:integration && node esbuild.mjs && vscode-test", diff --git a/src/logging/httpRequestsTelemetry.ts b/src/logging/httpRequestsTelemetry.ts index 886c4971..dd95b94c 100644 --- a/src/logging/httpRequestsTelemetry.ts +++ b/src/logging/httpRequestsTelemetry.ts @@ -43,6 +43,7 @@ const ROUTE_NORMALIZATION_RULES: ReadonlyArray = [ ].map((rule) => rule.split("/")); interface HttpRequestBucket { + count1xx: number; count2xx: number; count3xx: number; count4xx: number; @@ -124,6 +125,8 @@ export class HttpRequestsTelemetry implements Disposable { if (networkError || statusCode === undefined) { bucket.countNetworkError += 1; + } else if (statusCode >= 100 && statusCode < 200) { + bucket.count1xx += 1; } else if (statusCode >= 200 && statusCode < 300) { bucket.count2xx += 1; } else if (statusCode >= 300 && statusCode < 400) { @@ -146,6 +149,7 @@ export class HttpRequestsTelemetry implements Disposable { let bucket = byRoute.get(route); if (!bucket) { bucket = { + count1xx: 0, count2xx: 0, count3xx: 0, count4xx: 0, @@ -165,18 +169,21 @@ export class HttpRequestsTelemetry implements Disposable { ); for (const [method, byRoute] of this.#buckets) { for (const [route, bucket] of byRoute) { + const sortedDurations = bucket.durationsMs.toSorted((a, b) => a - b); this.#telemetry.log( EVENT_NAME, { method, route }, { window_seconds: elapsedSeconds, + count_1xx: bucket.count1xx, count_2xx: bucket.count2xx, count_3xx: bucket.count3xx, count_4xx: bucket.count4xx, count_5xx: bucket.count5xx, count_network_error: bucket.countNetworkError, - avg_duration_ms: average(bucket.durationsMs), - p95_duration_ms: percentile95(bucket.durationsMs), + p50_duration_ms: percentile(sortedDurations, 0.5), + p95_duration_ms: percentile(sortedDurations, 0.95), + p99_duration_ms: percentile(sortedDurations, 0.99), }, ); } @@ -265,18 +272,10 @@ function elapsedMs( : undefined; } -function average(values: readonly number[]): number { - if (values.length === 0) { +function percentile(sortedValues: readonly number[], p: number): number { + if (sortedValues.length === 0) { return 0; } - return values.reduce((sum, value) => sum + value, 0) / values.length; -} - -function percentile95(values: readonly number[]): number { - if (values.length === 0) { - return 0; - } - const sorted = values.toSorted((a, b) => a - b); - const index = Math.ceil(sorted.length * 0.95) - 1; - return sorted[Math.max(0, index)]; + const index = Math.ceil(sortedValues.length * p) - 1; + return sortedValues[Math.max(0, index)]; } diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index 3a22c6da..c132fb47 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -256,7 +256,12 @@ describe("CoderApi", () => { { method: "GET", route: "/api/v2/workspaces/{id}" }, expect.objectContaining({ window_seconds: 60, + count_1xx: 0, count_2xx: 1, + count_3xx: 0, + count_4xx: 0, + count_5xx: 0, + count_network_error: 0, }), ); }); diff --git a/test/unit/logging/httpRequestsTelemetry.test.ts b/test/unit/logging/httpRequestsTelemetry.test.ts index 00263d7a..fce97c26 100644 --- a/test/unit/logging/httpRequestsTelemetry.test.ts +++ b/test/unit/logging/httpRequestsTelemetry.test.ts @@ -80,13 +80,15 @@ describe("HttpRequestsTelemetry", () => { { method: "GET", route: "/api/v2/workspaces/{id}" }, { window_seconds: WINDOW_SECONDS, + count_1xx: 0, count_2xx: 2, count_3xx: 0, count_4xx: 0, count_5xx: 0, count_network_error: 0, - avg_duration_ms: 150, + p50_duration_ms: 100, p95_duration_ms: 200, + p99_duration_ms: 200, }, ); expect(log).toHaveBeenNthCalledWith( @@ -100,6 +102,7 @@ describe("HttpRequestsTelemetry", () => { it("counts status code classes and network errors", async () => { start(); const route = "/api/v2/users/danny/workspaces"; + recordResponse(rollup, { method: "POST", url: route, status: 101 }); recordResponse(rollup, { method: "POST", url: route, status: 201 }); recordResponse(rollup, { method: "POST", url: route, status: 302 }); recordAxiosError(rollup, { method: "POST", url: route, status: 404 }); @@ -112,6 +115,7 @@ describe("HttpRequestsTelemetry", () => { "http.requests", { method: "POST", route: "/api/v2/users/{name}/workspaces" }, expect.objectContaining({ + count_1xx: 1, count_2xx: 1, count_3xx: 1, count_4xx: 1, @@ -139,7 +143,7 @@ describe("HttpRequestsTelemetry", () => { expect(vi.getTimerCount()).toBe(0); }); - it("calculates nearest-rank p95", async () => { + it("calculates nearest-rank p50, p95, p99", async () => { start(); for (let durationMs = 10; durationMs <= 200; durationMs += 10) { recordResponse(rollup, { @@ -155,7 +159,11 @@ describe("HttpRequestsTelemetry", () => { expect(log).toHaveBeenCalledWith( "http.requests", { method: "GET", route: "/api/v2/workspaces/{id}" }, - expect.objectContaining({ avg_duration_ms: 105, p95_duration_ms: 190 }), + expect.objectContaining({ + p50_duration_ms: 100, + p95_duration_ms: 190, + p99_duration_ms: 200, + }), ); }); @@ -180,8 +188,9 @@ describe("HttpRequestsTelemetry", () => { { method: "GET", route: "/api/v2/workspaces/{id}" }, expect.objectContaining({ count_2xx: 1, - avg_duration_ms: 0, + p50_duration_ms: 0, p95_duration_ms: 0, + p99_duration_ms: 0, }), ); });