From a800f6ef9cfa7447fe2f8a8ba9f0a204c0875f84 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 26 Aug 2026 21:01:22 +0000 Subject: [PATCH 01/60] feat(logging): add BufferingLogger for below-level connection logs Wraps a Logger and keeps a bounded in-memory ring of entries below the sink's current level (the ones it would drop). flush() replays them into the sink at a level guaranteed to be written, so a connection failure can preserve the debug detail leading up to it without the user having enabled debug logging. Only below-level entries are buffered (no duplication of what the sink already writes); flush is coalesced by a short suppression window. --- src/logging/logBuffer.ts | 177 ++++++++++++++++ test/unit/logging/logBuffer.test.ts | 309 ++++++++++++++++++++++++++++ 2 files changed, 486 insertions(+) create mode 100644 src/logging/logBuffer.ts create mode 100644 test/unit/logging/logBuffer.test.ts diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts new file mode 100644 index 0000000000..0c1a149b70 --- /dev/null +++ b/src/logging/logBuffer.ts @@ -0,0 +1,177 @@ +import type { Logger } from "./logger"; + +/** + * Numeric severities matching `vscode.LogLevel` (Off=0, Trace=1, Debug=2, + * Info=3, Warning=4, Error=5). Kept as plain numbers so this module stays + * free of the VS Code API and easy to test. + */ +const SEVERITY = { + trace: 1, + debug: 2, + info: 3, + warn: 4, + error: 5, +} as const; + +type Level = keyof typeof SEVERITY; + +const LEVEL_LABEL: Record = { + trace: "TRACE", + debug: "DEBUG", + info: "INFO", + warn: "WARN", + error: "ERROR", +}; + +/** Reads the sink's effective log level (numeric, matching `vscode.LogLevel`). */ +export interface LogLevelSource { + getLogLevel(): number; + onDidChangeLogLevel(listener: (level: number) => void): { dispose(): void }; +} + +/** The failure-time surface used by connection-failure call sites. */ +export interface ConnectionLogBuffer { + flush(reason: string): void; +} + +interface BufferedEntry { + readonly atMs: number; + readonly level: Level; + readonly message: string; + readonly args: unknown[]; +} + +function normalizeCapacity(capacity: number): number { + return Number.isFinite(capacity) && capacity > 0 ? Math.floor(capacity) : 0; +} + +/** + * Wraps a {@link Logger} and keeps a bounded, in-memory ring of entries whose + * level is **below the sink's current level** — the ones the sink would + * otherwise drop. On a connection failure, {@link flush} replays those entries + * into the sink so they persist to disk (and any support bundle), giving Support + * the debug detail leading up to the failure without the user having enabled + * debug logging beforehand. + * + * Only below-level entries are buffered, so nothing that the sink already writes + * is ever duplicated. Replay is emitted at the least-verbose level the sink + * still writes, so the flush lands regardless of the configured level. + */ +export class BufferingLogger implements Logger, ConnectionLogBuffer { + private entries: BufferedEntry[] = []; + private capacity: number; + private currentLevel: number; + private lastFlushMs = Number.NEGATIVE_INFINITY; + private readonly levelSubscription: { dispose(): void }; + + public constructor( + private readonly inner: Logger, + private readonly levelSource: LogLevelSource, + capacity: number, + private readonly flushSuppressionMs = 5_000, + private readonly now: () => number = Date.now, + ) { + this.capacity = normalizeCapacity(capacity); + this.currentLevel = levelSource.getLogLevel(); + this.levelSubscription = levelSource.onDidChangeLogLevel((level) => { + this.currentLevel = level; + }); + } + + public trace(message: string, ...args: unknown[]): void { + this.record("trace", message, args); + this.inner.trace(message, ...args); + } + + public debug(message: string, ...args: unknown[]): void { + this.record("debug", message, args); + this.inner.debug(message, ...args); + } + + public info(message: string, ...args: unknown[]): void { + this.record("info", message, args); + this.inner.info(message, ...args); + } + + public warn(message: string, ...args: unknown[]): void { + this.record("warn", message, args); + this.inner.warn(message, ...args); + } + + public error(message: string, ...args: unknown[]): void { + this.record("error", message, args); + this.inner.error(message, ...args); + } + + public show(): void { + this.inner.show(); + } + + /** Resize the ring, keeping the most recent entries. */ + public setCapacity(capacity: number): void { + this.capacity = normalizeCapacity(capacity); + if (this.entries.length > this.capacity) { + this.entries.splice(0, this.entries.length - this.capacity); + } + } + + /** + * Replay buffered entries into the sink and clear them. No-op when empty or + * when called again within the suppression window (one outage often trips + * several failure signals at once). + */ + public flush(reason: string): void { + const now = this.now(); + if (now - this.lastFlushMs < this.flushSuppressionMs) { + return; + } + if (this.entries.length === 0) { + return; + } + this.lastFlushMs = now; + const entries = this.entries; + this.entries = []; + + const emit = this.replayEmitter(); + emit( + `[buffered] connection failure (${reason}): replaying ${entries.length} buffered log line(s)`, + ); + for (const entry of entries) { + emit( + `[buffered] ${new Date(entry.atMs).toISOString()} ${LEVEL_LABEL[entry.level]} ${entry.message}`, + ...entry.args, + ); + } + emit(`[buffered] end of buffered logs (${reason})`); + } + + public dispose(): void { + this.levelSubscription.dispose(); + } + + /** + * The least-verbose sink method that is still written at the current level, + * so a flush is captured whatever the user's log level (except Off, where the + * sink writes nothing). + */ + private replayEmitter(): (message: string, ...args: unknown[]) => void { + const level = this.levelSource.getLogLevel(); + if (level >= SEVERITY.error) { + return (message, ...args) => this.inner.error(message, ...args); + } + if (level >= SEVERITY.warn) { + return (message, ...args) => this.inner.warn(message, ...args); + } + return (message, ...args) => this.inner.info(message, ...args); + } + + private record(level: Level, message: string, args: unknown[]): void { + if (this.capacity === 0 || SEVERITY[level] >= this.currentLevel) { + return; + } + this.entries.push({ atMs: this.now(), level, message, args }); + if (this.entries.length > this.capacity) { + this.entries.shift(); + } + } +} diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts new file mode 100644 index 0000000000..8a3f0a7cce --- /dev/null +++ b/test/unit/logging/logBuffer.test.ts @@ -0,0 +1,309 @@ +import { describe, expect, it, vi } from "vitest"; + +import { BufferingLogger, type LogLevelSource } from "@/logging/logBuffer"; + +import type { Logger } from "@/logging/logger"; + +// Numeric levels matching vscode.LogLevel. +const OFF = 0; +const DEBUG = 2; +const INFO = 3; +const WARNING = 4; +const ERROR = 5; + +interface Call { + level: keyof Logger; + message: string; + args: unknown[]; +} + +function recordingLogger(): { logger: Logger; calls: Call[] } { + const calls: Call[] = []; + const push = + (level: keyof Logger) => + (message: string, ...args: unknown[]) => + calls.push({ level, message, args }); + return { + calls, + logger: { + trace: push("trace"), + debug: push("debug"), + info: push("info"), + warn: push("warn"), + error: push("error"), + show: vi.fn(), + }, + }; +} + +function fakeLevelSource(initial: number): LogLevelSource & { + set(level: number): void; +} { + let level = initial; + const listeners = new Set<(level: number) => void>(); + return { + getLogLevel: () => level, + onDidChangeLogLevel: (listener) => { + listeners.add(listener); + return { dispose: () => listeners.delete(listener) }; + }, + set(next: number) { + level = next; + for (const listener of listeners) { + listener(next); + } + }, + }; +} + +function clock(start = 1_000): { + now: () => number; + advance(ms: number): void; +} { + let t = start; + return { now: () => t, advance: (ms) => (t += ms) }; +} + +describe("BufferingLogger", () => { + it("forwards every call to the inner logger", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + + buffer.trace("t"); + buffer.debug("d"); + buffer.info("i"); + buffer.warn("w"); + buffer.error("e"); + + expect(calls.map((c) => c.level)).toEqual([ + "trace", + "debug", + "info", + "warn", + "error", + ]); + }); + + it("buffers only entries below the current level and replays them on flush", () => { + const { logger, calls } = recordingLogger(); + const time = clock(); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO), + 10, + 5_000, + time.now, + ); + + buffer.debug("hidden debug"); + buffer.info("visible info"); + + calls.length = 0; // ignore the pass-through calls + buffer.flush("test_reason"); + + const replayed = calls.filter((c) => c.message.includes("[buffered]")); + // header + one debug line + footer; the info line was at level and not buffered. + expect(replayed).toHaveLength(3); + expect(replayed[0].message).toContain("connection failure (test_reason)"); + expect(replayed[1].message).toContain("DEBUG hidden debug"); + expect(replayed[2].message).toContain("end of buffered logs"); + }); + + it("does not buffer entries at or above the current level", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + + buffer.info("i"); + buffer.warn("w"); + buffer.error("e"); + + calls.length = 0; + buffer.flush("r"); + + expect(calls).toHaveLength(0); + }); + + it("evicts the oldest entry when capacity is exceeded", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 2); + + buffer.debug("one"); + buffer.debug("two"); + buffer.debug("three"); + + calls.length = 0; + buffer.flush("r"); + + const lines = calls.map((c) => c.message); + expect(lines.some((l) => l.includes("one"))).toBe(false); + expect(lines.some((l) => l.includes("two"))).toBe(true); + expect(lines.some((l) => l.includes("three"))).toBe(true); + }); + + it("clears the buffer after a flush", () => { + const { logger, calls } = recordingLogger(); + const time = clock(); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO), + 10, + 5_000, + time.now, + ); + + buffer.debug("d"); + buffer.flush("first"); + time.advance(10_000); // past the suppression window + + calls.length = 0; + buffer.flush("second"); + + expect(calls).toHaveLength(0); + }); + + it("is a no-op when the buffer is empty", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + + buffer.flush("r"); + + expect(calls).toHaveLength(0); + }); + + it("suppresses a second flush within the suppression window", () => { + const { logger, calls } = recordingLogger(); + const time = clock(); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO), + 10, + 5_000, + time.now, + ); + + buffer.debug("a"); + buffer.flush("first"); + + time.advance(1_000); // within the window + buffer.debug("b"); + calls.length = 0; + buffer.flush("second"); + + expect(calls).toHaveLength(0); + }); + + it("re-evaluates what is below level when the level changes", () => { + const { logger, calls } = recordingLogger(); + const level = fakeLevelSource(ERROR); + const buffer = new BufferingLogger(logger, level, 10); + + buffer.info("info at error level"); // below ERROR -> buffered + level.set(INFO); + buffer.info("info at info level"); // at INFO -> not buffered + + calls.length = 0; + buffer.flush("r"); + + const lines = calls.map((c) => c.message); + expect(lines.some((l) => l.includes("info at error level"))).toBe(true); + expect(lines.some((l) => l.includes("info at info level"))).toBe(false); + }); + + it("buffers nothing when capacity is zero", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 0); + + buffer.debug("d"); + calls.length = 0; + buffer.flush("r"); + + expect(calls).toHaveLength(0); + }); + + it("keeps the most recent entries when shrunk via setCapacity", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + + buffer.debug("one"); + buffer.debug("two"); + buffer.debug("three"); + buffer.setCapacity(1); + + calls.length = 0; + buffer.flush("r"); + + const lines = calls.map((c) => c.message); + expect(lines.some((l) => l.includes("three"))).toBe(true); + expect(lines.some((l) => l.includes("one"))).toBe(false); + expect(lines.some((l) => l.includes("two"))).toBe(false); + }); + + it.each([ + { level: INFO, expected: "info" as const }, + { level: WARNING, expected: "warn" as const }, + { level: ERROR, expected: "error" as const }, + ])( + "replays at $expected so the flush is written at level $level", + ({ level, expected }) => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(level), 10); + + // Always below the current level so it is buffered. + buffer.trace("below"); + calls.length = 0; + buffer.flush("r"); + + expect(calls.length).toBeGreaterThan(0); + expect(calls.every((c) => c.level === expected)).toBe(true); + }, + ); + + it("preserves extra args on replay", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const detail = { code: 1006 }; + + buffer.debug("dropped", detail); + calls.length = 0; + buffer.flush("r"); + + const line = calls.find((c) => c.message.includes("dropped")); + expect(line?.args).toEqual([detail]); + }); + + it("stops buffering after dispose unsubscribes from level changes", () => { + const { logger } = recordingLogger(); + const level = fakeLevelSource(INFO); + const buffer = new BufferingLogger(logger, level, 10); + + buffer.dispose(); + // Changing the level must not throw or affect the disposed buffer. + expect(() => level.set(ERROR)).not.toThrow(); + }); + + it("does not buffer at the Off level", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(OFF), 10); + + buffer.trace("t"); + buffer.debug("d"); + calls.length = 0; + buffer.flush("r"); + + expect(calls).toHaveLength(0); + }); + + it("buffers trace but not debug at the Debug level", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(DEBUG), 10); + + buffer.trace("trace line"); + buffer.debug("debug line"); + calls.length = 0; + buffer.flush("r"); + + const lines = calls.map((c) => c.message); + expect(lines.some((l) => l.includes("trace line"))).toBe(true); + expect(lines.some((l) => l.includes("debug line"))).toBe(false); + }); +}); From 69efd2fee99b24247a0d9da386c664c1e9469468 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 26 Aug 2026 21:04:18 +0000 Subject: [PATCH 02/60] feat(logging): wire the connection log buffer into the service container --- package.json | 6 ++++++ src/core/container.ts | 46 ++++++++++++++++++++++++++++++++++++++++--- 2 files changed, 49 insertions(+), 3 deletions(-) diff --git a/package.json b/package.json index 203b9b23d9..6673e19fc3 100644 --- a/package.json +++ b/package.json @@ -215,6 +215,12 @@ "minimum": 0, "default": 250 }, + "coder.connectionLogBuffer.size": { + "markdownDescription": "Number of connection debug log lines to keep in memory below the current log level. On a connection failure they are written out so a support bundle captures the detail leading up to it, without debug logging enabled beforehand. Set to `0` to disable. The buffer is lost on a hard kill or out-of-memory event.", + "type": "number", + "minimum": 0, + "default": 1000 + }, "coder.httpClientLogLevel": { "markdownDescription": "Controls the verbosity of HTTP client logging. This affects what details are logged for each HTTP request and response.", "type": "string", diff --git a/src/core/container.ts b/src/core/container.ts index 56cd0edf83..7df2b74568 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -1,6 +1,10 @@ import * as vscode from "vscode"; import { AuthTelemetry } from "../instrumentation/auth"; +import { + BufferingLogger, + type ConnectionLogBuffer, +} from "../logging/logBuffer"; import { prefixLogger } from "../logging/prefixLogger"; import { shortId } from "../logging/utils"; import { LoginCoordinator } from "../login/loginCoordinator"; @@ -30,6 +34,8 @@ import type { Logger } from "../logging/logger"; export class ServiceContainer implements vscode.Disposable { private readonly outputChannel: vscode.LogOutputChannel; private readonly logger: Logger; + private readonly connectionLogBuffer: BufferingLogger; + private readonly disposables: vscode.Disposable[] = []; private readonly pathResolver: PathResolver; private readonly mementoManager: MementoManager; private readonly secretsManager: SecretsManager; @@ -48,9 +54,23 @@ export class ServiceContainer implements vscode.Disposable { this.outputChannel = vscode.window.createOutputChannel("Coder", { log: true, }); - this.logger = prefixLogger( - this.outputChannel, - `[session ${shortId(sessionId)}]`, + this.connectionLogBuffer = new BufferingLogger( + prefixLogger(this.outputChannel, `[session ${shortId(sessionId)}]`), + { + getLogLevel: () => this.outputChannel.logLevel, + onDidChangeLogLevel: (listener) => + this.outputChannel.onDidChangeLogLevel(listener), + }, + readConnectionLogBufferSize(), + ); + this.logger = this.connectionLogBuffer; + this.disposables.push( + this.connectionLogBuffer, + vscode.workspace.onDidChangeConfiguration((event) => { + if (event.affectsConfiguration(CONNECTION_LOG_BUFFER_SIZE_KEY)) { + this.connectionLogBuffer.setCapacity(readConnectionLogBufferSize()); + } + }), ); this.pathResolver = new PathResolver( context.globalStorageUri.fsPath, @@ -148,6 +168,11 @@ export class ServiceContainer implements vscode.Disposable { return this.logger; } + /** The below-level connection log buffer; flush it on a connection failure. */ + getConnectionLogBuffer(): ConnectionLogBuffer { + return this.connectionLogBuffer; + } + getCliManager(): CliManager { return this.cliManager; } @@ -193,6 +218,9 @@ export class ServiceContainer implements vscode.Disposable { this.commandManager.dispose(); this.contextManager.dispose(); this.loginCoordinator.dispose(); + for (const disposable of this.disposables) { + disposable.dispose(); + } try { await this.telemetryService.dispose(); } finally { @@ -200,3 +228,15 @@ export class ServiceContainer implements vscode.Disposable { } } } + +const CONNECTION_LOG_BUFFER_SIZE_KEY = "coder.connectionLogBuffer.size"; +const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; + +function readConnectionLogBufferSize(): number { + return vscode.workspace + .getConfiguration() + .get( + CONNECTION_LOG_BUFFER_SIZE_KEY, + DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + ); +} From bbb9d5bfece7aa075f4319c62dec4260e8e0a50c Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 26 Aug 2026 21:12:18 +0000 Subject: [PATCH 03/60] feat(logging): flush the connection log buffer on connection failures --- src/api/coderApi.ts | 7 ++ src/extension.ts | 1 + src/remote/workspaceStateMachine.ts | 4 + src/websocket/reconnectingWebSocket.ts | 27 +++++- src/workspace/workspaceMonitor.ts | 4 + test/mocks/testHelpers.ts | 6 ++ .../unit/remote/workspaceStateMachine.test.ts | 14 ++- .../websocket/reconnectingWebSocket.test.ts | 89 +++++++++++++++++++ test/unit/workspace/workspaceMonitor.test.ts | 15 ++++ 9 files changed, 163 insertions(+), 4 deletions(-) diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index c401cb9e46..249b24d2db 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -69,6 +69,7 @@ import type { } from "coder/site/src/api/typesGenerated"; import type { ClientOptions } from "ws"; +import type { ConnectionStateReason } from "../instrumentation/websocket"; import type { Logger } from "../logging/logger"; import type { CloseEvent, @@ -125,6 +126,9 @@ export class CoderApi extends Api implements vscode.Disposable { private readonly telemetry: TelemetryReporter, private readonly httpRequestsTelemetry: HttpRequestsTelemetry, private readonly authConfigTracker: AuthConfigTracker, + private readonly onConnectionFailure?: ( + reason: ConnectionStateReason, + ) => void, ) { super(); wrapWithValidation(this); @@ -145,6 +149,7 @@ export class CoderApi extends Api implements vscode.Disposable { token: string | undefined, output: Logger, telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, + onConnectionFailure?: (reason: ConnectionStateReason) => void, ): CoderApi { const httpRequestsTelemetry = new HttpRequestsTelemetry(telemetry); const authConfigTracker = new AuthConfigTracker(); @@ -153,6 +158,7 @@ export class CoderApi extends Api implements vscode.Disposable { telemetry, httpRequestsTelemetry, authConfigTracker, + onConnectionFailure, ); client.getAxiosInstance().defaults.timeout = DEFAULT_REQUEST_TIMEOUT_MS; client.getAxiosInstance().defaults.headers.common[BAGGAGE_HEADER] = @@ -548,6 +554,7 @@ export class CoderApi extends Api implements vscode.Disposable { } return refreshCertificates(refreshCommand, this.output); }, + onConnectionFailure: this.onConnectionFailure, telemetry: this.telemetry, }; diff --git a/src/extension.ts b/src/extension.ts index e5733b0bb2..6d6294e3d9 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -143,6 +143,7 @@ async function doActivate( deploymentSessionAuth?.token, output, telemetryService, + (reason) => serviceContainer.getConnectionLogBuffer().flush(reason), ); ctx.subscriptions.push(client); diff --git a/src/remote/workspaceStateMachine.ts b/src/remote/workspaceStateMachine.ts index fc4242d967..0e44f9fa93 100644 --- a/src/remote/workspaceStateMachine.ts +++ b/src/remote/workspaceStateMachine.ts @@ -32,6 +32,7 @@ import type { CoderApi } from "../api/coderApi"; import type { ServiceContainer } from "../core/container"; import type { StartupMode } from "../core/mementoManager"; import type { FeatureSet } from "../featureSet"; +import type { ConnectionLogBuffer } from "../logging/logBuffer"; import type { Logger } from "../logging/logger"; import type { CliAuth } from "../settings/cli"; import type { AuthorityParts } from "../util/authority"; @@ -50,6 +51,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { private workspace: Workspace | undefined; private readonly logger: Logger; + private readonly connectionLogBuffer: ConnectionLogBuffer; constructor( private readonly parts: AuthorityParts, @@ -61,6 +63,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { container: ServiceContainer, ) { this.logger = container.getLogger(); + this.connectionLogBuffer = container.getConnectionLogBuffer(); this.terminal = new TerminalOutputChannel("Coder: Workspace Build"); const telemetry = container.getTelemetryService(); const workspaceName = `${parts.username}/${parts.workspace}`; @@ -189,6 +192,7 @@ export class WorkspaceStateMachine implements vscode.Disposable { return false; case "disconnected": + this.connectionLogBuffer.flush("agent_disconnected"); throw new Error(`Agent ${workspaceName}/${agent.name} disconnected`); case "timeout": diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index a881599378..80e1d6aeb1 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -28,6 +28,22 @@ function toCloseEventError(event: CloseEvent): Error { return new Error(`WebSocket closed with code ${event.code}: ${event.reason}`); } +/** + * Terminal-failure reasons: the socket has given up and surfaced an error, + * rather than dropping transiently and auto-reconnecting. These are the moments + * worth flushing the connection log buffer. + */ +const CONNECTION_FAILURE_REASONS: ReadonlySet = new Set([ + "unrecoverable_close", + "unrecoverable_http", + "certificate_error", +]); + +/** Whether a state-transition reason represents a genuine connection failure. */ +export function isConnectionFailure(reason: ConnectionStateReason): boolean { + return CONNECTION_FAILURE_REASONS.has(reason); +} + /** * Connection states for the ReconnectingWebSocket state machine. */ @@ -117,6 +133,8 @@ export interface ReconnectingWebSocketOptions { telemetry: TelemetryReporter; /** Callback invoked when a refreshable certificate error is detected. Returns true if refresh succeeded. */ onCertificateRefreshNeeded: () => Promise; + /** Callback invoked when the connection fails terminally (not a transient drop). */ + onConnectionFailure?: (reason: ConnectionStateReason) => void; } export class ReconnectingWebSocket< @@ -125,7 +143,10 @@ export class ReconnectingWebSocket< readonly #socketFactory: SocketFactory; readonly #logger: Logger; readonly #telemetry: WebSocketTelemetry; - readonly #options: Required>; + readonly #options: Required< + Omit + >; + readonly #onConnectionFailure?: (reason: ConnectionStateReason) => void; readonly #eventHandlers: { [K in WebSocketEventType]: Set>; } = { @@ -179,6 +200,7 @@ export class ReconnectingWebSocket< jitterFactor: options.jitterFactor ?? 0.1, onCertificateRefreshNeeded: options.onCertificateRefreshNeeded, }; + this.#onConnectionFailure = options.onConnectionFailure; this.#backoffMs = this.#options.initialBackoffMs; this.#onDispose = onDispose; } @@ -293,6 +315,9 @@ export class ReconnectingWebSocket< error: options.error, }); this.clearCurrentSocket(options.code, options.closeReason); + if (isConnectionFailure(reason)) { + this.#onConnectionFailure?.(reason); + } } public close(code?: number, reason?: string): void { diff --git a/src/workspace/workspaceMonitor.ts b/src/workspace/workspaceMonitor.ts index debcf6c545..20cf6a0168 100644 --- a/src/workspace/workspaceMonitor.ts +++ b/src/workspace/workspaceMonitor.ts @@ -26,6 +26,7 @@ import { import type { CoderApi } from "../api/coderApi"; import type { ServiceContainer } from "../core/container"; import type { ContextManager } from "../core/contextManager"; +import type { ConnectionLogBuffer } from "../logging/logBuffer"; import type { Logger } from "../logging/logger"; import type { TelemetryReporter } from "../telemetry/reporter"; import type { UnidirectionalStream } from "../websocket/eventStreamConnection"; @@ -63,6 +64,7 @@ export class WorkspaceMonitor implements vscode.Disposable { private readonly agentObserver = new WorkspaceAgentObserver(); private readonly logger: Logger; private readonly contextManager: ContextManager; + private readonly connectionLogBuffer: ConnectionLogBuffer; private latestWorkspace: Workspace; @@ -73,6 +75,7 @@ export class WorkspaceMonitor implements vscode.Disposable { ) { this.logger = container.getLogger(); this.contextManager = container.getContextManager(); + this.connectionLogBuffer = container.getConnectionLogBuffer(); this.name = createWorkspaceIdentifier(workspace); this.telemetry = container.getTelemetryService(); this.latestWorkspace = workspace; @@ -312,6 +315,7 @@ export class WorkspaceMonitor implements vscode.Disposable { "Got empty error while monitoring workspace", ); this.logger.error(message); + this.connectionLogBuffer.flush("workspace_monitor_error"); } private updateContext(workspace: Workspace) { diff --git a/test/mocks/testHelpers.ts b/test/mocks/testHelpers.ts index 708440cbb0..b3d07a83a8 100644 --- a/test/mocks/testHelpers.ts +++ b/test/mocks/testHelpers.ts @@ -42,6 +42,7 @@ import type { PathResolver } from "@/core/pathResolver"; import type { SecretsManager } from "@/core/secretsManager"; import type { DeploymentManager } from "@/deployment/deploymentManager"; import type { Deployment } from "@/deployment/types"; +import type { ConnectionLogBuffer } from "@/logging/logBuffer"; import type { Logger } from "@/logging/logger"; import type { LoginCoordinator } from "@/login/loginCoordinator"; import type { NetworkInfo } from "@/remote/sshProcess"; @@ -625,10 +626,14 @@ export function createMockServiceContainer( pathResolver?: PathResolver; contextManager?: ContextManagerLike; loginCoordinator?: LoginCoordinatorLike; + connectionLogBuffer?: ConnectionLogBuffer; } = {}, ): ServiceContainer { const telemetry = overrides.telemetry ?? createTestTelemetryService(); const logger = overrides.logger ?? createMockLogger(); + const connectionLogBuffer = overrides.connectionLogBuffer ?? { + flush: () => {}, + }; const require = (name: string, value: T | undefined): T => { if (value === undefined) { throw new Error(`createMockServiceContainer: '${name}' was not provided`); @@ -638,6 +643,7 @@ export function createMockServiceContainer( return { getTelemetryService: () => telemetry, getLogger: () => logger, + getConnectionLogBuffer: () => connectionLogBuffer, getSecretsManager: () => require("secretsManager", overrides.secretsManager), getMementoManager: () => diff --git a/test/unit/remote/workspaceStateMachine.test.ts b/test/unit/remote/workspaceStateMachine.test.ts index e437b67467..ee50360fd1 100644 --- a/test/unit/remote/workspaceStateMachine.test.ts +++ b/test/unit/remote/workspaceStateMachine.test.ts @@ -103,6 +103,7 @@ function setup( enableLocalTelemetry(); const progress = new MockProgress<{ message?: string }>(); const userInteraction = new MockUserInteraction(); + const connectionLogBuffer = { flush: vi.fn() }; const sm = new WorkspaceStateMachine( DEFAULT_PARTS, {} as CoderApi, @@ -110,9 +111,13 @@ function setup( "/usr/bin/coder", {} as FeatureSet, { mode: "url", url: "https://test.coder.com" }, - createMockServiceContainer({ telemetry, logger: createMockLogger() }), + createMockServiceContainer({ + telemetry, + logger: createMockLogger(), + connectionLogBuffer, + }), ); - return { sm, progress, userInteraction }; + return { sm, progress, userInteraction, connectionLogBuffer }; } describe("WorkspaceStateMachine", () => { @@ -148,11 +153,14 @@ describe("WorkspaceStateMachine", () => { }); it("throws when agent is disconnected", async () => { - const { sm, progress } = setup(); + const { sm, progress, connectionLogBuffer } = setup(); const ws = runningWorkspace({ status: "disconnected" }); await expect(sm.processWorkspace(ws, progress)).rejects.toThrow( "disconnected", ); + expect(connectionLogBuffer.flush).toHaveBeenCalledWith( + "agent_disconnected", + ); }); it("triggers update and falls through to agent check", async () => { diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index 463490a2ba..0f703a12ea 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -8,6 +8,7 @@ import { WebSocketCloseCode, HttpStatusCode } from "@/websocket/codes"; import { ConnectionState, ReconnectingWebSocket, + isConnectionFailure, type SocketFactory, } from "@/websocket/reconnectingWebSocket"; @@ -20,6 +21,7 @@ import { createMockLogger } from "../../mocks/testHelpers"; import type { CloseEvent, Event as WsEvent } from "ws"; +import type { ConnectionStateReason } from "@/instrumentation/websocket"; import type { UnidirectionalStream } from "@/websocket/eventStreamConnection"; describe("ReconnectingWebSocket", () => { @@ -794,6 +796,91 @@ describe("ReconnectingWebSocket", () => { ws.close(); }); }); + + describe("Connection failure callback", () => { + it.each([ + "unrecoverable_close", + "unrecoverable_http", + "certificate_error", + ] as const)("treats %s as a connection failure", (reason) => { + expect(isConnectionFailure(reason)).toBe(true); + }); + + it.each([ + "initial_connect", + "manual_reconnect", + "scheduled_reconnect", + "open", + "disconnect", + "dispose", + "connection_error", + "normal_close", + "unexpected_close", + ] as const)("does not treat %s as a connection failure", (reason) => { + expect(isConnectionFailure(reason)).toBe(false); + }); + + it("fires onConnectionFailure on an unrecoverable close code", async () => { + const onConnectionFailure = vi.fn(); + const { ws, sockets } = await createReconnectingWebSocket({ + onConnectionFailure, + }); + + sockets[0].fireOpen(); + sockets[0].fireClose({ + code: WebSocketCloseCode.PROTOCOL_ERROR, + reason: "Unrecoverable", + }); + + expect(onConnectionFailure).toHaveBeenCalledWith("unrecoverable_close"); + ws.close(); + }); + + it("does not fire onConnectionFailure on a normal close", async () => { + const onConnectionFailure = vi.fn(); + const { ws, sockets } = await createReconnectingWebSocket({ + onConnectionFailure, + }); + + sockets[0].fireOpen(); + sockets[0].fireClose({ + code: WebSocketCloseCode.NORMAL, + reason: "Normal", + }); + + expect(onConnectionFailure).not.toHaveBeenCalled(); + ws.close(); + }); + + it("does not fire onConnectionFailure on a manual disconnect", async () => { + const onConnectionFailure = vi.fn(); + const { ws, sockets } = await createReconnectingWebSocket({ + onConnectionFailure, + }); + + sockets[0].fireOpen(); + ws.disconnect(); + + expect(onConnectionFailure).not.toHaveBeenCalled(); + ws.close(); + }); + + it("does not fire onConnectionFailure on a transient reconnecting drop", async () => { + const onConnectionFailure = vi.fn(); + const { ws, sockets } = await createReconnectingWebSocket({ + onConnectionFailure, + }); + + sockets[0].fireOpen(); + sockets[0].fireClose({ + code: WebSocketCloseCode.ABNORMAL, + reason: "Network error", + }); + + expect(onConnectionFailure).not.toHaveBeenCalled(); + ws.close(); + }); + }); }); type MockSocket = UnidirectionalStream & { @@ -867,6 +954,7 @@ function createMockSocket(): MockSocket { interface FactoryOptions { onDispose?: () => void; onCertificateRefreshNeeded?: () => Promise; + onConnectionFailure?: (reason: ConnectionStateReason) => void; telemetry?: TelemetryReporter; } @@ -929,6 +1017,7 @@ async function fromFactory( telemetry: options.telemetry ?? NOOP_TELEMETRY_REPORTER, onCertificateRefreshNeeded: options.onCertificateRefreshNeeded ?? (() => Promise.resolve(false)), + onConnectionFailure: options.onConnectionFailure, }, options.onDispose, ); diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index 29fd685848..f6d7ac90c0 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -55,6 +55,7 @@ describe("WorkspaceMonitor", () => { const statusBar = new MockStatusBarItem(); const contextManager = new MockContextManager(); const logger = createMockLogger(); + const connectionLogBuffer = { flush: vi.fn() }; const client = { watchWorkspace: vi.fn().mockResolvedValue(stream), getTemplate: vi.fn().mockResolvedValue({ @@ -71,6 +72,7 @@ describe("WorkspaceMonitor", () => { telemetry, logger, contextManager, + connectionLogBuffer, }), ); return { @@ -81,6 +83,7 @@ describe("WorkspaceMonitor", () => { statusBar, contextManager, logger, + connectionLogBuffer, }; } @@ -112,6 +115,18 @@ describe("WorkspaceMonitor", () => { }); }); + describe("connection failure", () => { + it("flushes the connection log buffer when the socket errors", async () => { + const { stream, connectionLogBuffer } = await setup(); + + stream.pushError(new Error("socket boom")); + + expect(connectionLogBuffer.flush).toHaveBeenCalledWith( + "workspace_monitor_error", + ); + }); + }); + describe("state logging", () => { it("logs the initial workspace state as observed with flat scalars", async () => { const { logger } = await setup( From 9c3d21b3a5af58660ec1f43c39b83cabdedbe3f7 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 26 Aug 2026 21:13:05 +0000 Subject: [PATCH 04/60] docs: document the connection log buffer --- CONTRIBUTING.md | 32 ++++++++++++++++++++++++++++++++ 1 file changed, 32 insertions(+) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 5f5d53fa9a..ba42487418 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -132,6 +132,38 @@ next to the code: **[`src/instrumentation/CONVENTIONS.md`](src/instrumentation/CONVENTIONS.md)** +## Logging + +The extension logs to the "Coder" output channel, a `LogOutputChannel` that gates +messages by the level chosen in its gear menu. To help Support diagnose +connection failures without asking users to reproduce with debug logging enabled, +a `BufferingLogger` ([`src/logging/logBuffer.ts`](src/logging/logBuffer.ts)) +wraps the channel and keeps a bounded, in-memory ring of the log lines that sit +**below** the current level — the ones the channel would otherwise drop. + +On a genuine connection failure the buffer is flushed: the captured lines are +re-emitted into the output channel (each marked `[buffered]` with its original +timestamp and level) so they land on disk and in a support bundle. Only +below-level lines are buffered, so nothing already written is duplicated. + +Flush happens only on genuine failures, never on transient drops or intentional +teardown: + +- a reconnecting WebSocket terminal failure (`unrecoverable_close`, + `unrecoverable_http`, `certificate_error`); +- a `WorkspaceMonitor` socket error; +- an agent reported as `disconnected` during connection. + +A short suppression window coalesces the burst of signals a single outage often +triggers into one flush. + +The buffer size is set by `coder.connectionLogBuffer.size` (number of lines; +`0` disables it). It lives in memory, so a hard kill or out-of-memory event +loses it. Extension SSH debug logs that pass through the shared logger are +buffered; the CLI `ProxyCommand` writes its own file logs under +`coder.proxyLogDirectory`, which support bundles already collect from disk, so +those are not buffered here. + ## Testing There are a few ways you can test the "Open in VS Code" flow: From 00b2c58e89daacdffde6565b04a7d9e3721f8e3d Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 8 Sep 2026 21:58:58 -0700 Subject: [PATCH 05/60] refactor: make LEVEL_LABEL readonly --- src/logging/logBuffer.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 0c1a149b70..7384f1c0aa 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -15,7 +15,7 @@ const SEVERITY = { type Level = keyof typeof SEVERITY; -const LEVEL_LABEL: Record = { +const LEVEL_LABEL: Readonly> = { trace: "TRACE", debug: "DEBUG", info: "INFO", From 65e0f5ca5b3c9bbc3bc0753b5406ac30a7f7f961 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 8 Sep 2026 22:00:10 -0700 Subject: [PATCH 06/60] style: move constants before class --- src/core/container.ts | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index 7df2b74568..9dd3a577ac 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -27,6 +27,9 @@ import { sessionId } from "./sessionId"; import type { Logger } from "../logging/logger"; +const CONNECTION_LOG_BUFFER_SIZE_KEY = "coder.connectionLogBuffer.size"; +const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; + /** * Service container for dependency injection. * Centralizes the creation and management of all core services. @@ -229,9 +232,6 @@ export class ServiceContainer implements vscode.Disposable { } } -const CONNECTION_LOG_BUFFER_SIZE_KEY = "coder.connectionLogBuffer.size"; -const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; - function readConnectionLogBufferSize(): number { return vscode.workspace .getConfiguration() From e7108f7ef7b7ce8920348b2fc1af595c6b48b298 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 08:55:11 -0700 Subject: [PATCH 07/60] refactor: rename BufferedEntry to LogEntry --- src/logging/logBuffer.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 7384f1c0aa..e94d25c3d5 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -34,7 +34,7 @@ export interface ConnectionLogBuffer { flush(reason: string): void; } -interface BufferedEntry { +interface LogEntry { readonly atMs: number; readonly level: Level; readonly message: string; @@ -58,7 +58,7 @@ function normalizeCapacity(capacity: number): number { * still writes, so the flush lands regardless of the configured level. */ export class BufferingLogger implements Logger, ConnectionLogBuffer { - private entries: BufferedEntry[] = []; + private entries: LogEntry[] = []; private capacity: number; private currentLevel: number; private lastFlushMs = Number.NEGATIVE_INFINITY; From b647c8b4aa542c7f02b131b59a9cab24bc871491 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 09:00:05 -0700 Subject: [PATCH 08/60] refactor: rename CONNECTION_FAILURE_REASONS to TERMINAL_CONNECTION_FAILURE_REASONS, and isConnectionFailure to isTerminalConnectionFailure --- src/websocket/reconnectingWebSocket.ts | 19 ++++++++----------- .../websocket/reconnectingWebSocket.test.ts | 15 +++++++++------ 2 files changed, 17 insertions(+), 17 deletions(-) diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index 80e1d6aeb1..4a74ce1b7a 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -29,19 +29,16 @@ function toCloseEventError(event: CloseEvent): Error { } /** - * Terminal-failure reasons: the socket has given up and surfaced an error, - * rather than dropping transiently and auto-reconnecting. These are the moments - * worth flushing the connection log buffer. + * Connection failures that stop automatic retries. */ -const CONNECTION_FAILURE_REASONS: ReadonlySet = new Set([ - "unrecoverable_close", - "unrecoverable_http", - "certificate_error", -]); +const TERMINAL_CONNECTION_FAILURE_REASONS: ReadonlySet = + new Set(["unrecoverable_close", "unrecoverable_http", "certificate_error"]); /** Whether a state-transition reason represents a genuine connection failure. */ -export function isConnectionFailure(reason: ConnectionStateReason): boolean { - return CONNECTION_FAILURE_REASONS.has(reason); +export function isTerminalConnectionFailure( + reason: ConnectionStateReason, +): boolean { + return TERMINAL_CONNECTION_FAILURE_REASONS.has(reason); } /** @@ -315,7 +312,7 @@ export class ReconnectingWebSocket< error: options.error, }); this.clearCurrentSocket(options.code, options.closeReason); - if (isConnectionFailure(reason)) { + if (isTerminalConnectionFailure(reason)) { this.#onConnectionFailure?.(reason); } } diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index 0f703a12ea..ae338282b8 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -8,7 +8,7 @@ import { WebSocketCloseCode, HttpStatusCode } from "@/websocket/codes"; import { ConnectionState, ReconnectingWebSocket, - isConnectionFailure, + isTerminalConnectionFailure, type SocketFactory, } from "@/websocket/reconnectingWebSocket"; @@ -802,8 +802,8 @@ describe("ReconnectingWebSocket", () => { "unrecoverable_close", "unrecoverable_http", "certificate_error", - ] as const)("treats %s as a connection failure", (reason) => { - expect(isConnectionFailure(reason)).toBe(true); + ] as const)("treats %s as a terminal connection failure", (reason) => { + expect(isTerminalConnectionFailure(reason)).toBe(true); }); it.each([ @@ -816,9 +816,12 @@ describe("ReconnectingWebSocket", () => { "connection_error", "normal_close", "unexpected_close", - ] as const)("does not treat %s as a connection failure", (reason) => { - expect(isConnectionFailure(reason)).toBe(false); - }); + ] as const)( + "does not treat %s as a terminal connection failure", + (reason) => { + expect(isTerminalConnectionFailure(reason)).toBe(false); + }, + ); it("fires onConnectionFailure on an unrecoverable close code", async () => { const onConnectionFailure = vi.fn(); From 71ec1b10ec7d86ff5ad828edb46bf616f319e893 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 09:03:23 -0700 Subject: [PATCH 09/60] docs: shorten BufferingLogger description comment --- src/logging/logBuffer.ts | 12 ++---------- 1 file changed, 2 insertions(+), 10 deletions(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index e94d25c3d5..9e69dc3a93 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -46,16 +46,8 @@ function normalizeCapacity(capacity: number): number { } /** - * Wraps a {@link Logger} and keeps a bounded, in-memory ring of entries whose - * level is **below the sink's current level** — the ones the sink would - * otherwise drop. On a connection failure, {@link flush} replays those entries - * into the sink so they persist to disk (and any support bundle), giving Support - * the debug detail leading up to the failure without the user having enabled - * debug logging beforehand. - * - * Only below-level entries are buffered, so nothing that the sink already writes - * is ever duplicated. Replay is emitted at the least-verbose level the sink - * still writes, so the flush lands regardless of the configured level. + * Buffers entries below the current log level and replays them on failure at a + * level the output channel persists. */ export class BufferingLogger implements Logger, ConnectionLogBuffer { private entries: LogEntry[] = []; From bd7df6164766a95cc68656c701d98da57df3b13a Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 11:22:20 -0700 Subject: [PATCH 10/60] chore: add coder.connectionLogBuffer.size to COLLECTED_SETTINGS --- src/supportBundle/settings.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/src/supportBundle/settings.ts b/src/supportBundle/settings.ts index 8517d4f1f4..db68e4eda1 100644 --- a/src/supportBundle/settings.ts +++ b/src/supportBundle/settings.ts @@ -17,6 +17,7 @@ const COLLECTED_SETTINGS: readonly string[] = [ "coder.autologin", "coder.binaryDestination", "coder.binarySource", + "coder.connectionLogBuffer.size", "coder.defaultUrl", "coder.disableNotifications", "coder.disableSignatureVerification", From f309f0f20b8d73f1951cc19f189023d59a39f3f5 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 11:29:26 -0700 Subject: [PATCH 11/60] refactor: return single BufferingLogger field from both getLogger and getConnectionLogBuffer --- src/core/container.ts | 12 +++++------- 1 file changed, 5 insertions(+), 7 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index 9dd3a577ac..1cb8de7c7a 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -36,8 +36,7 @@ const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; */ export class ServiceContainer implements vscode.Disposable { private readonly outputChannel: vscode.LogOutputChannel; - private readonly logger: Logger; - private readonly connectionLogBuffer: BufferingLogger; + private readonly logger: BufferingLogger; private readonly disposables: vscode.Disposable[] = []; private readonly pathResolver: PathResolver; private readonly mementoManager: MementoManager; @@ -57,7 +56,7 @@ export class ServiceContainer implements vscode.Disposable { this.outputChannel = vscode.window.createOutputChannel("Coder", { log: true, }); - this.connectionLogBuffer = new BufferingLogger( + this.logger = new BufferingLogger( prefixLogger(this.outputChannel, `[session ${shortId(sessionId)}]`), { getLogLevel: () => this.outputChannel.logLevel, @@ -66,12 +65,11 @@ export class ServiceContainer implements vscode.Disposable { }, readConnectionLogBufferSize(), ); - this.logger = this.connectionLogBuffer; this.disposables.push( - this.connectionLogBuffer, + this.logger, vscode.workspace.onDidChangeConfiguration((event) => { if (event.affectsConfiguration(CONNECTION_LOG_BUFFER_SIZE_KEY)) { - this.connectionLogBuffer.setCapacity(readConnectionLogBufferSize()); + this.logger.setCapacity(readConnectionLogBufferSize()); } }), ); @@ -173,7 +171,7 @@ export class ServiceContainer implements vscode.Disposable { /** The below-level connection log buffer; flush it on a connection failure. */ getConnectionLogBuffer(): ConnectionLogBuffer { - return this.connectionLogBuffer; + return this.logger; } getCliManager(): CliManager { From 600270622ddc735de1f9308135c6d35f67e6ffc0 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 18:53:39 +0000 Subject: [PATCH 12/60] refactor(logging): remove the flush suppression window --- src/logging/logBuffer.ts | 13 ++------ test/unit/logging/logBuffer.test.ts | 51 +++++++++++++---------------- 2 files changed, 25 insertions(+), 39 deletions(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 9e69dc3a93..ad7da68720 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -53,14 +53,12 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { private entries: LogEntry[] = []; private capacity: number; private currentLevel: number; - private lastFlushMs = Number.NEGATIVE_INFINITY; private readonly levelSubscription: { dispose(): void }; public constructor( private readonly inner: Logger, private readonly levelSource: LogLevelSource, capacity: number, - private readonly flushSuppressionMs = 5_000, private readonly now: () => number = Date.now, ) { this.capacity = normalizeCapacity(capacity); @@ -108,19 +106,14 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { } /** - * Replay buffered entries into the sink and clear them. No-op when empty or - * when called again within the suppression window (one outage often trips - * several failure signals at once). + * Replay buffered entries into the sink and clear them. No-op when empty. + * Clearing the buffer means a later flush only replays entries accumulated + * since this one, so consecutive failures never duplicate lines. */ public flush(reason: string): void { - const now = this.now(); - if (now - this.lastFlushMs < this.flushSuppressionMs) { - return; - } if (this.entries.length === 0) { return; } - this.lastFlushMs = now; const entries = this.entries; this.entries = []; diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 8a3f0a7cce..55b7666dc5 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -91,7 +91,6 @@ describe("BufferingLogger", () => { logger, fakeLevelSource(INFO), 10, - 5_000, time.now, ); @@ -142,18 +141,10 @@ describe("BufferingLogger", () => { it("clears the buffer after a flush", () => { const { logger, calls } = recordingLogger(); - const time = clock(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO), - 10, - 5_000, - time.now, - ); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); buffer.debug("d"); buffer.flush("first"); - time.advance(10_000); // past the suppression window calls.length = 0; buffer.flush("second"); @@ -161,33 +152,35 @@ describe("BufferingLogger", () => { expect(calls).toHaveLength(0); }); - it("is a no-op when the buffer is empty", () => { + it("flushes newly accumulated entries on each consecutive failure", () => { const { logger, calls } = recordingLogger(); const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); - buffer.flush("r"); + buffer.debug("before first failure"); + calls.length = 0; + buffer.flush("first"); + const firstLines = calls.map((c) => c.message); + expect(firstLines.some((l) => l.includes("before first failure"))).toBe( + true, + ); - expect(calls).toHaveLength(0); + buffer.debug("before second failure"); + calls.length = 0; + buffer.flush("second"); + const secondLines = calls.map((c) => c.message); + expect(secondLines.some((l) => l.includes("before second failure"))).toBe( + true, + ); + expect(secondLines.some((l) => l.includes("before first failure"))).toBe( + false, + ); }); - it("suppresses a second flush within the suppression window", () => { + it("is a no-op when the buffer is empty", () => { const { logger, calls } = recordingLogger(); - const time = clock(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO), - 10, - 5_000, - time.now, - ); - - buffer.debug("a"); - buffer.flush("first"); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); - time.advance(1_000); // within the window - buffer.debug("b"); - calls.length = 0; - buffer.flush("second"); + buffer.flush("r"); expect(calls).toHaveLength(0); }); From 4cba97b9fad61efb0d716948c1a77c8e0355fed7 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 18:54:56 +0000 Subject: [PATCH 13/60] refactor(logging): use Date.now directly instead of an injected clock --- src/logging/logBuffer.ts | 3 +- test/unit/logging/logBuffer.test.ts | 53 +++++++++++++---------------- 2 files changed, 25 insertions(+), 31 deletions(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index ad7da68720..a479853541 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -59,7 +59,6 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { private readonly inner: Logger, private readonly levelSource: LogLevelSource, capacity: number, - private readonly now: () => number = Date.now, ) { this.capacity = normalizeCapacity(capacity); this.currentLevel = levelSource.getLogLevel(); @@ -154,7 +153,7 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { if (this.capacity === 0 || SEVERITY[level] >= this.currentLevel) { return; } - this.entries.push({ atMs: this.now(), level, message, args }); + this.entries.push({ atMs: Date.now(), level, message, args }); if (this.entries.length > this.capacity) { this.entries.shift(); } diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 55b7666dc5..41fdfc0e92 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -56,14 +56,6 @@ function fakeLevelSource(initial: number): LogLevelSource & { }; } -function clock(start = 1_000): { - now: () => number; - advance(ms: number): void; -} { - let t = start; - return { now: () => t, advance: (ms) => (t += ms) }; -} - describe("BufferingLogger", () => { it("forwards every call to the inner logger", () => { const { logger, calls } = recordingLogger(); @@ -85,27 +77,30 @@ describe("BufferingLogger", () => { }); it("buffers only entries below the current level and replays them on flush", () => { - const { logger, calls } = recordingLogger(); - const time = clock(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO), - 10, - time.now, - ); - - buffer.debug("hidden debug"); - buffer.info("visible info"); - - calls.length = 0; // ignore the pass-through calls - buffer.flush("test_reason"); - - const replayed = calls.filter((c) => c.message.includes("[buffered]")); - // header + one debug line + footer; the info line was at level and not buffered. - expect(replayed).toHaveLength(3); - expect(replayed[0].message).toContain("connection failure (test_reason)"); - expect(replayed[1].message).toContain("DEBUG hidden debug"); - expect(replayed[2].message).toContain("end of buffered logs"); + vi.useFakeTimers(); + try { + vi.setSystemTime(new Date("2024-01-01T00:00:00.000Z")); + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + + buffer.debug("hidden debug"); + buffer.info("visible info"); + + // Flush later; the replay must carry the original record time. + vi.setSystemTime(new Date("2024-01-01T00:05:00.000Z")); + calls.length = 0; // ignore the pass-through calls + buffer.flush("test_reason"); + + const replayed = calls.filter((c) => c.message.includes("[buffered]")); + // header + one debug line + footer; the info line was at level and not buffered. + expect(replayed).toHaveLength(3); + expect(replayed[0].message).toContain("connection failure (test_reason)"); + expect(replayed[1].message).toContain("DEBUG hidden debug"); + expect(replayed[1].message).toContain("2024-01-01T00:00:00.000Z"); + expect(replayed[2].message).toContain("end of buffered logs"); + } finally { + vi.useRealTimers(); + } }); it("does not buffer entries at or above the current level", () => { From 6ce51a504f20727883f14bd251e3bfc8bc453f70 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 18:56:45 +0000 Subject: [PATCH 14/60] refactor(logging): take a single getLogLevel callback instead of LogLevelSource --- src/core/container.ts | 7 +- src/logging/logBuffer.ts | 22 +----- test/unit/logging/logBuffer.test.ts | 103 +++++++++++++++++++--------- 3 files changed, 73 insertions(+), 59 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index 1cb8de7c7a..2fb9261622 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -58,15 +58,10 @@ export class ServiceContainer implements vscode.Disposable { }); this.logger = new BufferingLogger( prefixLogger(this.outputChannel, `[session ${shortId(sessionId)}]`), - { - getLogLevel: () => this.outputChannel.logLevel, - onDidChangeLogLevel: (listener) => - this.outputChannel.onDidChangeLogLevel(listener), - }, + () => this.outputChannel.logLevel, readConnectionLogBufferSize(), ); this.disposables.push( - this.logger, vscode.workspace.onDidChangeConfiguration((event) => { if (event.affectsConfiguration(CONNECTION_LOG_BUFFER_SIZE_KEY)) { this.logger.setCapacity(readConnectionLogBufferSize()); diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index a479853541..7755a218d5 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -23,12 +23,6 @@ const LEVEL_LABEL: Readonly> = { error: "ERROR", }; -/** Reads the sink's effective log level (numeric, matching `vscode.LogLevel`). */ -export interface LogLevelSource { - getLogLevel(): number; - onDidChangeLogLevel(listener: (level: number) => void): { dispose(): void }; -} - /** The failure-time surface used by connection-failure call sites. */ export interface ConnectionLogBuffer { flush(reason: string): void; @@ -52,19 +46,13 @@ function normalizeCapacity(capacity: number): number { export class BufferingLogger implements Logger, ConnectionLogBuffer { private entries: LogEntry[] = []; private capacity: number; - private currentLevel: number; - private readonly levelSubscription: { dispose(): void }; public constructor( private readonly inner: Logger, - private readonly levelSource: LogLevelSource, + private readonly getLogLevel: () => number, capacity: number, ) { this.capacity = normalizeCapacity(capacity); - this.currentLevel = levelSource.getLogLevel(); - this.levelSubscription = levelSource.onDidChangeLogLevel((level) => { - this.currentLevel = level; - }); } public trace(message: string, ...args: unknown[]): void { @@ -129,17 +117,13 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { emit(`[buffered] end of buffered logs (${reason})`); } - public dispose(): void { - this.levelSubscription.dispose(); - } - /** * The least-verbose sink method that is still written at the current level, * so a flush is captured whatever the user's log level (except Off, where the * sink writes nothing). */ private replayEmitter(): (message: string, ...args: unknown[]) => void { - const level = this.levelSource.getLogLevel(); + const level = this.getLogLevel(); if (level >= SEVERITY.error) { return (message, ...args) => this.inner.error(message, ...args); } @@ -150,7 +134,7 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { } private record(level: Level, message: string, args: unknown[]): void { - if (this.capacity === 0 || SEVERITY[level] >= this.currentLevel) { + if (this.capacity === 0 || SEVERITY[level] >= this.getLogLevel()) { return; } this.entries.push({ atMs: Date.now(), level, message, args }); diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 41fdfc0e92..0ac6fb9418 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -1,6 +1,6 @@ import { describe, expect, it, vi } from "vitest"; -import { BufferingLogger, type LogLevelSource } from "@/logging/logBuffer"; +import { BufferingLogger } from "@/logging/logBuffer"; import type { Logger } from "@/logging/logger"; @@ -36,22 +36,15 @@ function recordingLogger(): { logger: Logger; calls: Call[] } { }; } -function fakeLevelSource(initial: number): LogLevelSource & { +function fakeLevelSource(initial: number): { + getLogLevel: () => number; set(level: number): void; } { let level = initial; - const listeners = new Set<(level: number) => void>(); return { getLogLevel: () => level, - onDidChangeLogLevel: (listener) => { - listeners.add(listener); - return { dispose: () => listeners.delete(listener) }; - }, set(next: number) { level = next; - for (const listener of listeners) { - listener(next); - } }, }; } @@ -59,7 +52,11 @@ function fakeLevelSource(initial: number): LogLevelSource & { describe("BufferingLogger", () => { it("forwards every call to the inner logger", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); buffer.trace("t"); buffer.debug("d"); @@ -81,7 +78,11 @@ describe("BufferingLogger", () => { try { vi.setSystemTime(new Date("2024-01-01T00:00:00.000Z")); const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); buffer.debug("hidden debug"); buffer.info("visible info"); @@ -105,7 +106,11 @@ describe("BufferingLogger", () => { it("does not buffer entries at or above the current level", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); buffer.info("i"); buffer.warn("w"); @@ -119,7 +124,11 @@ describe("BufferingLogger", () => { it("evicts the oldest entry when capacity is exceeded", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 2); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 2, + ); buffer.debug("one"); buffer.debug("two"); @@ -136,7 +145,11 @@ describe("BufferingLogger", () => { it("clears the buffer after a flush", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); buffer.debug("d"); buffer.flush("first"); @@ -149,7 +162,11 @@ describe("BufferingLogger", () => { it("flushes newly accumulated entries on each consecutive failure", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); buffer.debug("before first failure"); calls.length = 0; @@ -173,7 +190,11 @@ describe("BufferingLogger", () => { it("is a no-op when the buffer is empty", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); buffer.flush("r"); @@ -183,7 +204,7 @@ describe("BufferingLogger", () => { it("re-evaluates what is below level when the level changes", () => { const { logger, calls } = recordingLogger(); const level = fakeLevelSource(ERROR); - const buffer = new BufferingLogger(logger, level, 10); + const buffer = new BufferingLogger(logger, level.getLogLevel, 10); buffer.info("info at error level"); // below ERROR -> buffered level.set(INFO); @@ -199,7 +220,11 @@ describe("BufferingLogger", () => { it("buffers nothing when capacity is zero", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 0); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 0, + ); buffer.debug("d"); calls.length = 0; @@ -210,7 +235,11 @@ describe("BufferingLogger", () => { it("keeps the most recent entries when shrunk via setCapacity", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); buffer.debug("one"); buffer.debug("two"); @@ -234,7 +263,11 @@ describe("BufferingLogger", () => { "replays at $expected so the flush is written at level $level", ({ level, expected }) => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(level), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(level).getLogLevel, + 10, + ); // Always below the current level so it is buffered. buffer.trace("below"); @@ -248,7 +281,11 @@ describe("BufferingLogger", () => { it("preserves extra args on replay", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(INFO), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + 10, + ); const detail = { code: 1006 }; buffer.debug("dropped", detail); @@ -259,19 +296,13 @@ describe("BufferingLogger", () => { expect(line?.args).toEqual([detail]); }); - it("stops buffering after dispose unsubscribes from level changes", () => { - const { logger } = recordingLogger(); - const level = fakeLevelSource(INFO); - const buffer = new BufferingLogger(logger, level, 10); - - buffer.dispose(); - // Changing the level must not throw or affect the disposed buffer. - expect(() => level.set(ERROR)).not.toThrow(); - }); - it("does not buffer at the Off level", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(OFF), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(OFF).getLogLevel, + 10, + ); buffer.trace("t"); buffer.debug("d"); @@ -283,7 +314,11 @@ describe("BufferingLogger", () => { it("buffers trace but not debug at the Debug level", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeLevelSource(DEBUG), 10); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(DEBUG).getLogLevel, + 10, + ); buffer.trace("trace line"); buffer.debug("debug line"); From a16495e2b8242005e4f8a9e61d5c8b888ec8e4c3 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 18:57:15 +0000 Subject: [PATCH 15/60] refactor(container): dispose the log buffer config subscription via a named field --- src/core/container.ts | 11 ++++------- 1 file changed, 4 insertions(+), 7 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index 2fb9261622..3d6da92aca 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -37,7 +37,7 @@ const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; export class ServiceContainer implements vscode.Disposable { private readonly outputChannel: vscode.LogOutputChannel; private readonly logger: BufferingLogger; - private readonly disposables: vscode.Disposable[] = []; + private readonly connectionLogBufferConfigSubscription: vscode.Disposable; private readonly pathResolver: PathResolver; private readonly mementoManager: MementoManager; private readonly secretsManager: SecretsManager; @@ -61,13 +61,12 @@ export class ServiceContainer implements vscode.Disposable { () => this.outputChannel.logLevel, readConnectionLogBufferSize(), ); - this.disposables.push( + this.connectionLogBufferConfigSubscription = vscode.workspace.onDidChangeConfiguration((event) => { if (event.affectsConfiguration(CONNECTION_LOG_BUFFER_SIZE_KEY)) { this.logger.setCapacity(readConnectionLogBufferSize()); } - }), - ); + }); this.pathResolver = new PathResolver( context.globalStorageUri.fsPath, context.logUri.fsPath, @@ -214,9 +213,7 @@ export class ServiceContainer implements vscode.Disposable { this.commandManager.dispose(); this.contextManager.dispose(); this.loginCoordinator.dispose(); - for (const disposable of this.disposables) { - disposable.dispose(); - } + this.connectionLogBufferConfigSubscription.dispose(); try { await this.telemetryService.dispose(); } finally { From 2c389f454b5f7bcb25d37d258abdc3e8563869f2 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 18:58:22 +0000 Subject: [PATCH 16/60] refactor(workspace): stop flushing the log buffer from the monitor's notifyError --- src/workspace/workspaceMonitor.ts | 4 ---- test/unit/workspace/workspaceMonitor.test.ts | 12 ------------ 2 files changed, 16 deletions(-) diff --git a/src/workspace/workspaceMonitor.ts b/src/workspace/workspaceMonitor.ts index 20cf6a0168..debcf6c545 100644 --- a/src/workspace/workspaceMonitor.ts +++ b/src/workspace/workspaceMonitor.ts @@ -26,7 +26,6 @@ import { import type { CoderApi } from "../api/coderApi"; import type { ServiceContainer } from "../core/container"; import type { ContextManager } from "../core/contextManager"; -import type { ConnectionLogBuffer } from "../logging/logBuffer"; import type { Logger } from "../logging/logger"; import type { TelemetryReporter } from "../telemetry/reporter"; import type { UnidirectionalStream } from "../websocket/eventStreamConnection"; @@ -64,7 +63,6 @@ export class WorkspaceMonitor implements vscode.Disposable { private readonly agentObserver = new WorkspaceAgentObserver(); private readonly logger: Logger; private readonly contextManager: ContextManager; - private readonly connectionLogBuffer: ConnectionLogBuffer; private latestWorkspace: Workspace; @@ -75,7 +73,6 @@ export class WorkspaceMonitor implements vscode.Disposable { ) { this.logger = container.getLogger(); this.contextManager = container.getContextManager(); - this.connectionLogBuffer = container.getConnectionLogBuffer(); this.name = createWorkspaceIdentifier(workspace); this.telemetry = container.getTelemetryService(); this.latestWorkspace = workspace; @@ -315,7 +312,6 @@ export class WorkspaceMonitor implements vscode.Disposable { "Got empty error while monitoring workspace", ); this.logger.error(message); - this.connectionLogBuffer.flush("workspace_monitor_error"); } private updateContext(workspace: Workspace) { diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index f6d7ac90c0..74365d4970 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -115,18 +115,6 @@ describe("WorkspaceMonitor", () => { }); }); - describe("connection failure", () => { - it("flushes the connection log buffer when the socket errors", async () => { - const { stream, connectionLogBuffer } = await setup(); - - stream.pushError(new Error("socket boom")); - - expect(connectionLogBuffer.flush).toHaveBeenCalledWith( - "workspace_monitor_error", - ); - }); - }); - describe("state logging", () => { it("logs the initial workspace state as observed with flat scalars", async () => { const { logger } = await setup( From d6e49dd293934ed62f4165e4cbdf032dc873c7be Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 19:01:30 +0000 Subject: [PATCH 17/60] feat(remote): flush the log buffer on the workspace client's terminal socket failures --- src/remote/remote.ts | 2 ++ test/unit/api/coderApi.test.ts | 51 +++++++++++++++++++++++++++++++++- 2 files changed, 52 insertions(+), 1 deletion(-) diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 612da18f57..dcbe4e575c 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -280,6 +280,8 @@ export class Remote { token, this.logger, this.serviceContainer.getTelemetryService(), + (reason) => + this.serviceContainer.getConnectionLogBuffer().flush(reason), ); disposables.push(workspaceClient); diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index b3eca3fc48..c5e1212d39 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -37,6 +37,7 @@ import { NOOP_TELEMETRY_REPORTER, type TelemetryReporter, } from "@/telemetry/reporter"; +import { WebSocketCloseCode } from "@/websocket/codes"; import { ReconnectingWebSocket } from "@/websocket/reconnectingWebSocket"; import { @@ -114,8 +115,15 @@ describe("CoderApi", () => { url = CODER_URL, token = AXIOS_TOKEN, telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, + onConnectionFailure?: (reason: string) => void, ) => { - return CoderApi.create(url, token, mockLogger, telemetry); + return CoderApi.create( + url, + token, + mockLogger, + telemetry, + onConnectionFailure, + ); }; beforeEach(() => { @@ -574,6 +582,47 @@ describe("CoderApi", () => { }); }); + describe("connection failure callback", () => { + it("invokes onConnectionFailure on a terminal socket failure", async () => { + const onConnectionFailure = vi.fn(); + const failingApi = createApi( + CODER_URL, + AXIOS_TOKEN, + NOOP_TELEMETRY_REPORTER, + onConnectionFailure, + ); + + let closeHandler: ((event: unknown) => void) | undefined; + const mockWs = createMockWebSocket( + `wss://${CODER_URL.replace("https://", "")}/api/v2/workspaceagents/${AGENT_ID}/watch-metadata-ws`, + { + on: vi.fn((event: string, handler: (e: unknown) => void) => { + if (event === "open") { + setImmediate(() => handler(undefined)); + } + if (event === "close") { + closeHandler = handler; + } + return mockWs as Ws; + }), + }, + ); + setupWebSocketMock(mockWs); + + const connection = await failingApi.watchAgentMetadata(AGENT_ID); + + // An unrecoverable close code is a terminal failure, not a retry. + closeHandler?.({ + code: WebSocketCloseCode.PROTOCOL_ERROR, + reason: "Unrecoverable", + wasClean: false, + }); + + expect(onConnectionFailure).toHaveBeenCalledWith("unrecoverable_close"); + connection.close(); + }); + }); + describe("SSE Fallback", () => { beforeEach(() => { api = createApi(); From 50cb93510095cff52256c3a6da5c9ecaf941c423 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 19:02:09 +0000 Subject: [PATCH 18/60] test(workspace): assert malformed messages do not flush the log buffer --- test/unit/workspace/workspaceMonitor.test.ts | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index 74365d4970..5cfe716a76 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -115,6 +115,17 @@ describe("WorkspaceMonitor", () => { }); }); + describe("connection failure", () => { + it("does not flush the log buffer on a malformed message", async () => { + const { stream, connectionLogBuffer } = await setup(); + + // A parse/processing error is not a socket failure, so nothing flushes. + stream.pushError(new Error("malformed message")); + + expect(connectionLogBuffer.flush).not.toHaveBeenCalled(); + }); + }); + describe("state logging", () => { it("logs the initial workspace state as observed with flat scalars", async () => { const { logger } = await setup( From ce55a5b65155c635eb8a2deb3edcaf7ed18b753d Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 19:50:03 +0000 Subject: [PATCH 19/60] feat(logging): cap the connection log buffer size and describe it as entries --- package.json | 3 ++- src/logging/logBuffer.ts | 11 +++++++++- test/unit/logging/logBuffer.test.ts | 32 ++++++++++++++++++++++++++++- 3 files changed, 43 insertions(+), 3 deletions(-) diff --git a/package.json b/package.json index 6673e19fc3..96fcdab25f 100644 --- a/package.json +++ b/package.json @@ -216,9 +216,10 @@ "default": 250 }, "coder.connectionLogBuffer.size": { - "markdownDescription": "Number of connection debug log lines to keep in memory below the current log level. On a connection failure they are written out so a support bundle captures the detail leading up to it, without debug logging enabled beforehand. Set to `0` to disable. The buffer is lost on a hard kill or out-of-memory event.", + "markdownDescription": "Maximum number of connection debug log entries to keep in memory below the current log level. Each entry may span multiple lines and structured arguments. On a connection failure they are written out so a support bundle captures the detail leading up to it, without debug logging enabled beforehand. Set to `0` to disable. Values above `10000` are clamped to `10000`. The buffer is lost on a hard kill or out-of-memory event.", "type": "number", "minimum": 0, + "maximum": 10000, "default": 1000 }, "coder.httpClientLogLevel": { diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 7755a218d5..dc2dd3f053 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -35,8 +35,17 @@ interface LogEntry { readonly args: unknown[]; } +/** + * Largest configurable capacity, as an entry count. Bounds worst-case memory + * so a typo or an unreasonable setting cannot grow the buffer without limit. + */ +export const MAX_CONNECTION_LOG_BUFFER_SIZE = 10_000; + function normalizeCapacity(capacity: number): number { - return Number.isFinite(capacity) && capacity > 0 ? Math.floor(capacity) : 0; + if (!Number.isFinite(capacity) || capacity <= 0) { + return 0; + } + return Math.min(Math.floor(capacity), MAX_CONNECTION_LOG_BUFFER_SIZE); } /** diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 0ac6fb9418..781b6fcc7c 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -1,6 +1,9 @@ import { describe, expect, it, vi } from "vitest"; -import { BufferingLogger } from "@/logging/logBuffer"; +import { + BufferingLogger, + MAX_CONNECTION_LOG_BUFFER_SIZE, +} from "@/logging/logBuffer"; import type { Logger } from "@/logging/logger"; @@ -218,6 +221,33 @@ describe("BufferingLogger", () => { expect(lines.some((l) => l.includes("info at info level"))).toBe(false); }); + it("clamps capacity to the maximum, evicting beyond it", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger( + logger, + fakeLevelSource(INFO).getLogLevel, + MAX_CONNECTION_LOG_BUFFER_SIZE + 5, + ); + + for (let i = 0; i < MAX_CONNECTION_LOG_BUFFER_SIZE + 5; i++) { + buffer.debug(`entry ${i}`); + } + + calls.length = 0; + buffer.flush("r"); + + // header + capped entries + footer; the oldest 5 were evicted. + const buffered = calls.filter((c) => c.message.includes("entry ")); + expect(buffered).toHaveLength(MAX_CONNECTION_LOG_BUFFER_SIZE); + const lines = buffered.map((c) => c.message); + expect(lines.some((l) => l.endsWith("entry 0"))).toBe(false); + expect( + lines.some((l) => + l.endsWith(`entry ${MAX_CONNECTION_LOG_BUFFER_SIZE + 4}`), + ), + ).toBe(true); + }); + it("buffers nothing when capacity is zero", () => { const { logger, calls } = recordingLogger(); const buffer = new BufferingLogger( From 5ae77bc1183620f626d529217f4bc8a023c69d58 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 9 Sep 2026 19:50:03 +0000 Subject: [PATCH 20/60] docs: sync connection log buffer notes with the flush and suppression changes --- CONTRIBUTING.md | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index ba42487418..c5a84c1bfb 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -151,14 +151,10 @@ teardown: - a reconnecting WebSocket terminal failure (`unrecoverable_close`, `unrecoverable_http`, `certificate_error`); -- a `WorkspaceMonitor` socket error; - an agent reported as `disconnected` during connection. -A short suppression window coalesces the burst of signals a single outage often -triggers into one flush. - -The buffer size is set by `coder.connectionLogBuffer.size` (number of lines; -`0` disables it). It lives in memory, so a hard kill or out-of-memory event +The buffer size is set by `coder.connectionLogBuffer.size` (maximum number of +entries, capped at 10,000; `0` disables it). It lives in memory, so a hard kill or out-of-memory event loses it. Extension SSH debug logs that pass through the shared logger are buffered; the CLI `ProxyCommand` writes its own file logs under `coder.proxyLogDirectory`, which support bundles already collect from disk, so From b8bf5bac59a1ce2b6cebc296202f38c9a7fbc9b7 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Thu, 10 Sep 2026 14:28:03 -0700 Subject: [PATCH 21/60] docs: trim/correct buffering logger descriptions --- CONTRIBUTING.md | 8 ++++---- package.json | 2 +- 2 files changed, 5 insertions(+), 5 deletions(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index c5a84c1bfb..eb773c2b39 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -138,13 +138,13 @@ The extension logs to the "Coder" output channel, a `LogOutputChannel` that gate messages by the level chosen in its gear menu. To help Support diagnose connection failures without asking users to reproduce with debug logging enabled, a `BufferingLogger` ([`src/logging/logBuffer.ts`](src/logging/logBuffer.ts)) -wraps the channel and keeps a bounded, in-memory ring of the log lines that sit +wraps the channel and keeps a bounded, in-memory ring of the entries that sit **below** the current level — the ones the channel would otherwise drop. -On a genuine connection failure the buffer is flushed: the captured lines are +On a genuine connection failure the buffer is flushed: the captured entries are re-emitted into the output channel (each marked `[buffered]` with its original timestamp and level) so they land on disk and in a support bundle. Only -below-level lines are buffered, so nothing already written is duplicated. +below-level entries are buffered, so nothing already written is duplicated. Flush happens only on genuine failures, never on transient drops or intentional teardown: @@ -156,7 +156,7 @@ teardown: The buffer size is set by `coder.connectionLogBuffer.size` (maximum number of entries, capped at 10,000; `0` disables it). It lives in memory, so a hard kill or out-of-memory event loses it. Extension SSH debug logs that pass through the shared logger are -buffered; the CLI `ProxyCommand` writes its own file logs under +buffered. The CLI `ProxyCommand` writes its own file logs under `coder.proxyLogDirectory`, which support bundles already collect from disk, so those are not buffered here. diff --git a/package.json b/package.json index 96fcdab25f..3d9db5d697 100644 --- a/package.json +++ b/package.json @@ -216,7 +216,7 @@ "default": 250 }, "coder.connectionLogBuffer.size": { - "markdownDescription": "Maximum number of connection debug log entries to keep in memory below the current log level. Each entry may span multiple lines and structured arguments. On a connection failure they are written out so a support bundle captures the detail leading up to it, without debug logging enabled beforehand. Set to `0` to disable. Values above `10000` are clamped to `10000`. The buffer is lost on a hard kill or out-of-memory event.", + "markdownDescription": "Maximum number of log entries below the Coder output channel's log level to keep in memory. When a connection fails, the extension writes them to the channel so a support bundle includes the detail leading up to the failure without debug logging enabled beforehand. Set to `0` to disable.", "type": "number", "minimum": 0, "maximum": 10000, From 3308ec0c1d8f1868723b24abdf37da3b05d215cc Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 00:00:44 +0000 Subject: [PATCH 22/60] fix(websocket): register non-message events via addEventListener for CloseEvent codes --- src/websocket/oneWayWebSocket.ts | 58 +++++++++++++++++++++++++++++--- test/unit/api/coderApi.test.ts | 12 ++++++- 2 files changed, 64 insertions(+), 6 deletions(-) diff --git a/src/websocket/oneWayWebSocket.ts b/src/websocket/oneWayWebSocket.ts index c028e593c4..af43fc37ca 100644 --- a/src/websocket/oneWayWebSocket.ts +++ b/src/websocket/oneWayWebSocket.ts @@ -80,9 +80,34 @@ export class OneWayWebSocket< this.#socket.on("message", wrapped); this.#messageCallbacks.set(messageCallback, wrapped); - } else { - // For other events, cast and add directly - this.#socket.on(event, callback); + return; + } + + // `ws` only exposes `.code`/`.reason` on the DOM-style CloseEvent from + // addEventListener; the `on()` emitter passes them positionally, which + // leaves `event.code` undefined for consumers. + switch (event) { + case "open": + this.#socket.addEventListener( + "open", + callback as EventHandler, + ); + break; + case "close": + this.#socket.addEventListener( + "close", + callback as EventHandler, + ); + break; + case "error": + this.#socket.addEventListener( + "error", + callback as EventHandler, + ); + break; + case "message": + // Handled above via the early return. + break; } } @@ -98,8 +123,31 @@ export class OneWayWebSocket< this.#socket.off("message", wrapper); this.#messageCallbacks.delete(messageCallback); } - } else { - this.#socket.off(event, callback); + return; + } + + switch (event) { + case "open": + this.#socket.removeEventListener( + "open", + callback as EventHandler, + ); + break; + case "close": + this.#socket.removeEventListener( + "close", + callback as EventHandler, + ); + break; + case "error": + this.#socket.removeEventListener( + "error", + callback as EventHandler, + ); + break; + case "message": + // Handled above via the early return. + break; } } diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index c5e1212d39..6ce69c14c0 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -1231,13 +1231,23 @@ function createMockWebSocket( url: string, overrides?: Partial, ): Partial { - return { + const mock: Partial = { url, on: vi.fn(), off: vi.fn(), close: vi.fn(), ...overrides, }; + // OneWayWebSocket registers open/close/error via addEventListener and only + // message via on(). Tests still stub those handlers through `on`, so delegate + // unless a test provides its own addEventListener. + if (!overrides?.addEventListener) { + mock.addEventListener = mock.on as Ws["addEventListener"]; + } + if (!overrides?.removeEventListener) { + mock.removeEventListener = mock.off as Ws["removeEventListener"]; + } + return mock; } type MockEventSource = Partial & { From 30d9b0809afdf6a6c4c952a3a59fe8dacc6dc4eb Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 00:01:38 +0000 Subject: [PATCH 23/60] test(workspace): drop the un-failable monitor buffer test and its plumbing --- test/unit/workspace/workspaceMonitor.test.ts | 14 -------------- 1 file changed, 14 deletions(-) diff --git a/test/unit/workspace/workspaceMonitor.test.ts b/test/unit/workspace/workspaceMonitor.test.ts index 5cfe716a76..29fd685848 100644 --- a/test/unit/workspace/workspaceMonitor.test.ts +++ b/test/unit/workspace/workspaceMonitor.test.ts @@ -55,7 +55,6 @@ describe("WorkspaceMonitor", () => { const statusBar = new MockStatusBarItem(); const contextManager = new MockContextManager(); const logger = createMockLogger(); - const connectionLogBuffer = { flush: vi.fn() }; const client = { watchWorkspace: vi.fn().mockResolvedValue(stream), getTemplate: vi.fn().mockResolvedValue({ @@ -72,7 +71,6 @@ describe("WorkspaceMonitor", () => { telemetry, logger, contextManager, - connectionLogBuffer, }), ); return { @@ -83,7 +81,6 @@ describe("WorkspaceMonitor", () => { statusBar, contextManager, logger, - connectionLogBuffer, }; } @@ -115,17 +112,6 @@ describe("WorkspaceMonitor", () => { }); }); - describe("connection failure", () => { - it("does not flush the log buffer on a malformed message", async () => { - const { stream, connectionLogBuffer } = await setup(); - - // A parse/processing error is not a socket failure, so nothing flushes. - stream.pushError(new Error("malformed message")); - - expect(connectionLogBuffer.flush).not.toHaveBeenCalled(); - }); - }); - describe("state logging", () => { it("logs the initial workspace state as observed with flat scalars", async () => { const { logger } = await setup( From 8fd78781b72cbded284b664cfb18514e1d894642 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 00:07:19 +0000 Subject: [PATCH 24/60] feat(logging): refocus buffer flush triggers on genuine connection failures Exclude UNAUTHORIZED handshakes (token refresh reconnects), fix the unrecoverable-HTTP substring match, move workspace-open failures to the single extension catch, and pass the socket route into the flush. --- src/api/coderApi.ts | 6 +- src/extension.ts | 4 +- src/remote/remote.ts | 6 +- src/remote/workspaceStateMachine.ts | 4 -- src/websocket/reconnectingWebSocket.ts | 50 ++++++++++----- test/mocks/testHelpers.ts | 6 +- test/unit/api/coderApi.test.ts | 5 +- .../unit/remote/workspaceStateMachine.test.ts | 9 +-- .../websocket/reconnectingWebSocket.test.ts | 62 ++++++++++++++++++- 9 files changed, 113 insertions(+), 39 deletions(-) diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index 249b24d2db..c93bdf8d5b 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -128,6 +128,7 @@ export class CoderApi extends Api implements vscode.Disposable { private readonly authConfigTracker: AuthConfigTracker, private readonly onConnectionFailure?: ( reason: ConnectionStateReason, + route: string, ) => void, ) { super(); @@ -149,7 +150,10 @@ export class CoderApi extends Api implements vscode.Disposable { token: string | undefined, output: Logger, telemetry: TelemetryReporter = NOOP_TELEMETRY_REPORTER, - onConnectionFailure?: (reason: ConnectionStateReason) => void, + onConnectionFailure?: ( + reason: ConnectionStateReason, + route: string, + ) => void, ): CoderApi { const httpRequestsTelemetry = new HttpRequestsTelemetry(telemetry); const authConfigTracker = new AuthConfigTracker(); diff --git a/src/extension.ts b/src/extension.ts index 6d6294e3d9..8abd5c5657 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -143,7 +143,8 @@ async function doActivate( deploymentSessionAuth?.token, output, telemetryService, - (reason) => serviceContainer.getConnectionLogBuffer().flush(reason), + (reason, route) => + serviceContainer.getConnectionLogBuffer().flush(`${reason} ${route}`), ); ctx.subscriptions.push(client); @@ -512,6 +513,7 @@ async function doActivate( ); } // Always close remote session when we fail to open a workspace. + serviceContainer.getConnectionLogBuffer().flush("workspace_open_failed"); await remote.closeRemote(); return; } diff --git a/src/remote/remote.ts b/src/remote/remote.ts index dcbe4e575c..99b3c98472 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -280,8 +280,10 @@ export class Remote { token, this.logger, this.serviceContainer.getTelemetryService(), - (reason) => - this.serviceContainer.getConnectionLogBuffer().flush(reason), + (reason, route) => + this.serviceContainer + .getConnectionLogBuffer() + .flush(`${reason} ${route}`), ); disposables.push(workspaceClient); diff --git a/src/remote/workspaceStateMachine.ts b/src/remote/workspaceStateMachine.ts index 0e44f9fa93..fc4242d967 100644 --- a/src/remote/workspaceStateMachine.ts +++ b/src/remote/workspaceStateMachine.ts @@ -32,7 +32,6 @@ import type { CoderApi } from "../api/coderApi"; import type { ServiceContainer } from "../core/container"; import type { StartupMode } from "../core/mementoManager"; import type { FeatureSet } from "../featureSet"; -import type { ConnectionLogBuffer } from "../logging/logBuffer"; import type { Logger } from "../logging/logger"; import type { CliAuth } from "../settings/cli"; import type { AuthorityParts } from "../util/authority"; @@ -51,7 +50,6 @@ export class WorkspaceStateMachine implements vscode.Disposable { private workspace: Workspace | undefined; private readonly logger: Logger; - private readonly connectionLogBuffer: ConnectionLogBuffer; constructor( private readonly parts: AuthorityParts, @@ -63,7 +61,6 @@ export class WorkspaceStateMachine implements vscode.Disposable { container: ServiceContainer, ) { this.logger = container.getLogger(); - this.connectionLogBuffer = container.getConnectionLogBuffer(); this.terminal = new TerminalOutputChannel("Coder: Workspace Build"); const telemetry = container.getTelemetryService(); const workspaceName = `${parts.username}/${parts.workspace}`; @@ -192,7 +189,6 @@ export class WorkspaceStateMachine implements vscode.Disposable { return false; case "disconnected": - this.connectionLogBuffer.flush("agent_disconnected"); throw new Error(`Agent ${workspaceName}/${agent.name} disconnected`); case "timeout": diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index 4a74ce1b7a..6d2f8108a0 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -8,6 +8,7 @@ import { import { WebSocketCloseCode, + HttpStatusCode, NORMAL_CLOSURE_CODES, UNRECOVERABLE_WS_CLOSE_CODES, UNRECOVERABLE_HTTP_CODES, @@ -131,7 +132,7 @@ export interface ReconnectingWebSocketOptions { /** Callback invoked when a refreshable certificate error is detected. Returns true if refresh succeeded. */ onCertificateRefreshNeeded: () => Promise; /** Callback invoked when the connection fails terminally (not a transient drop). */ - onConnectionFailure?: (reason: ConnectionStateReason) => void; + onConnectionFailure?: (reason: ConnectionStateReason, route: string) => void; } export class ReconnectingWebSocket< @@ -143,7 +144,10 @@ export class ReconnectingWebSocket< readonly #options: Required< Omit >; - readonly #onConnectionFailure?: (reason: ConnectionStateReason) => void; + readonly #onConnectionFailure?: ( + reason: ConnectionStateReason, + route: string, + ) => void; readonly #eventHandlers: { [K in WebSocketEventType]: Set>; } = { @@ -301,7 +305,12 @@ export class ReconnectingWebSocket< private disconnectWithReason( reason: ConnectionStateReason, cause: ConnectionDropCause, - options: { code?: number; closeReason?: string; error?: unknown } = {}, + options: { + code?: number; + closeReason?: string; + error?: unknown; + flushable?: boolean; + } = {}, ): void { if (!this.#dispatch({ type: "DISCONNECT" }, reason)) { return; @@ -312,8 +321,8 @@ export class ReconnectingWebSocket< error: options.error, }); this.clearCurrentSocket(options.code, options.closeReason); - if (isTerminalConnectionFailure(reason)) { - this.#onConnectionFailure?.(reason); + if (isTerminalConnectionFailure(reason) && options.flushable !== false) { + this.#onConnectionFailure?.(reason, this.#route); } } @@ -418,7 +427,7 @@ export class ReconnectingWebSocket< if (UNRECOVERABLE_WS_CLOSE_CODES.has(event.code)) { this.#logger.error( - `WebSocket connection closed with unrecoverable error code ${event.code}`, + `WebSocket connection closed with unrecoverable error code ${event.code} for ${this.#route}`, ); this.disconnectWithReason("unrecoverable_close", "unrecoverable_close", { code: event.code, @@ -537,12 +546,18 @@ export class ReconnectingWebSocket< return; } - if (this.isUnrecoverableHttpError(error)) { + const unrecoverableStatus = this.unrecoverableHttpStatus(error); + if (unrecoverableStatus !== undefined) { this.#logger.error( - `Unrecoverable HTTP error during connection for ${this.#route}`, + `Unrecoverable HTTP error (${unrecoverableStatus}) during connection for ${this.#route}`, error, ); - this.disconnectWithReason("unrecoverable_http", "error", { error }); + // An expired token surfaces as 401, but OAuth refreshes and reconnects + // the same socket seconds later, so it is not a genuine outage to flush. + this.disconnectWithReason("unrecoverable_http", "error", { + error, + flushable: unrecoverableStatus !== HttpStatusCode.UNAUTHORIZED, + }); return; } @@ -562,16 +577,19 @@ export class ReconnectingWebSocket< } /** - * Check if an error message contains an unrecoverable HTTP status code. + * Returns the unrecoverable HTTP status carried by a failed handshake, or + * `undefined`. Matches the `ws` "Unexpected server response: " message + * exactly so host/port digits like `127.0.0.1:4040` cannot masquerade as a + * status code. */ - private isUnrecoverableHttpError(error: unknown): boolean { + private unrecoverableHttpStatus(error: unknown): number | undefined { const message = (error as { message?: string }).message || String(error); - for (const code of UNRECOVERABLE_HTTP_CODES) { - if (message.includes(String(code))) { - return true; - } + const match = /unexpected server response:\s*(\d{3})/i.exec(message); + if (!match) { + return undefined; } - return false; + const status = Number(match[1]); + return UNRECOVERABLE_HTTP_CODES.has(status) ? status : undefined; } private dispose(code?: number, reason?: string): void { diff --git a/test/mocks/testHelpers.ts b/test/mocks/testHelpers.ts index b3d07a83a8..bc5959cc29 100644 --- a/test/mocks/testHelpers.ts +++ b/test/mocks/testHelpers.ts @@ -626,14 +626,10 @@ export function createMockServiceContainer( pathResolver?: PathResolver; contextManager?: ContextManagerLike; loginCoordinator?: LoginCoordinatorLike; - connectionLogBuffer?: ConnectionLogBuffer; } = {}, ): ServiceContainer { const telemetry = overrides.telemetry ?? createTestTelemetryService(); const logger = overrides.logger ?? createMockLogger(); - const connectionLogBuffer = overrides.connectionLogBuffer ?? { - flush: () => {}, - }; const require = (name: string, value: T | undefined): T => { if (value === undefined) { throw new Error(`createMockServiceContainer: '${name}' was not provided`); @@ -643,7 +639,7 @@ export function createMockServiceContainer( return { getTelemetryService: () => telemetry, getLogger: () => logger, - getConnectionLogBuffer: () => connectionLogBuffer, + getConnectionLogBuffer: (): ConnectionLogBuffer => ({ flush: () => {} }), getSecretsManager: () => require("secretsManager", overrides.secretsManager), getMementoManager: () => diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index 6ce69c14c0..728472266f 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -618,7 +618,10 @@ describe("CoderApi", () => { wasClean: false, }); - expect(onConnectionFailure).toHaveBeenCalledWith("unrecoverable_close"); + expect(onConnectionFailure).toHaveBeenCalledWith( + "unrecoverable_close", + expect.any(String), + ); connection.close(); }); }); diff --git a/test/unit/remote/workspaceStateMachine.test.ts b/test/unit/remote/workspaceStateMachine.test.ts index ee50360fd1..97e654bc36 100644 --- a/test/unit/remote/workspaceStateMachine.test.ts +++ b/test/unit/remote/workspaceStateMachine.test.ts @@ -103,7 +103,6 @@ function setup( enableLocalTelemetry(); const progress = new MockProgress<{ message?: string }>(); const userInteraction = new MockUserInteraction(); - const connectionLogBuffer = { flush: vi.fn() }; const sm = new WorkspaceStateMachine( DEFAULT_PARTS, {} as CoderApi, @@ -114,10 +113,9 @@ function setup( createMockServiceContainer({ telemetry, logger: createMockLogger(), - connectionLogBuffer, }), ); - return { sm, progress, userInteraction, connectionLogBuffer }; + return { sm, progress, userInteraction }; } describe("WorkspaceStateMachine", () => { @@ -153,14 +151,11 @@ describe("WorkspaceStateMachine", () => { }); it("throws when agent is disconnected", async () => { - const { sm, progress, connectionLogBuffer } = setup(); + const { sm, progress } = setup(); const ws = runningWorkspace({ status: "disconnected" }); await expect(sm.processWorkspace(ws, progress)).rejects.toThrow( "disconnected", ); - expect(connectionLogBuffer.flush).toHaveBeenCalledWith( - "agent_disconnected", - ); }); it("triggers update and falls through to agent check", async () => { diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index ae338282b8..f0939bec47 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -152,6 +152,61 @@ describe("ReconnectingWebSocket", () => { }, ); + it("does not flush on an unrecoverable 401 (token refresh reconnects the same socket)", async () => { + const onConnectionFailure = vi.fn(); + const { ws, sockets } = await createReconnectingWebSocket({ + onConnectionFailure, + }); + + sockets[0].fireError( + new Error(`Unexpected server response: ${HttpStatusCode.UNAUTHORIZED}`), + ); + + expect(ws.state).toBe(ConnectionState.DISCONNECTED); + expect(onConnectionFailure).not.toHaveBeenCalled(); + ws.close(); + }); + + it.each([ + HttpStatusCode.FORBIDDEN, + HttpStatusCode.GONE, + HttpStatusCode.UPGRADE_REQUIRED, + ])( + "flushes with the route on an unrecoverable HTTP failure: %i", + async (statusCode) => { + const onConnectionFailure = vi.fn(); + const { ws, sockets } = await createReconnectingWebSocket({ + onConnectionFailure, + }); + + sockets[0].fireError( + new Error(`Unexpected server response: ${statusCode}`), + ); + + expect(onConnectionFailure).toHaveBeenCalledWith( + "unrecoverable_http", + expect.any(String), + ); + ws.close(); + }, + ); + + it("does not read host/port digits as a status code", async () => { + const onConnectionFailure = vi.fn(); + const { ws, sockets } = await createReconnectingWebSocket({ + onConnectionFailure, + }); + + // A port ending in 404x must not be treated as HTTP 404. + sockets[0].fireError(new Error("connect ECONNREFUSED 127.0.0.1:4040")); + + expect(onConnectionFailure).not.toHaveBeenCalled(); + // Generic connection errors retry rather than terminate. + await vi.advanceTimersByTimeAsync(1000); + expect(sockets.length).toBeGreaterThan(1); + ws.close(); + }); + it("reconnect() connects immediately and cancels pending reconnections", async () => { const { ws, sockets } = await createReconnectingWebSocket(); @@ -835,7 +890,10 @@ describe("ReconnectingWebSocket", () => { reason: "Unrecoverable", }); - expect(onConnectionFailure).toHaveBeenCalledWith("unrecoverable_close"); + expect(onConnectionFailure).toHaveBeenCalledWith( + "unrecoverable_close", + expect.any(String), + ); ws.close(); }); @@ -957,7 +1015,7 @@ function createMockSocket(): MockSocket { interface FactoryOptions { onDispose?: () => void; onCertificateRefreshNeeded?: () => Promise; - onConnectionFailure?: (reason: ConnectionStateReason) => void; + onConnectionFailure?: (reason: ConnectionStateReason, route: string) => void; telemetry?: TelemetryReporter; } From 1e01b30aa8b7281714c5732fef9b9e67ace43479 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 00:12:27 +0000 Subject: [PATCH 25/60] refactor(settings): move logger setting readers into src/settings/logger.ts --- src/api/coderApi.ts | 17 +--- src/core/container.ts | 40 +++++---- src/logging/logBuffer.ts | 28 ++---- src/settings/logger.ts | 50 +++++++++++ test/unit/logging/logBuffer.test.ts | 129 ++++------------------------ test/unit/settings/logger.test.ts | 65 ++++++++++++++ 6 files changed, 165 insertions(+), 164 deletions(-) create mode 100644 src/settings/logger.ts create mode 100644 test/unit/settings/logger.test.ts diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index c93bdf8d5b..b445352691 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -25,13 +25,11 @@ import { logResponse, } from "../logging/httpLogger"; import { HttpRequestsTelemetry } from "../logging/httpRequestsTelemetry"; -import { - HttpClientLogLevel, - type RequestConfigWithMeta, -} from "../logging/types"; +import { type RequestConfigWithMeta } from "../logging/types"; import { sizeOf } from "../logging/utils"; import { AuthConfigTracker } from "../settings/authConfig"; import { getHeaderCommand } from "../settings/headers"; +import { readHttpClientLogLevel } from "../settings/logger"; import { NOOP_TELEMETRY_REPORTER, type TelemetryReporter, @@ -824,13 +822,6 @@ function getSize(headers: AxiosHeaders, data: unknown): number | undefined { return sizeOf(data); } -function getLogLevel(): HttpClientLogLevel { - const logLevelStr = vscode.workspace - .getConfiguration() - .get( - "coder.httpClientLogLevel", - HttpClientLogLevel[HttpClientLogLevel.BASIC], - ) - .toUpperCase(); - return HttpClientLogLevel[logLevelStr as keyof typeof HttpClientLogLevel]; +function getLogLevel() { + return readHttpClientLogLevel(vscode.workspace.getConfiguration()); } diff --git a/src/core/container.ts b/src/core/container.ts index 3d6da92aca..08308f8363 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -1,5 +1,6 @@ import * as vscode from "vscode"; +import { watchConfigurationChanges } from "../configWatcher"; import { AuthTelemetry } from "../instrumentation/auth"; import { BufferingLogger, @@ -9,6 +10,10 @@ import { prefixLogger } from "../logging/prefixLogger"; import { shortId } from "../logging/utils"; import { LoginCoordinator } from "../login/loginCoordinator"; import { OAuthCallback } from "../oauth/oauthCallback"; +import { + CONNECTION_LOG_BUFFER_SIZE_SETTING, + readConnectionLogBufferSize, +} from "../settings/logger"; import { buildSession, extractExtensionVersion } from "../telemetry/event"; import { TelemetryService } from "../telemetry/service"; import { LocalJsonlSink } from "../telemetry/sinks/localJsonlSink"; @@ -27,9 +32,6 @@ import { sessionId } from "./sessionId"; import type { Logger } from "../logging/logger"; -const CONNECTION_LOG_BUFFER_SIZE_KEY = "coder.connectionLogBuffer.size"; -const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; - /** * Service container for dependency injection. * Centralizes the creation and management of all core services. @@ -58,15 +60,24 @@ export class ServiceContainer implements vscode.Disposable { }); this.logger = new BufferingLogger( prefixLogger(this.outputChannel, `[session ${shortId(sessionId)}]`), - () => this.outputChannel.logLevel, - readConnectionLogBufferSize(), + this.outputChannel, + readConnectionLogBufferSize(vscode.workspace.getConfiguration()), ); - this.connectionLogBufferConfigSubscription = - vscode.workspace.onDidChangeConfiguration((event) => { - if (event.affectsConfiguration(CONNECTION_LOG_BUFFER_SIZE_KEY)) { - this.logger.setCapacity(readConnectionLogBufferSize()); + this.connectionLogBufferConfigSubscription = watchConfigurationChanges( + [ + { + setting: CONNECTION_LOG_BUFFER_SIZE_SETTING, + getValue: () => + readConnectionLogBufferSize(vscode.workspace.getConfiguration()), + }, + ], + (changes) => { + const size = changes.get(CONNECTION_LOG_BUFFER_SIZE_SETTING); + if (typeof size === "number") { + this.logger.setCapacity(size); } - }); + }, + ); this.pathResolver = new PathResolver( context.globalStorageUri.fsPath, context.logUri.fsPath, @@ -221,12 +232,3 @@ export class ServiceContainer implements vscode.Disposable { } } } - -function readConnectionLogBufferSize(): number { - return vscode.workspace - .getConfiguration() - .get( - CONNECTION_LOG_BUFFER_SIZE_KEY, - DEFAULT_CONNECTION_LOG_BUFFER_SIZE, - ); -} diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index dc2dd3f053..093a5bd3bd 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -35,34 +35,18 @@ interface LogEntry { readonly args: unknown[]; } -/** - * Largest configurable capacity, as an entry count. Bounds worst-case memory - * so a typo or an unreasonable setting cannot grow the buffer without limit. - */ -export const MAX_CONNECTION_LOG_BUFFER_SIZE = 10_000; - -function normalizeCapacity(capacity: number): number { - if (!Number.isFinite(capacity) || capacity <= 0) { - return 0; - } - return Math.min(Math.floor(capacity), MAX_CONNECTION_LOG_BUFFER_SIZE); -} - /** * Buffers entries below the current log level and replays them on failure at a * level the output channel persists. */ export class BufferingLogger implements Logger, ConnectionLogBuffer { private entries: LogEntry[] = []; - private capacity: number; public constructor( private readonly inner: Logger, - private readonly getLogLevel: () => number, - capacity: number, - ) { - this.capacity = normalizeCapacity(capacity); - } + private readonly channel: { readonly logLevel: number }, + private capacity: number, + ) {} public trace(message: string, ...args: unknown[]): void { this.record("trace", message, args); @@ -95,7 +79,7 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { /** Resize the ring, keeping the most recent entries. */ public setCapacity(capacity: number): void { - this.capacity = normalizeCapacity(capacity); + this.capacity = capacity; if (this.entries.length > this.capacity) { this.entries.splice(0, this.entries.length - this.capacity); } @@ -132,7 +116,7 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { * sink writes nothing). */ private replayEmitter(): (message: string, ...args: unknown[]) => void { - const level = this.getLogLevel(); + const level = this.channel.logLevel; if (level >= SEVERITY.error) { return (message, ...args) => this.inner.error(message, ...args); } @@ -143,7 +127,7 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { } private record(level: Level, message: string, args: unknown[]): void { - if (this.capacity === 0 || SEVERITY[level] >= this.getLogLevel()) { + if (this.capacity === 0 || SEVERITY[level] >= this.channel.logLevel) { return; } this.entries.push({ atMs: Date.now(), level, message, args }); diff --git a/src/settings/logger.ts b/src/settings/logger.ts new file mode 100644 index 0000000000..65432f1ded --- /dev/null +++ b/src/settings/logger.ts @@ -0,0 +1,50 @@ +import { HttpClientLogLevel } from "../logging/types"; + +import type { WorkspaceConfiguration } from "vscode"; + + +export const CONNECTION_LOG_BUFFER_SIZE_SETTING = + "coder.connectionLogBuffer.size"; +export const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; +/** + * Largest configurable capacity, as an entry count. Bounds worst-case memory so + * a typo or an unreasonable setting cannot grow the buffer without limit. + */ +export const MAX_CONNECTION_LOG_BUFFER_SIZE = 10_000; + +const HTTP_CLIENT_LOG_LEVEL_SETTING = "coder.httpClientLogLevel"; + +/** + * Number of connection log entries to buffer below the output channel's level. + * `0` disables buffering; larger values are clamped to + * {@link MAX_CONNECTION_LOG_BUFFER_SIZE}. Missing, non-numeric, non-finite, or + * negative values fall back to the default rather than silently disabling. + */ +export function readConnectionLogBufferSize( + cfg: Pick, +): number { + const value = cfg.get( + CONNECTION_LOG_BUFFER_SIZE_SETTING, + DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + ); + if (typeof value !== "number" || !Number.isFinite(value) || value < 0) { + return DEFAULT_CONNECTION_LOG_BUFFER_SIZE; + } + return Math.min(Math.floor(value), MAX_CONNECTION_LOG_BUFFER_SIZE); +} + +/** HTTP client logging verbosity. Falls back to `BASIC` for unknown values. */ +export function readHttpClientLogLevel( + cfg: Pick, +): HttpClientLogLevel { + const value = cfg + .get( + HTTP_CLIENT_LOG_LEVEL_SETTING, + HttpClientLogLevel[HttpClientLogLevel.BASIC], + ) + .toUpperCase(); + return ( + HttpClientLogLevel[value as keyof typeof HttpClientLogLevel] ?? + HttpClientLogLevel.BASIC + ); +} diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 781b6fcc7c..0a4c28f92d 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -1,9 +1,6 @@ import { describe, expect, it, vi } from "vitest"; -import { - BufferingLogger, - MAX_CONNECTION_LOG_BUFFER_SIZE, -} from "@/logging/logBuffer"; +import { BufferingLogger } from "@/logging/logBuffer"; import type { Logger } from "@/logging/logger"; @@ -39,27 +36,14 @@ function recordingLogger(): { logger: Logger; calls: Call[] } { }; } -function fakeLevelSource(initial: number): { - getLogLevel: () => number; - set(level: number): void; -} { - let level = initial; - return { - getLogLevel: () => level, - set(next: number) { - level = next; - }, - }; +function fakeChannel(initial: number): { logLevel: number } { + return { logLevel: initial }; } describe("BufferingLogger", () => { it("forwards every call to the inner logger", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); buffer.trace("t"); buffer.debug("d"); @@ -81,11 +65,7 @@ describe("BufferingLogger", () => { try { vi.setSystemTime(new Date("2024-01-01T00:00:00.000Z")); const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); buffer.debug("hidden debug"); buffer.info("visible info"); @@ -109,11 +89,7 @@ describe("BufferingLogger", () => { it("does not buffer entries at or above the current level", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); buffer.info("i"); buffer.warn("w"); @@ -127,11 +103,7 @@ describe("BufferingLogger", () => { it("evicts the oldest entry when capacity is exceeded", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 2, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 2); buffer.debug("one"); buffer.debug("two"); @@ -148,11 +120,7 @@ describe("BufferingLogger", () => { it("clears the buffer after a flush", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); buffer.debug("d"); buffer.flush("first"); @@ -165,11 +133,7 @@ describe("BufferingLogger", () => { it("flushes newly accumulated entries on each consecutive failure", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); buffer.debug("before first failure"); calls.length = 0; @@ -193,11 +157,7 @@ describe("BufferingLogger", () => { it("is a no-op when the buffer is empty", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); buffer.flush("r"); @@ -206,11 +166,11 @@ describe("BufferingLogger", () => { it("re-evaluates what is below level when the level changes", () => { const { logger, calls } = recordingLogger(); - const level = fakeLevelSource(ERROR); - const buffer = new BufferingLogger(logger, level.getLogLevel, 10); + const channel = fakeChannel(ERROR); + const buffer = new BufferingLogger(logger, channel, 10); buffer.info("info at error level"); // below ERROR -> buffered - level.set(INFO); + channel.logLevel = INFO; buffer.info("info at info level"); // at INFO -> not buffered calls.length = 0; @@ -221,40 +181,9 @@ describe("BufferingLogger", () => { expect(lines.some((l) => l.includes("info at info level"))).toBe(false); }); - it("clamps capacity to the maximum, evicting beyond it", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - MAX_CONNECTION_LOG_BUFFER_SIZE + 5, - ); - - for (let i = 0; i < MAX_CONNECTION_LOG_BUFFER_SIZE + 5; i++) { - buffer.debug(`entry ${i}`); - } - - calls.length = 0; - buffer.flush("r"); - - // header + capped entries + footer; the oldest 5 were evicted. - const buffered = calls.filter((c) => c.message.includes("entry ")); - expect(buffered).toHaveLength(MAX_CONNECTION_LOG_BUFFER_SIZE); - const lines = buffered.map((c) => c.message); - expect(lines.some((l) => l.endsWith("entry 0"))).toBe(false); - expect( - lines.some((l) => - l.endsWith(`entry ${MAX_CONNECTION_LOG_BUFFER_SIZE + 4}`), - ), - ).toBe(true); - }); - it("buffers nothing when capacity is zero", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 0, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 0); buffer.debug("d"); calls.length = 0; @@ -265,11 +194,7 @@ describe("BufferingLogger", () => { it("keeps the most recent entries when shrunk via setCapacity", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); buffer.debug("one"); buffer.debug("two"); @@ -293,11 +218,7 @@ describe("BufferingLogger", () => { "replays at $expected so the flush is written at level $level", ({ level, expected }) => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(level).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(level), 10); // Always below the current level so it is buffered. buffer.trace("below"); @@ -311,11 +232,7 @@ describe("BufferingLogger", () => { it("preserves extra args on replay", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(INFO).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); const detail = { code: 1006 }; buffer.debug("dropped", detail); @@ -328,11 +245,7 @@ describe("BufferingLogger", () => { it("does not buffer at the Off level", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(OFF).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(OFF), 10); buffer.trace("t"); buffer.debug("d"); @@ -344,11 +257,7 @@ describe("BufferingLogger", () => { it("buffers trace but not debug at the Debug level", () => { const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger( - logger, - fakeLevelSource(DEBUG).getLogLevel, - 10, - ); + const buffer = new BufferingLogger(logger, fakeChannel(DEBUG), 10); buffer.trace("trace line"); buffer.debug("debug line"); diff --git a/test/unit/settings/logger.test.ts b/test/unit/settings/logger.test.ts new file mode 100644 index 0000000000..a0a6b484a2 --- /dev/null +++ b/test/unit/settings/logger.test.ts @@ -0,0 +1,65 @@ +import { describe, expect, it } from "vitest"; + +import { HttpClientLogLevel } from "@/logging/types"; +import { + DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + MAX_CONNECTION_LOG_BUFFER_SIZE, + readConnectionLogBufferSize, + readHttpClientLogLevel, +} from "@/settings/logger"; + +import type { WorkspaceConfiguration } from "vscode"; + +function cfg(value: unknown): Pick { + return { + get: (_key: string, fallback?: unknown) => + value === undefined ? fallback : value, + } as Pick; +} + +describe("readConnectionLogBufferSize", () => { + it("returns the configured value when in range", () => { + expect(readConnectionLogBufferSize(cfg(250))).toBe(250); + }); + + it("floors fractional values", () => { + expect(readConnectionLogBufferSize(cfg(250.9))).toBe(250); + }); + + it("treats zero as disabled", () => { + expect(readConnectionLogBufferSize(cfg(0))).toBe(0); + }); + + it("clamps values above the maximum", () => { + expect(readConnectionLogBufferSize(cfg(1_000_000))).toBe( + MAX_CONNECTION_LOG_BUFFER_SIZE, + ); + }); + + it.each([-1, Infinity, Number.NaN, "2000", null, {}])( + "falls back to the default for invalid value %p", + (value) => { + expect(readConnectionLogBufferSize(cfg(value))).toBe( + DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + ); + }, + ); + + it("uses the default when unset", () => { + expect(readConnectionLogBufferSize(cfg(undefined))).toBe( + DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + ); + }); +}); + +describe("readHttpClientLogLevel", () => { + it("maps a known level case-insensitively", () => { + expect(readHttpClientLogLevel(cfg("body"))).toBe(HttpClientLogLevel.BODY); + }); + + it("falls back to BASIC for an unknown level", () => { + expect(readHttpClientLogLevel(cfg("nonsense"))).toBe( + HttpClientLogLevel.BASIC, + ); + }); +}); From 88195a7cdd3fb35327ca9e8516cd6391d048829c Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 00:17:26 +0000 Subject: [PATCH 26/60] refactor(logging): trim buffer replay and redact registration_access_token - Return early from flush at Off so context survives until logging returns. - Add registration_access_token to SENSITIVE_BODY_FIELDS. - Drop LEVEL_LABEL in favor of level.toUpperCase(). - Pick the replay sink by name instead of a closure. - Prefix every physical line of multi-line entries with [buffered]. - Describe the max capacity as an entry count, not a byte cap. --- src/logging/formatters.ts | 1 + src/logging/logBuffer.ts | 78 ++++++++++++---------------- src/settings/logger.ts | 5 +- test/unit/logging/formatters.test.ts | 2 + test/unit/logging/logBuffer.test.ts | 34 ++++++++++++ 5 files changed, 71 insertions(+), 49 deletions(-) diff --git a/src/logging/formatters.ts b/src/logging/formatters.ts index b962b1dec1..331a67b990 100644 --- a/src/logging/formatters.ts +++ b/src/logging/formatters.ts @@ -24,6 +24,7 @@ const SENSITIVE_BODY_FIELDS: ReadonlySet> = new Set([ "id_token", "password", "refresh_token", + "registration_access_token", "token", ]); diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 093a5bd3bd..83a6bf8617 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -15,13 +15,8 @@ const SEVERITY = { type Level = keyof typeof SEVERITY; -const LEVEL_LABEL: Readonly> = { - trace: "TRACE", - debug: "DEBUG", - info: "INFO", - warn: "WARN", - error: "ERROR", -}; +/** Sink methods that the output channel persists at any non-Off level. */ +type ReplaySink = "info" | "warn" | "error"; /** The failure-time surface used by connection-failure call sites. */ export interface ConnectionLogBuffer { @@ -48,30 +43,11 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { private capacity: number, ) {} - public trace(message: string, ...args: unknown[]): void { - this.record("trace", message, args); - this.inner.trace(message, ...args); - } - - public debug(message: string, ...args: unknown[]): void { - this.record("debug", message, args); - this.inner.debug(message, ...args); - } - - public info(message: string, ...args: unknown[]): void { - this.record("info", message, args); - this.inner.info(message, ...args); - } - - public warn(message: string, ...args: unknown[]): void { - this.record("warn", message, args); - this.inner.warn(message, ...args); - } - - public error(message: string, ...args: unknown[]): void { - this.record("error", message, args); - this.inner.error(message, ...args); - } + public readonly trace = this.wrap("trace"); + public readonly debug = this.wrap("debug"); + public readonly info = this.wrap("info"); + public readonly warn = this.wrap("warn"); + public readonly error = this.wrap("error"); public show(): void { this.inner.show(); @@ -88,42 +64,52 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { /** * Replay buffered entries into the sink and clear them. No-op when empty. * Clearing the buffer means a later flush only replays entries accumulated - * since this one, so consecutive failures never duplicate lines. + * since this one, so consecutive failures never duplicate entries. */ public flush(reason: string): void { + // The channel writes nothing at Off, so replaying now would discard the + // context. Keep it buffered until logging is turned back on. + if (this.channel.logLevel === 0) { + return; + } if (this.entries.length === 0) { return; } const entries = this.entries; this.entries = []; - const emit = this.replayEmitter(); - emit( - `[buffered] connection failure (${reason}): replaying ${entries.length} buffered log line(s)`, + const sink = this.replaySink(); + this.inner[sink]( + `[buffered] connection failure (${reason}): replaying ${entries.length} buffered entries`, ); for (const entry of entries) { - emit( - `[buffered] ${new Date(entry.atMs).toISOString()} ${LEVEL_LABEL[entry.level]} ${entry.message}`, - ...entry.args, - ); + const line = `[buffered] ${new Date(entry.atMs).toISOString()} ${entry.level.toUpperCase()} ${entry.message}`; + this.inner[sink](line.replaceAll("\n", "\n[buffered] "), ...entry.args); } - emit(`[buffered] end of buffered logs (${reason})`); + this.inner[sink](`[buffered] end of buffered logs (${reason})`); + } + + /** Pass a call through to the sink and buffer it when below the level. */ + private wrap(level: Level): (message: string, ...args: unknown[]) => void { + return (message, ...args) => { + this.record(level, message, args); + this.inner[level](message, ...args); + }; } /** * The least-verbose sink method that is still written at the current level, - * so a flush is captured whatever the user's log level (except Off, where the - * sink writes nothing). + * so a flush is captured whatever the user's log level. */ - private replayEmitter(): (message: string, ...args: unknown[]) => void { + private replaySink(): ReplaySink { const level = this.channel.logLevel; if (level >= SEVERITY.error) { - return (message, ...args) => this.inner.error(message, ...args); + return "error"; } if (level >= SEVERITY.warn) { - return (message, ...args) => this.inner.warn(message, ...args); + return "warn"; } - return (message, ...args) => this.inner.info(message, ...args); + return "info"; } private record(level: Level, message: string, args: unknown[]): void { diff --git a/src/settings/logger.ts b/src/settings/logger.ts index 65432f1ded..046c43f98f 100644 --- a/src/settings/logger.ts +++ b/src/settings/logger.ts @@ -2,13 +2,12 @@ import { HttpClientLogLevel } from "../logging/types"; import type { WorkspaceConfiguration } from "vscode"; - export const CONNECTION_LOG_BUFFER_SIZE_SETTING = "coder.connectionLogBuffer.size"; export const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; /** - * Largest configurable capacity, as an entry count. Bounds worst-case memory so - * a typo or an unreasonable setting cannot grow the buffer without limit. + * Largest configurable capacity. Bounds the entry count kept in memory; each + * entry still holds live `args` references, so this is a count, not a byte cap. */ export const MAX_CONNECTION_LOG_BUFFER_SIZE = 10_000; diff --git a/test/unit/logging/formatters.test.ts b/test/unit/logging/formatters.test.ts index 8eb699dd66..ab0d581b22 100644 --- a/test/unit/logging/formatters.test.ts +++ b/test/unit/logging/formatters.test.ts @@ -143,6 +143,7 @@ describe("Logging formatters", () => { const result = formatBody({ access_token: "secret-access", refresh_token: "secret-refresh", + registration_access_token: "secret-registration", client_secret: "secret-client", code: "secret-code", code_verifier: "secret-verifier", @@ -152,6 +153,7 @@ describe("Logging formatters", () => { token_type: "bearer", }); expect(result).toContain("access_token: ''"); + expect(result).toContain("registration_access_token: ''"); expect(result).toContain("token_type: 'bearer'"); expect(result).not.toContain("secret-"); }); diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 0a4c28f92d..f0c56793ed 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -268,4 +268,38 @@ describe("BufferingLogger", () => { expect(lines.some((l) => l.includes("trace line"))).toBe(true); expect(lines.some((l) => l.includes("debug line"))).toBe(false); }); + + it("preserves entries when flushed at Off and replays once logging returns", () => { + const { logger, calls } = recordingLogger(); + const channel = fakeChannel(INFO); + const buffer = new BufferingLogger(logger, channel, 10); + + buffer.debug("hidden debug"); + + // Off writes nothing, so the flush must keep the entry buffered. + channel.logLevel = OFF; + calls.length = 0; + buffer.flush("while off"); + expect(calls).toHaveLength(0); + + // Once logging is back on, the same entry replays. + channel.logLevel = INFO; + buffer.flush("after off"); + expect(calls.some((c) => c.message.includes("hidden debug"))).toBe(true); + }); + + it("prefixes every physical line of a multi-line message with [buffered]", () => { + const { logger, calls } = recordingLogger(); + const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); + + buffer.debug("first line\nsecond line\nthird line"); + calls.length = 0; + buffer.flush("r"); + + const entry = calls.find((c) => c.message.includes("first line")); + expect(entry).toBeDefined(); + for (const line of entry!.message.split("\n")) { + expect(line.startsWith("[buffered] ")).toBe(true); + } + }); }); From da4fa14d46403b8a19f1df5033bd11b41ad7788f Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 00:33:29 +0000 Subject: [PATCH 27/60] test: consolidate buffer, reconnect, and websocket-mock tests - logBuffer: add setup() with level/capacity tables and Date.now spy, folding 15 tests into 6. - reconnectingWebSocket: drop the predicate-only Set.has tables, un-export isTerminalConnectionFailure, and assert onConnectionFailure through the existing close-code, HTTP, and cert-refresh tests. - coderApi: give createMockWebSocket fireOpen/fireClose/fireError/fireMessage and a connectError option, replacing the interim addEventListener->on delegation and the hand-rolled close handler. --- src/websocket/reconnectingWebSocket.ts | 6 +- test/unit/api/coderApi.test.ts | 165 ++++---- test/unit/logging/logBuffer.test.ts | 367 +++++++----------- .../websocket/reconnectingWebSocket.test.ts | 147 +++---- 4 files changed, 254 insertions(+), 431 deletions(-) diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index 6d2f8108a0..d460dacee0 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -35,10 +35,8 @@ function toCloseEventError(event: CloseEvent): Error { const TERMINAL_CONNECTION_FAILURE_REASONS: ReadonlySet = new Set(["unrecoverable_close", "unrecoverable_http", "certificate_error"]); -/** Whether a state-transition reason represents a genuine connection failure. */ -export function isTerminalConnectionFailure( - reason: ConnectionStateReason, -): boolean { +/** Whether a reason stops automatic retries. */ +function isTerminalConnectionFailure(reason: ConnectionStateReason): boolean { return TERMINAL_CONNECTION_FAILURE_REASONS.has(reason); } diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index 728472266f..983ca3f62b 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -465,15 +465,8 @@ describe("CoderApi", () => { beforeEach(() => { api = createApi(CODER_URL, AXIOS_TOKEN); - // createOneWayWebSocket waits for open, so we need to fire it - const mockWs = createMockWebSocket(wsUrl, { - on: vi.fn((event, handler) => { - if (event === "open") { - setImmediate(() => handler()); - } - return mockWs as Ws; - }), - }); + // createOneWayWebSocket waits for open, which the mock fires automatically. + const mockWs = createMockWebSocket(wsUrl); setupWebSocketMock(mockWs); }); @@ -591,28 +584,15 @@ describe("CoderApi", () => { NOOP_TELEMETRY_REPORTER, onConnectionFailure, ); - - let closeHandler: ((event: unknown) => void) | undefined; const mockWs = createMockWebSocket( `wss://${CODER_URL.replace("https://", "")}/api/v2/workspaceagents/${AGENT_ID}/watch-metadata-ws`, - { - on: vi.fn((event: string, handler: (e: unknown) => void) => { - if (event === "open") { - setImmediate(() => handler(undefined)); - } - if (event === "close") { - closeHandler = handler; - } - return mockWs as Ws; - }), - }, ); setupWebSocketMock(mockWs); const connection = await failingApi.watchAgentMetadata(AGENT_ID); // An unrecoverable close code is a terminal failure, not a retry. - closeHandler?.({ + mockWs.fireClose({ code: WebSocketCloseCode.PROTOCOL_ERROR, reason: "Unrecoverable", wasClean: false, @@ -638,14 +618,6 @@ describe("CoderApi", () => { it("uses WebSocket when no errors occur", async () => { const mockWs = createMockWebSocket( `wss://${CODER_URL.replace("https://", "")}/api/v2/workspaceagents/${AGENT_ID}/watch-metadata`, - { - on: vi.fn((event, handler) => { - if (event === "open") { - setImmediate(() => handler()); - } - return mockWs as Ws; - }), - }, ); setupWebSocketMock(mockWs); @@ -672,17 +644,10 @@ describe("CoderApi", () => { const mockWs = createMockWebSocket( `wss://${CODER_URL.replace("https://", "")}/api/v2/test`, { - on: vi.fn((event: string, handler: (e: unknown) => void) => { - if (event === "error") { - setImmediate(() => { - handler({ - error: new Error("404 Not Found"), - message: "404 Not Found", - }); - }); - } - return mockWs as Ws; - }), + connectError: { + error: new Error("404 Not Found"), + message: "404 Not Found", + }, }, ); setupWebSocketMock(mockWs); @@ -719,14 +684,7 @@ describe("CoderApi", () => { vi.mocked(Ws).mockImplementation(function () { wsAttempts++; const mockWs = createMockWebSocket("wss://test", { - on: vi.fn((event: string, handler: (e: unknown) => void) => { - if (event === "error") { - setImmediate(() => - handler({ error: new Error("Something 404") }), - ); - } - return mockWs as Ws; - }), + connectError: { error: new Error("Something 404") }, }); return mockWs as Ws; }); @@ -753,22 +711,13 @@ describe("CoderApi", () => { }); const setupAutoOpeningWebSocket = () => { - const sockets: Array> = []; - const handlers: Record void> = {}; + const sockets: MockWebSocket[] = []; vi.mocked(Ws).mockImplementation(function (url: string | URL) { - const mockWs = createMockWebSocket(String(url), { - on: vi.fn((event: string, handler: (...args: unknown[]) => void) => { - handlers[event] = handler; - if (event === "open") { - setImmediate(() => handler()); - } - return mockWs as Ws; - }), - }); + const mockWs = createMockWebSocket(String(url)); sockets.push(mockWs); return mockWs as Ws; }); - return { sockets, handlers }; + return { sockets }; }; describe("Reconnection on Host/Token Changes", () => { @@ -904,14 +853,7 @@ describe("CoderApi", () => { async ({ eventMessage, expectedMessage }) => { api = createApi(); const mockWs = createMockWebSocket("wss://test", { - on: vi.fn((event: string, handler: (e: unknown) => void) => { - if (event === "error") { - setImmediate(() => - handler({ error: undefined, message: eventMessage }), - ); - } - return mockWs as Ws; - }), + connectError: { error: undefined, message: eventMessage }, }); setupWebSocketMock(mockWs); @@ -1102,14 +1044,7 @@ describe("CoderApi", () => { it("disposes all tracked reconnecting sockets", async () => { const sockets: Array> = []; vi.mocked(Ws).mockImplementation(function (url: string | URL) { - const mockWs = createMockWebSocket(String(url), { - on: vi.fn((event, handler) => { - if (event === "open") { - setImmediate(() => handler()); - } - return mockWs as Ws; - }), - }); + const mockWs = createMockWebSocket(String(url)); sockets.push(mockWs); return mockWs as Ws; }); @@ -1175,12 +1110,12 @@ describe("CoderApi", () => { it("does not reconnect sockets in AWAITING_RETRY state when config changes", async () => { mockConfig.set("coder.insecure", false); - const { sockets, handlers } = setupAutoOpeningWebSocket(); + const { sockets } = setupAutoOpeningWebSocket(); api = createApi(CODER_URL, AXIOS_TOKEN); await api.watchAgentMetadata(AGENT_ID); // Trigger close with abnormal code to put socket in AWAITING_RETRY - handlers["close"]?.({ code: 1006, reason: "Abnormal closure" }); + sockets.at(-1)?.fireClose({ code: 1006, reason: "Abnormal closure" }); await tick(); mockConfig.set("coder.insecure", true); @@ -1197,13 +1132,13 @@ describe("CoderApi", () => { "reconnects sockets in DISCONNECTED state when %s changes", async (setting, before, after) => { mockConfig.set(setting, before); - const { sockets, handlers } = setupAutoOpeningWebSocket(); + const { sockets } = setupAutoOpeningWebSocket(); api = createApi(CODER_URL, AXIOS_TOKEN); await api.watchAgentMetadata(AGENT_ID); await tick(); // Trigger close with unrecoverable code to put socket in DISCONNECTED - handlers["close"]?.({ code: 1002, reason: "Protocol error" }); + sockets.at(-1)?.fireClose({ code: 1002, reason: "Protocol error" }); await tick(); mockConfig.set(setting, after); @@ -1230,26 +1165,62 @@ const mockAdapterImpl = vi.hoisted( }, ); +type MockWebSocket = Partial & { + fireOpen: () => void; + fireClose: (event: { + code: number; + reason: string; + wasClean?: boolean; + }) => void; + fireError: (event: { error?: Error; message?: string }) => void; + fireMessage: (data: unknown) => void; +}; + +interface MockWebSocketOptions { + /** Fire this error on connect instead of "open" to simulate a handshake failure. */ + connectError?: { error?: Error; message?: string }; +} + function createMockWebSocket( url: string, - overrides?: Partial, -): Partial { - const mock: Partial = { + options: MockWebSocketOptions = {}, +): MockWebSocket { + // OneWayWebSocket registers open/close/error via addEventListener and only + // message via on(), mirroring the DOM/ws split in production. + const domHandlers: Record void) | undefined> = {}; + const messageHandlers = new Set<(e: unknown) => void>(); + const mock: MockWebSocket = { url, - on: vi.fn(), - off: vi.fn(), + on: vi.fn((event: string, handler: (e: unknown) => void) => { + if (event === "message") { + messageHandlers.add(handler); + } + return mock as Ws; + }), + off: vi.fn((event: string, handler: (e: unknown) => void) => { + if (event === "message") { + messageHandlers.delete(handler); + } + return mock as Ws; + }), + addEventListener: vi.fn((event: string, handler: (e: unknown) => void) => { + domHandlers[event] = handler; + if (event === "open" && !options.connectError) { + setImmediate(() => handler(new Event("open"))); + } + if (event === "error" && options.connectError) { + setImmediate(() => handler(options.connectError)); + } + }), + removeEventListener: vi.fn((event: string) => { + domHandlers[event] = undefined; + }), close: vi.fn(), - ...overrides, + fireOpen: () => domHandlers.open?.(new Event("open")), + fireClose: (event) => domHandlers.close?.(event), + fireError: (event) => domHandlers.error?.(event), + fireMessage: (data) => messageHandlers.forEach((handler) => handler(data)), }; - // OneWayWebSocket registers open/close/error via addEventListener and only - // message via on(). Tests still stub those handlers through `on`, so delegate - // unless a test provides its own addEventListener. - if (!overrides?.addEventListener) { - mock.addEventListener = mock.on as Ws["addEventListener"]; - } - if (!overrides?.removeEventListener) { - mock.removeEventListener = mock.off as Ws["removeEventListener"]; - } return mock; } diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index f0c56793ed..b9630b26ac 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -1,4 +1,4 @@ -import { describe, expect, it, vi } from "vitest"; +import { afterEach, describe, expect, it, vi } from "vitest"; import { BufferingLogger } from "@/logging/logBuffer"; @@ -11,39 +11,46 @@ const INFO = 3; const WARNING = 4; const ERROR = 5; +type LogMethod = "trace" | "debug" | "info" | "warn" | "error"; + interface Call { level: keyof Logger; message: string; args: unknown[]; } -function recordingLogger(): { logger: Logger; calls: Call[] } { +function setup(level: number, capacity: number) { const calls: Call[] = []; const push = - (level: keyof Logger) => + (method: keyof Logger) => (message: string, ...args: unknown[]) => - calls.push({ level, message, args }); - return { - calls, - logger: { - trace: push("trace"), - debug: push("debug"), - info: push("info"), - warn: push("warn"), - error: push("error"), - show: vi.fn(), - }, + calls.push({ level: method, message, args }); + const logger: Logger = { + trace: push("trace"), + debug: push("debug"), + info: push("info"), + warn: push("warn"), + error: push("error"), + show: vi.fn(), + }; + const channel = { logLevel: level }; + const buffer = new BufferingLogger(logger, channel, capacity); + // Ignore the pass-through calls, then return only what the flush replayed. + const flush = (reason = "r"): string[] => { + calls.length = 0; + buffer.flush(reason); + return calls.map((c) => c.message); }; + return { buffer, calls, channel, flush }; } -function fakeChannel(initial: number): { logLevel: number } { - return { logLevel: initial }; -} +afterEach(() => { + vi.restoreAllMocks(); +}); describe("BufferingLogger", () => { it("forwards every call to the inner logger", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); + const { buffer, calls } = setup(INFO, 10); buffer.trace("t"); buffer.debug("d"); @@ -60,246 +67,150 @@ describe("BufferingLogger", () => { ]); }); - it("buffers only entries below the current level and replays them on flush", () => { - vi.useFakeTimers(); - try { - vi.setSystemTime(new Date("2024-01-01T00:00:00.000Z")); - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); - - buffer.debug("hidden debug"); - buffer.info("visible info"); - - // Flush later; the replay must carry the original record time. - vi.setSystemTime(new Date("2024-01-01T00:05:00.000Z")); - calls.length = 0; // ignore the pass-through calls - buffer.flush("test_reason"); - - const replayed = calls.filter((c) => c.message.includes("[buffered]")); - // header + one debug line + footer; the info line was at level and not buffered. - expect(replayed).toHaveLength(3); - expect(replayed[0].message).toContain("connection failure (test_reason)"); - expect(replayed[1].message).toContain("DEBUG hidden debug"); - expect(replayed[1].message).toContain("2024-01-01T00:00:00.000Z"); - expect(replayed[2].message).toContain("end of buffered logs"); - } finally { - vi.useRealTimers(); - } - }); - - it("does not buffer entries at or above the current level", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); - - buffer.info("i"); - buffer.warn("w"); - buffer.error("e"); - - calls.length = 0; - buffer.flush("r"); - - expect(calls).toHaveLength(0); - }); - - it("evicts the oldest entry when capacity is exceeded", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 2); - - buffer.debug("one"); - buffer.debug("two"); - buffer.debug("three"); - - calls.length = 0; - buffer.flush("r"); - - const lines = calls.map((c) => c.message); - expect(lines.some((l) => l.includes("one"))).toBe(false); - expect(lines.some((l) => l.includes("two"))).toBe(true); - expect(lines.some((l) => l.includes("three"))).toBe(true); - }); - - it("clears the buffer after a flush", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); - - buffer.debug("d"); - buffer.flush("first"); - - calls.length = 0; - buffer.flush("second"); - - expect(calls).toHaveLength(0); - }); - - it("flushes newly accumulated entries on each consecutive failure", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); - - buffer.debug("before first failure"); - calls.length = 0; - buffer.flush("first"); - const firstLines = calls.map((c) => c.message); - expect(firstLines.some((l) => l.includes("before first failure"))).toBe( - true, - ); - - buffer.debug("before second failure"); - calls.length = 0; - buffer.flush("second"); - const secondLines = calls.map((c) => c.message); - expect(secondLines.some((l) => l.includes("before second failure"))).toBe( - true, - ); - expect(secondLines.some((l) => l.includes("before first failure"))).toBe( - false, - ); - }); - - it("is a no-op when the buffer is empty", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); + it.each([ + { + level: DEBUG, + hidden: "trace" as LogMethod, + shown: "debug" as LogMethod, + sink: "info" as const, + }, + { + level: INFO, + hidden: "debug" as LogMethod, + shown: "info" as LogMethod, + sink: "info" as const, + }, + { + level: WARNING, + hidden: "info" as LogMethod, + shown: "warn" as LogMethod, + sink: "warn" as const, + }, + { + level: ERROR, + hidden: "warn" as LogMethod, + shown: "error" as LogMethod, + sink: "error" as const, + }, + ])( + "at level $level buffers below-level entries and replays them via the $sink sink", + ({ level, hidden, shown, sink }) => { + const { buffer, calls, flush } = setup(level, 10); - buffer.flush("r"); + buffer[hidden]("hidden line"); + buffer[shown]("shown line"); + const lines = flush(); - expect(calls).toHaveLength(0); - }); + expect(lines.some((l) => l.includes("hidden line"))).toBe(true); + expect(lines.some((l) => l.includes("shown line"))).toBe(false); + expect(calls.every((c) => c.level === sink)).toBe(true); + }, + ); it("re-evaluates what is below level when the level changes", () => { - const { logger, calls } = recordingLogger(); - const channel = fakeChannel(ERROR); - const buffer = new BufferingLogger(logger, channel, 10); + const { buffer, channel, flush } = setup(ERROR, 10); buffer.info("info at error level"); // below ERROR -> buffered channel.logLevel = INFO; buffer.info("info at info level"); // at INFO -> not buffered - calls.length = 0; - buffer.flush("r"); - - const lines = calls.map((c) => c.message); + const lines = flush(); expect(lines.some((l) => l.includes("info at error level"))).toBe(true); expect(lines.some((l) => l.includes("info at info level"))).toBe(false); }); - it("buffers nothing when capacity is zero", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 0); - - buffer.debug("d"); - calls.length = 0; - buffer.flush("r"); - - expect(calls).toHaveLength(0); - }); - - it("keeps the most recent entries when shrunk via setCapacity", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); + it.each([ + { + name: "evicts the oldest entry when capacity is exceeded", + capacity: 2, + shrinkTo: undefined as number | undefined, + present: ["two", "three"], + absent: ["one"], + }, + { + name: "buffers nothing when capacity is zero", + capacity: 0, + shrinkTo: undefined as number | undefined, + present: [], + absent: ["one", "two", "three"], + }, + { + name: "keeps the most recent entries when shrunk via setCapacity", + capacity: 10, + shrinkTo: 1, + present: ["three"], + absent: ["one", "two"], + }, + ])("$name", ({ capacity, shrinkTo, present, absent }) => { + const { buffer, flush } = setup(INFO, capacity); buffer.debug("one"); buffer.debug("two"); buffer.debug("three"); - buffer.setCapacity(1); - - calls.length = 0; - buffer.flush("r"); + if (shrinkTo !== undefined) { + buffer.setCapacity(shrinkTo); + } - const lines = calls.map((c) => c.message); - expect(lines.some((l) => l.includes("three"))).toBe(true); - expect(lines.some((l) => l.includes("one"))).toBe(false); - expect(lines.some((l) => l.includes("two"))).toBe(false); + const lines = flush(); + for (const value of present) { + expect(lines.some((l) => l.includes(value))).toBe(true); + } + for (const value of absent) { + expect(lines.some((l) => l.includes(value))).toBe(false); + } }); - it.each([ - { level: INFO, expected: "info" as const }, - { level: WARNING, expected: "warn" as const }, - { level: ERROR, expected: "error" as const }, - ])( - "replays at $expected so the flush is written at level $level", - ({ level, expected }) => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(level), 10); - - // Always below the current level so it is buffered. - buffer.trace("below"); - calls.length = 0; - buffer.flush("r"); - - expect(calls.length).toBeGreaterThan(0); - expect(calls.every((c) => c.level === expected)).toBe(true); - }, - ); - - it("preserves extra args on replay", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); + it("replays each entry with its record time, args, and a [buffered] prefix on every line", () => { + const recordedAt = Date.parse("2024-01-01T00:00:00.000Z"); + vi.spyOn(Date, "now").mockReturnValueOnce(recordedAt); + const { buffer, calls, flush } = setup(INFO, 10); const detail = { code: 1006 }; - buffer.debug("dropped", detail); - calls.length = 0; - buffer.flush("r"); - - const line = calls.find((c) => c.message.includes("dropped")); - expect(line?.args).toEqual([detail]); - }); + buffer.debug("first line\nsecond line", detail); + const lines = flush(); - it("does not buffer at the Off level", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(OFF), 10); + expect(lines[0]).toContain("connection failure (r)"); + expect(lines[lines.length - 1]).toContain("end of buffered logs"); - buffer.trace("t"); - buffer.debug("d"); - calls.length = 0; - buffer.flush("r"); - - expect(calls).toHaveLength(0); + const entry = calls.find((c) => c.message.includes("first line")); + expect(entry).toBeDefined(); + expect(entry?.message).toContain("2024-01-01T00:00:00.000Z"); + expect(entry?.message).toContain("DEBUG first line"); + for (const line of entry?.message.split("\n") ?? []) { + expect(line.startsWith("[buffered] ")).toBe(true); + } + expect(entry?.args).toEqual([detail]); }); - it("buffers trace but not debug at the Debug level", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(DEBUG), 10); + it("clears after flush, no-ops when empty, and preserves entries flushed while Off", () => { + const { buffer, channel, flush } = setup(INFO, 10); - buffer.trace("trace line"); - buffer.debug("debug line"); - calls.length = 0; - buffer.flush("r"); + // Empty flush is a no-op. + expect(flush()).toHaveLength(0); - const lines = calls.map((c) => c.message); - expect(lines.some((l) => l.includes("trace line"))).toBe(true); - expect(lines.some((l) => l.includes("debug line"))).toBe(false); - }); + // Each failure only replays entries accumulated since the previous one. + buffer.debug("before first"); + expect(flush("first").some((l) => l.includes("before first"))).toBe(true); + buffer.debug("before second"); + const second = flush("second"); + expect(second.some((l) => l.includes("before second"))).toBe(true); + expect(second.some((l) => l.includes("before first"))).toBe(false); - it("preserves entries when flushed at Off and replays once logging returns", () => { - const { logger, calls } = recordingLogger(); - const channel = fakeChannel(INFO); - const buffer = new BufferingLogger(logger, channel, 10); - - buffer.debug("hidden debug"); - - // Off writes nothing, so the flush must keep the entry buffered. + // Nothing is buffered while the channel itself is at Off. channel.logLevel = OFF; - calls.length = 0; - buffer.flush("while off"); - expect(calls).toHaveLength(0); - - // Once logging is back on, the same entry replays. + buffer.debug("logged while off"); channel.logLevel = INFO; - buffer.flush("after off"); - expect(calls.some((c) => c.message.includes("hidden debug"))).toBe(true); - }); - - it("prefixes every physical line of a multi-line message with [buffered]", () => { - const { logger, calls } = recordingLogger(); - const buffer = new BufferingLogger(logger, fakeChannel(INFO), 10); - - buffer.debug("first line\nsecond line\nthird line"); - calls.length = 0; - buffer.flush("r"); + expect(flush("after").some((l) => l.includes("logged while off"))).toBe( + false, + ); - const entry = calls.find((c) => c.message.includes("first line")); - expect(entry).toBeDefined(); - for (const line of entry!.message.split("\n")) { - expect(line.startsWith("[buffered] ")).toBe(true); - } + // A flush at Off keeps the context buffered until logging returns. + buffer.debug("buffered before going off"); + channel.logLevel = OFF; + expect(flush("off")).toHaveLength(0); + channel.logLevel = INFO; + expect( + flush("back").some((l) => l.includes("buffered before going off")), + ).toBe(true); }); }); diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index f0939bec47..b89479d5e7 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -8,7 +8,6 @@ import { WebSocketCloseCode, HttpStatusCode } from "@/websocket/codes"; import { ConnectionState, ReconnectingWebSocket, - isTerminalConnectionFailure, type SocketFactory, } from "@/websocket/reconnectingWebSocket"; @@ -36,7 +35,8 @@ describe("ReconnectingWebSocket", () => { describe("Reconnection Logic", () => { it("automatically reconnects on abnormal closure (1006)", async () => { - const { ws, sockets } = await createReconnectingWebSocket(); + const { ws, sockets, onConnectionFailure } = + await createReconnectingWebSocket(); sockets[0].fireOpen(); expect(ws.state).toBe(ConnectionState.CONNECTED); @@ -52,6 +52,8 @@ describe("ReconnectingWebSocket", () => { sockets[1].fireOpen(); expect(ws.state).toBe(ConnectionState.CONNECTED); + // A transient drop that reconnects is not a terminal failure. + expect(onConnectionFailure).not.toHaveBeenCalled(); ws.close(); }); @@ -61,13 +63,15 @@ describe("ReconnectingWebSocket", () => { ])( "does not reconnect on normal closure: $name ($code)", async ({ code }) => { - const { ws, sockets } = await createReconnectingWebSocket(); + const { ws, sockets, onConnectionFailure } = + await createReconnectingWebSocket(); sockets[0].fireOpen(); sockets[0].fireClose({ code, reason: "Normal" }); await vi.advanceTimersByTimeAsync(10000); expect(sockets).toHaveLength(1); + expect(onConnectionFailure).not.toHaveBeenCalled(); ws.close(); }, @@ -79,7 +83,8 @@ describe("ReconnectingWebSocket", () => { ])( "does not reconnect on unrecoverable WebSocket close code: %i", async (code) => { - const { ws, sockets } = await createReconnectingWebSocket(); + const { ws, sockets, onConnectionFailure } = + await createReconnectingWebSocket(); sockets[0].fireOpen(); expect(ws.state).toBe(ConnectionState.CONNECTED); @@ -89,6 +94,10 @@ describe("ReconnectingWebSocket", () => { await vi.advanceTimersByTimeAsync(10000); expect(sockets).toHaveLength(1); + expect(onConnectionFailure).toHaveBeenCalledWith( + "unrecoverable_close", + expect.any(String), + ); ws.close(); }, @@ -111,7 +120,8 @@ describe("ReconnectingWebSocket", () => { }); // create() returns a disconnected instance instead of throwing - const ws = await fromFactory(factory); + const onConnectionFailure = vi.fn(); + const ws = await fromFactory(factory, { onConnectionFailure }); // Should be disconnected after unrecoverable HTTP error expect(ws.state).toBe(ConnectionState.DISCONNECTED); @@ -119,6 +129,10 @@ describe("ReconnectingWebSocket", () => { // Should not retry after unrecoverable HTTP error await vi.advanceTimersByTimeAsync(10000); expect(socketCreationAttempts).toBe(1); + expect(onConnectionFailure).toHaveBeenCalledWith( + "unrecoverable_http", + expect.any(String), + ); ws.close(); }, @@ -153,10 +167,8 @@ describe("ReconnectingWebSocket", () => { ); it("does not flush on an unrecoverable 401 (token refresh reconnects the same socket)", async () => { - const onConnectionFailure = vi.fn(); - const { ws, sockets } = await createReconnectingWebSocket({ - onConnectionFailure, - }); + const { ws, sockets, onConnectionFailure } = + await createReconnectingWebSocket(); sockets[0].fireError( new Error(`Unexpected server response: ${HttpStatusCode.UNAUTHORIZED}`), @@ -174,10 +186,8 @@ describe("ReconnectingWebSocket", () => { ])( "flushes with the route on an unrecoverable HTTP failure: %i", async (statusCode) => { - const onConnectionFailure = vi.fn(); - const { ws, sockets } = await createReconnectingWebSocket({ - onConnectionFailure, - }); + const { ws, sockets, onConnectionFailure } = + await createReconnectingWebSocket(); sockets[0].fireError( new Error(`Unexpected server response: ${statusCode}`), @@ -192,10 +202,8 @@ describe("ReconnectingWebSocket", () => { ); it("does not read host/port digits as a status code", async () => { - const onConnectionFailure = vi.fn(); - const { ws, sockets } = await createReconnectingWebSocket({ - onConnectionFailure, - }); + const { ws, sockets, onConnectionFailure } = + await createReconnectingWebSocket(); // A port ending in 404x must not be treated as HTTP 404. sockets[0].fireError(new Error("connect ECONNREFUSED 127.0.0.1:4040")); @@ -763,6 +771,7 @@ describe("ReconnectingWebSocket", () => { const setupRefreshTest = async (onRefresh: () => Promise) => { const sockets: MockSocket[] = []; const refreshCallback = vi.fn().mockImplementation(onRefresh); + const onConnectionFailure = vi.fn(); const factory = vi.fn(() => { const socket = createMockSocket(); sockets.push(socket); @@ -770,9 +779,10 @@ describe("ReconnectingWebSocket", () => { }); const ws = await fromFactory(factory, { onCertificateRefreshNeeded: refreshCallback, + onConnectionFailure, }); sockets[0].fireOpen(); - return { ws, sockets, refreshCallback }; + return { ws, sockets, refreshCallback, onConnectionFailure }; }; it("reconnects after successful refresh", async () => { @@ -790,7 +800,7 @@ describe("ReconnectingWebSocket", () => { }); it("disconnects when refresh fails", async () => { - const { ws, sockets } = await setupRefreshTest(() => + const { ws, sockets, onConnectionFailure } = await setupRefreshTest(() => Promise.resolve(false), ); @@ -800,6 +810,10 @@ describe("ReconnectingWebSocket", () => { ); expect(sockets).toHaveLength(1); + expect(onConnectionFailure).toHaveBeenCalledWith( + "certificate_error", + expect.any(String), + ); ws.close(); }); @@ -853,71 +867,9 @@ describe("ReconnectingWebSocket", () => { }); describe("Connection failure callback", () => { - it.each([ - "unrecoverable_close", - "unrecoverable_http", - "certificate_error", - ] as const)("treats %s as a terminal connection failure", (reason) => { - expect(isTerminalConnectionFailure(reason)).toBe(true); - }); - - it.each([ - "initial_connect", - "manual_reconnect", - "scheduled_reconnect", - "open", - "disconnect", - "dispose", - "connection_error", - "normal_close", - "unexpected_close", - ] as const)( - "does not treat %s as a terminal connection failure", - (reason) => { - expect(isTerminalConnectionFailure(reason)).toBe(false); - }, - ); - - it("fires onConnectionFailure on an unrecoverable close code", async () => { - const onConnectionFailure = vi.fn(); - const { ws, sockets } = await createReconnectingWebSocket({ - onConnectionFailure, - }); - - sockets[0].fireOpen(); - sockets[0].fireClose({ - code: WebSocketCloseCode.PROTOCOL_ERROR, - reason: "Unrecoverable", - }); - - expect(onConnectionFailure).toHaveBeenCalledWith( - "unrecoverable_close", - expect.any(String), - ); - ws.close(); - }); - - it("does not fire onConnectionFailure on a normal close", async () => { - const onConnectionFailure = vi.fn(); - const { ws, sockets } = await createReconnectingWebSocket({ - onConnectionFailure, - }); - - sockets[0].fireOpen(); - sockets[0].fireClose({ - code: WebSocketCloseCode.NORMAL, - reason: "Normal", - }); - - expect(onConnectionFailure).not.toHaveBeenCalled(); - ws.close(); - }); - it("does not fire onConnectionFailure on a manual disconnect", async () => { - const onConnectionFailure = vi.fn(); - const { ws, sockets } = await createReconnectingWebSocket({ - onConnectionFailure, - }); + const { ws, sockets, onConnectionFailure } = + await createReconnectingWebSocket(); sockets[0].fireOpen(); ws.disconnect(); @@ -925,22 +877,6 @@ describe("ReconnectingWebSocket", () => { expect(onConnectionFailure).not.toHaveBeenCalled(); ws.close(); }); - - it("does not fire onConnectionFailure on a transient reconnecting drop", async () => { - const onConnectionFailure = vi.fn(); - const { ws, sockets } = await createReconnectingWebSocket({ - onConnectionFailure, - }); - - sockets[0].fireOpen(); - sockets[0].fireClose({ - code: WebSocketCloseCode.ABNORMAL, - reason: "Network error", - }); - - expect(onConnectionFailure).not.toHaveBeenCalled(); - ws.close(); - }); }); }); @@ -1012,6 +948,10 @@ function createMockSocket(): MockSocket { }; } +type ConnectionFailureSpy = ReturnType< + typeof vi.fn<(reason: ConnectionStateReason, route: string) => void> +>; + interface FactoryOptions { onDispose?: () => void; onCertificateRefreshNeeded?: () => Promise; @@ -1024,16 +964,19 @@ async function createReconnectingWebSocket( ): Promise<{ ws: ReconnectingWebSocket; sockets: MockSocket[]; + onConnectionFailure: ConnectionFailureSpy; }> { const sockets: MockSocket[] = []; + const onConnectionFailure = + vi.fn<(reason: ConnectionStateReason, route: string) => void>(); const factory = vi.fn(() => { const socket = createMockSocket(); sockets.push(socket); return Promise.resolve(socket); }); - const ws = await fromFactory(factory, options); + const ws = await fromFactory(factory, { ...options, onConnectionFailure }); expect(sockets).toHaveLength(1); - return { ws, sockets }; + return { ws, sockets, onConnectionFailure }; } async function createReconnectingWebSocketWithErrorControl( @@ -1078,7 +1021,7 @@ async function fromFactory( telemetry: options.telemetry ?? NOOP_TELEMETRY_REPORTER, onCertificateRefreshNeeded: options.onCertificateRefreshNeeded ?? (() => Promise.resolve(false)), - onConnectionFailure: options.onConnectionFailure, + onConnectionFailure: options.onConnectionFailure ?? vi.fn(), }, options.onDispose, ); From e1afe04e25315c33b7182e2bbfea0868abbd5e1e Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 00:34:53 +0000 Subject: [PATCH 28/60] docs: tighten the connection log buffer notes - Drop the em dash and the stale agent-disconnected flush trigger. - Reflect the workspace-open failure trigger and the 401 exclusion. - Shorten the not-buffered note to a single sentence. --- CONTRIBUTING.md | 19 ++++++++++--------- 1 file changed, 10 insertions(+), 9 deletions(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index eb773c2b39..ebf73d0780 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -139,26 +139,27 @@ messages by the level chosen in its gear menu. To help Support diagnose connection failures without asking users to reproduce with debug logging enabled, a `BufferingLogger` ([`src/logging/logBuffer.ts`](src/logging/logBuffer.ts)) wraps the channel and keeps a bounded, in-memory ring of the entries that sit -**below** the current level — the ones the channel would otherwise drop. +**below** the current level, which the channel would otherwise drop. On a genuine connection failure the buffer is flushed: the captured entries are re-emitted into the output channel (each marked `[buffered]` with its original timestamp and level) so they land on disk and in a support bundle. Only below-level entries are buffered, so nothing already written is duplicated. -Flush happens only on genuine failures, never on transient drops or intentional +The buffer flushes only on genuine connection failures, not on transient +reconnects, a handshake `401` that a token refresh recovers, or intentional teardown: - a reconnecting WebSocket terminal failure (`unrecoverable_close`, - `unrecoverable_http`, `certificate_error`); -- an agent reported as `disconnected` during connection. + `unrecoverable_http`, or `certificate_error`); +- a failure while opening a workspace (canceled build, missing agent, timeout, + or CLI/certificate error). -The buffer size is set by `coder.connectionLogBuffer.size` (maximum number of -entries, capped at 10,000; `0` disables it). It lives in memory, so a hard kill or out-of-memory event +The buffer size is set by `coder.connectionLogBuffer.size` (number of entries; +`0` disables it) and lives in memory, so a hard kill or out-of-memory event loses it. Extension SSH debug logs that pass through the shared logger are -buffered. The CLI `ProxyCommand` writes its own file logs under -`coder.proxyLogDirectory`, which support bundles already collect from disk, so -those are not buffered here. +buffered; the CLI `ProxyCommand` file logs under `coder.proxyLogDirectory` are +not, since support bundles already collect them from disk. ## Testing From c39b8f2a103225851178fb03a66225c41e056e3b Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 10:48:09 -0700 Subject: [PATCH 29/60] test: narrow LogMethod type, and factor out LevelCase/CapacityCase interfaces to remove type casts --- test/unit/logging/logBuffer.test.ts | 51 ++++++++++++++++++----------- 1 file changed, 32 insertions(+), 19 deletions(-) diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index b9630b26ac..a3be8052ba 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -11,10 +11,10 @@ const INFO = 3; const WARNING = 4; const ERROR = 5; -type LogMethod = "trace" | "debug" | "info" | "warn" | "error"; +type LogMethod = Exclude; interface Call { - level: keyof Logger; + level: LogMethod; message: string; args: unknown[]; } @@ -22,7 +22,7 @@ interface Call { function setup(level: number, capacity: number) { const calls: Call[] = []; const push = - (method: keyof Logger) => + (method: LogMethod) => (message: string, ...args: unknown[]) => calls.push({ level: method, message, args }); const logger: Logger = { @@ -67,30 +67,37 @@ describe("BufferingLogger", () => { ]); }); - it.each([ + interface LevelCase { + level: number; + hidden: LogMethod; + shown: LogMethod; + sink: "info" | "warn" | "error"; + } + + it.each([ { level: DEBUG, - hidden: "trace" as LogMethod, - shown: "debug" as LogMethod, - sink: "info" as const, + hidden: "trace", + shown: "debug", + sink: "info", }, { level: INFO, - hidden: "debug" as LogMethod, - shown: "info" as LogMethod, - sink: "info" as const, + hidden: "debug", + shown: "info", + sink: "info", }, { level: WARNING, - hidden: "info" as LogMethod, - shown: "warn" as LogMethod, - sink: "warn" as const, + hidden: "info", + shown: "warn", + sink: "warn", }, { level: ERROR, - hidden: "warn" as LogMethod, - shown: "error" as LogMethod, - sink: "error" as const, + hidden: "warn", + shown: "error", + sink: "error", }, ])( "at level $level buffers below-level entries and replays them via the $sink sink", @@ -119,18 +126,24 @@ describe("BufferingLogger", () => { expect(lines.some((l) => l.includes("info at info level"))).toBe(false); }); - it.each([ + interface CapacityCase { + name: string; + capacity: number; + shrinkTo?: number; + present: string[]; + absent: string[]; + } + + it.each([ { name: "evicts the oldest entry when capacity is exceeded", capacity: 2, - shrinkTo: undefined as number | undefined, present: ["two", "three"], absent: ["one"], }, { name: "buffers nothing when capacity is zero", capacity: 0, - shrinkTo: undefined as number | undefined, present: [], absent: ["one", "two", "three"], }, From d365e4197273c15cdc7054d2cecc215aef11c92f Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 11:10:07 -0700 Subject: [PATCH 30/60] docs: compress buffer triggers + use active over passive voice --- CONTRIBUTING.md | 18 +++++------------- 1 file changed, 5 insertions(+), 13 deletions(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index ebf73d0780..085c926c97 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -141,19 +141,11 @@ a `BufferingLogger` ([`src/logging/logBuffer.ts`](src/logging/logBuffer.ts)) wraps the channel and keeps a bounded, in-memory ring of the entries that sit **below** the current level, which the channel would otherwise drop. -On a genuine connection failure the buffer is flushed: the captured entries are -re-emitted into the output channel (each marked `[buffered]` with its original -timestamp and level) so they land on disk and in a support bundle. Only -below-level entries are buffered, so nothing already written is duplicated. - -The buffer flushes only on genuine connection failures, not on transient -reconnects, a handshake `401` that a token refresh recovers, or intentional -teardown: - -- a reconnecting WebSocket terminal failure (`unrecoverable_close`, - `unrecoverable_http`, or `certificate_error`); -- a failure while opening a workspace (canceled build, missing agent, timeout, - or CLI/certificate error). +When a WebSocket fails terminally, a workspace fails to open, or you collect a +support bundle, the extension replays the ring into the channel. Each replayed +line carries a `[buffered]` marker with its original timestamp and level, so it +lands on disk and in the bundle. Transient reconnects and intentional teardown +never flush. Nothing is recorded or flushed while the channel is at `Off`. The buffer size is set by `coder.connectionLogBuffer.size` (number of entries; `0` disables it) and lives in memory, so a hard kill or out-of-memory event From df48a9049e9410fe949c4dcb7b4787f258e52c88 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 11:12:19 -0700 Subject: [PATCH 31/60] docs: shorten logger function comments --- src/settings/logger.ts | 9 +++------ 1 file changed, 3 insertions(+), 6 deletions(-) diff --git a/src/settings/logger.ts b/src/settings/logger.ts index 046c43f98f..a7537af0c4 100644 --- a/src/settings/logger.ts +++ b/src/settings/logger.ts @@ -6,18 +6,15 @@ export const CONNECTION_LOG_BUFFER_SIZE_SETTING = "coder.connectionLogBuffer.size"; export const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000; /** - * Largest configurable capacity. Bounds the entry count kept in memory; each - * entry still holds live `args` references, so this is a count, not a byte cap. + * Largest configurable capacity, in entries. */ export const MAX_CONNECTION_LOG_BUFFER_SIZE = 10_000; const HTTP_CLIENT_LOG_LEVEL_SETTING = "coder.httpClientLogLevel"; /** - * Number of connection log entries to buffer below the output channel's level. - * `0` disables buffering; larger values are clamped to - * {@link MAX_CONNECTION_LOG_BUFFER_SIZE}. Missing, non-numeric, non-finite, or - * negative values fall back to the default rather than silently disabling. + * Buffer size in entries, clamped to the maximum; invalid values fall back + * to the default. */ export function readConnectionLogBufferSize( cfg: Pick, From 32eb53f4e5db7768ca95b5993f2dec05b4d393d7 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 11:14:12 -0700 Subject: [PATCH 32/60] docs: rm reference to call sites from ConnectionLogBuffer comment --- src/logging/logBuffer.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 83a6bf8617..890801bcf3 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -18,7 +18,7 @@ type Level = keyof typeof SEVERITY; /** Sink methods that the output channel persists at any non-Off level. */ type ReplaySink = "info" | "warn" | "error"; -/** The failure-time surface used by connection-failure call sites. */ +/** Replays buffered below-level log entries on a connection failure. */ export interface ConnectionLogBuffer { flush(reason: string): void; } From 0ac564aa378c8bced048c157e67dbd0bb4c019ad Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 11:15:29 -0700 Subject: [PATCH 33/60] docs: describe getConnectionLogBuffer per se, not its caller --- src/core/container.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/core/container.ts b/src/core/container.ts index 08308f8363..9f7df9fc2a 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -174,7 +174,7 @@ export class ServiceContainer implements vscode.Disposable { return this.logger; } - /** The below-level connection log buffer; flush it on a connection failure. */ + /** The connection log buffer that replays below-level entries on failure. */ getConnectionLogBuffer(): ConnectionLogBuffer { return this.logger; } From 544d143b0f3870e3483a2016e7af0eabbab5afd1 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 11:21:23 -0700 Subject: [PATCH 34/60] docs: remove overpromise about turning logging back on from flush comment --- src/logging/logBuffer.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 890801bcf3..50eda9746a 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -67,8 +67,8 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { * since this one, so consecutive failures never duplicate entries. */ public flush(reason: string): void { - // The channel writes nothing at Off, so replaying now would discard the - // context. Keep it buffered until logging is turned back on. + // The channel writes nothing at Off. Keep the entries for the next flush; + // nothing new is recorded while Off. if (this.channel.logLevel === 0) { return; } From 5e539880338075b401b6c7db7a50ddfbde3156be Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 11:59:39 -0700 Subject: [PATCH 35/60] fix: flush on every closeRemote --- src/extension.ts | 1 - src/remote/remote.ts | 3 +++ 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/src/extension.ts b/src/extension.ts index 7e9a66007b..7abb66ae2f 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -515,7 +515,6 @@ async function doActivate( ); } // Always close remote session when we fail to open a workspace. - serviceContainer.getConnectionLogBuffer().flush("workspace_open_failed"); await remote.closeRemote(); return; } diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 99b3c98472..2e441777cd 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -1097,6 +1097,9 @@ export class Remote { // closeRemote ends the current remote session. public async closeRemote() { + this.serviceContainer + .getConnectionLogBuffer() + .flush("workspace_open_failed"); await vscode.commands.executeCommand("workbench.action.remote.close"); } From 3507a6772ba8e23119ad49edba3f00b9ed584d66 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:15:49 +0000 Subject: [PATCH 36/60] fix(websocket): reconnect after server-initiated normal closes handleSocketClose only runs for server-initiated closes (intentional disconnect()/close() dispatch first and return early), so parking the socket on 1000/1001 left the workspace monitor and inbox dead for the session after a coderd redeploy (liveness 1001, shutdown 1000). Drop the NORMAL_CLOSURE_CODES branch and set so those codes fall through to the backoff retry. --- src/websocket/codes.ts | 6 ------ src/websocket/reconnectingWebSocket.ts | 13 ++++--------- .../unit/websocket/reconnectingWebSocket.test.ts | 16 +++++++++------- 3 files changed, 13 insertions(+), 22 deletions(-) diff --git a/src/websocket/codes.ts b/src/websocket/codes.ts index f3fd95cdb5..1ea808fec0 100644 --- a/src/websocket/codes.ts +++ b/src/websocket/codes.ts @@ -51,9 +51,3 @@ export const UNRECOVERABLE_HTTP_CODES = new Set([ HttpStatusCode.GONE, HttpStatusCode.UPGRADE_REQUIRED, ]); - -/** Close codes indicating intentional closure - do not reconnect */ -export const NORMAL_CLOSURE_CODES = new Set([ - WebSocketCloseCode.NORMAL, - WebSocketCloseCode.GOING_AWAY, -]); diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index d460dacee0..f37329eca1 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -9,7 +9,6 @@ import { import { WebSocketCloseCode, HttpStatusCode, - NORMAL_CLOSURE_CODES, UNRECOVERABLE_WS_CLOSE_CODES, UNRECOVERABLE_HTTP_CODES, } from "./codes"; @@ -435,14 +434,10 @@ export class ReconnectingWebSocket< return; } - if (NORMAL_CLOSURE_CODES.has(event.code)) { - this.disconnectWithReason("normal_close", "normal_close", { - code: event.code, - closeReason: event.reason, - }); - return; - } - + // Every close that reaches here is server-initiated: intentional + // disconnect()/close() dispatch first and return early above. Normal + // codes such as coderd's liveness 1001 or a shutdown 1000 must reconnect, + // so they fall through to the backoff retry below. this.scheduleReconnect("unexpected_close", "unexpected_close", { code: event.code, error: toCloseEventError(event), diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index b89479d5e7..df8c6dd06d 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -61,16 +61,18 @@ describe("ReconnectingWebSocket", () => { { code: WebSocketCloseCode.NORMAL, name: "Normal Closure" }, { code: WebSocketCloseCode.GOING_AWAY, name: "Going Away" }, ])( - "does not reconnect on normal closure: $name ($code)", + "reconnects on a server-initiated normal closure: $name ($code)", async ({ code }) => { const { ws, sockets, onConnectionFailure } = await createReconnectingWebSocket(); sockets[0].fireOpen(); sockets[0].fireClose({ code, reason: "Normal" }); + expect(ws.state).toBe(ConnectionState.AWAITING_RETRY); - await vi.advanceTimersByTimeAsync(10000); - expect(sockets).toHaveLength(1); + await vi.advanceTimersByTimeAsync(300); + expect(sockets).toHaveLength(2); + // A server-initiated close is not a terminal failure. expect(onConnectionFailure).not.toHaveBeenCalled(); ws.close(); @@ -713,7 +715,7 @@ describe("ReconnectingWebSocket", () => { ]); }); - it("emits a normal-close drop and disconnects on server-initiated close", async () => { + it("emits an unexpected-close drop and reconnects on a server-initiated close", async () => { const sink = new TestSink(); const telemetry = createTestTelemetryService(sink); const { ws, sockets } = await createReconnectingWebSocket({ telemetry }); @@ -724,18 +726,18 @@ describe("ReconnectingWebSocket", () => { reason: "server restarting", }); - expect(ws.state).toBe(ConnectionState.DISCONNECTED); + expect(ws.state).toBe(ConnectionState.AWAITING_RETRY); const dropped = sink.eventsNamed("connection.dropped"); expect(dropped).toHaveLength(1); expect(dropped[0].properties).toMatchObject({ - cause: "normal_close", + cause: "unexpected_close", close_code: String(WebSocketCloseCode.GOING_AWAY), }); expect( sink .eventsNamed("connection.state_transitioned") .map((e) => e.properties.reason), - ).toContain("normal_close"); + ).toContain("unexpected_close"); ws.close(); }); From f5eb418cfcc3f8bde39e7ecbbec3055bc3543308 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:19:36 +0000 Subject: [PATCH 37/60] fix(websocket): match ws and eventsource handshake status codes The addEventListener fix routed SSE handshake failures through the same status check, but eventsource reports 'Non-200 status code ()', which the ws-only regex missed, so a 401/403/404/410 on the SSE fallback retried forever without flushing. Add a shared handshakeStatus() helper that parses both formats and use it for the unrecoverable-HTTP check and is404Error (dropping the includes('404') false positive). --- src/api/coderApi.ts | 4 ++-- src/websocket/reconnectingWebSocket.ts | 11 ++++------- src/websocket/utils.ts | 18 ++++++++++++++++++ test/unit/api/coderApi.test.ts | 8 +++++--- .../websocket/reconnectingWebSocket.test.ts | 18 +++++++++--------- 5 files changed, 38 insertions(+), 21 deletions(-) diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index b445352691..fae598f761 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -46,6 +46,7 @@ import { type SocketFactory, } from "../websocket/reconnectingWebSocket"; import { SseConnection } from "../websocket/sseConnection"; +import { handshakeStatus } from "../websocket/utils"; import { getRefreshCommand, refreshCertificates } from "./certificateRefresh"; import { @@ -538,8 +539,7 @@ export class CoderApi extends Api implements vscode.Disposable { * Check if an error is a 404 Not Found error. */ private is404Error(error: unknown): boolean { - const msg = error instanceof Error ? error.message : String(error); - return msg.includes(String(HttpStatusCode.NOT_FOUND)); + return handshakeStatus(error) === HttpStatusCode.NOT_FOUND; } /** diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index f37329eca1..a781dfdd83 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -12,6 +12,7 @@ import { UNRECOVERABLE_WS_CLOSE_CODES, UNRECOVERABLE_HTTP_CODES, } from "./codes"; +import { handshakeStatus } from "./utils"; import type { WebSocketEventType } from "coder/site/src/utils/OneWayWebSocket"; @@ -571,17 +572,13 @@ export class ReconnectingWebSocket< /** * Returns the unrecoverable HTTP status carried by a failed handshake, or - * `undefined`. Matches the `ws` "Unexpected server response: " message - * exactly so host/port digits like `127.0.0.1:4040` cannot masquerade as a - * status code. + * `undefined`. */ private unrecoverableHttpStatus(error: unknown): number | undefined { - const message = (error as { message?: string }).message || String(error); - const match = /unexpected server response:\s*(\d{3})/i.exec(message); - if (!match) { + const status = handshakeStatus(error); + if (status === undefined) { return undefined; } - const status = Number(match[1]); return UNRECOVERABLE_HTTP_CODES.has(status) ? status : undefined; } diff --git a/src/websocket/utils.ts b/src/websocket/utils.ts index 8fa34c61ac..aa7a15fcbc 100644 --- a/src/websocket/utils.ts +++ b/src/websocket/utils.ts @@ -27,3 +27,21 @@ export function rawDataToString(data: RawData): string { return new TextDecoder().decode(data); } } + +/** + * Parses the HTTP status carried by a failed WebSocket or SSE handshake. + * + * `ws` rejects with `Unexpected server response: ` and `eventsource` + * with `Non-200 status code ()`. Matching the phrase before the digits + * keeps a host/port such as `127.0.0.1:4040` from masquerading as a status + * code. + */ +const HANDSHAKE_STATUS = + /(?:unexpected server response:|non-200 status code \()\s*(\d{3})/i; + +/** HTTP status from a failed `ws` or `eventsource` handshake, or `undefined`. */ +export function handshakeStatus(error: unknown): number | undefined { + const message = (error as { message?: string }).message || String(error); + const match = HANDSHAKE_STATUS.exec(message); + return match ? Number(match[1]) : undefined; +} diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index 983ca3f62b..1e188f2ff5 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -645,8 +645,8 @@ describe("CoderApi", () => { `wss://${CODER_URL.replace("https://", "")}/api/v2/test`, { connectError: { - error: new Error("404 Not Found"), - message: "404 Not Found", + error: new Error("Unexpected server response: 404"), + message: "Unexpected server response: 404", }, }, ); @@ -684,7 +684,9 @@ describe("CoderApi", () => { vi.mocked(Ws).mockImplementation(function () { wsAttempts++; const mockWs = createMockWebSocket("wss://test", { - connectError: { error: new Error("Something 404") }, + connectError: { + error: new Error("Unexpected server response: 404"), + }, }); return mockWs as Ws; }); diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index df8c6dd06d..13d23bc300 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -106,19 +106,19 @@ describe("ReconnectingWebSocket", () => { ); it.each([ - HttpStatusCode.FORBIDDEN, - HttpStatusCode.GONE, - HttpStatusCode.UPGRADE_REQUIRED, + `Unexpected server response: ${HttpStatusCode.FORBIDDEN}`, + `Unexpected server response: ${HttpStatusCode.GONE}`, + `Unexpected server response: ${HttpStatusCode.UPGRADE_REQUIRED}`, + // eventsource (SSE fallback) reports the status this way. + `Non-200 status code (${HttpStatusCode.FORBIDDEN})`, ])( - "does not reconnect on unrecoverable HTTP error during creation: %i", - async (statusCode) => { + "does not reconnect on an unrecoverable handshake failure during creation: %s", + async (message) => { let socketCreationAttempts = 0; const factory = vi.fn(() => { socketCreationAttempts++; - // Simulate HTTP error during WebSocket handshake - return Promise.reject( - new Error(`Unexpected server response: ${statusCode}`), - ); + // Simulate an HTTP error during the handshake. + return Promise.reject(new Error(message)); }); // create() returns a disconnected instance instead of throwing From 4e43f5b3df811c4f54c4e9360ce54f6103526553 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:21:07 +0000 Subject: [PATCH 38/60] refactor(websocket): gate the buffer flush on an explicit failure flag The terminal-reason set, isTerminalConnectionFailure, and the negated flushable option all restated what the three failure call sites already know. Replace them with a single failure?: boolean on disconnectWithReason (true for unrecoverable close and certificate errors, status-dependent for unrecoverable HTTP so a 401 stays non-flushing). --- src/websocket/reconnectingWebSocket.ts | 24 +++++++++--------------- 1 file changed, 9 insertions(+), 15 deletions(-) diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index a781dfdd83..c4c7484355 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -29,17 +29,6 @@ function toCloseEventError(event: CloseEvent): Error { return new Error(`WebSocket closed with code ${event.code}: ${event.reason}`); } -/** - * Connection failures that stop automatic retries. - */ -const TERMINAL_CONNECTION_FAILURE_REASONS: ReadonlySet = - new Set(["unrecoverable_close", "unrecoverable_http", "certificate_error"]); - -/** Whether a reason stops automatic retries. */ -function isTerminalConnectionFailure(reason: ConnectionStateReason): boolean { - return TERMINAL_CONNECTION_FAILURE_REASONS.has(reason); -} - /** * Connection states for the ReconnectingWebSocket state machine. */ @@ -307,7 +296,8 @@ export class ReconnectingWebSocket< code?: number; closeReason?: string; error?: unknown; - flushable?: boolean; + /** Flush the connection log buffer: a genuine, surfaced failure. */ + failure?: boolean; } = {}, ): void { if (!this.#dispatch({ type: "DISCONNECT" }, reason)) { @@ -319,7 +309,7 @@ export class ReconnectingWebSocket< error: options.error, }); this.clearCurrentSocket(options.code, options.closeReason); - if (isTerminalConnectionFailure(reason) && options.flushable !== false) { + if (options.failure) { this.#onConnectionFailure?.(reason, this.#route); } } @@ -431,6 +421,7 @@ export class ReconnectingWebSocket< code: event.code, closeReason: event.reason, error: toCloseEventError(event), + failure: true, }); return; } @@ -550,7 +541,7 @@ export class ReconnectingWebSocket< // the same socket seconds later, so it is not a genuine outage to flush. this.disconnectWithReason("unrecoverable_http", "error", { error, - flushable: unrecoverableStatus !== HttpStatusCode.UNAUTHORIZED, + failure: unrecoverableStatus !== HttpStatusCode.UNAUTHORIZED, }); return; } @@ -561,7 +552,10 @@ export class ReconnectingWebSocket< if (await this.handleClientCertificateError(certError)) { this.#reconnectInternal("certificate_refresh"); } else { - this.disconnectWithReason("certificate_error", "error", { error }); + this.disconnectWithReason("certificate_error", "error", { + error, + failure: true, + }); } return; } From 76d23e2d0a5155eaef8fe5674883a81376830c3b Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:24:40 +0000 Subject: [PATCH 39/60] fix(websocket): seed the socket route so first-connect failures log it #lastRoute stayed "unknown" until the factory resolved, but waitForOpen turns every handshake failure into a factory rejection, so the flush header read "unrecoverable_http unknown" exactly when it mattered. Add a required route to ReconnectingWebSocketOptions, seed #lastRoute from it, and thread apiRoute through createReconnectingSocket's three callers. --- src/api/coderApi.ts | 52 +++++++++++-------- src/websocket/reconnectingWebSocket.ts | 10 +++- test/unit/api/coderApi.test.ts | 2 +- .../websocket/reconnectingWebSocket.test.ts | 4 +- 4 files changed, 42 insertions(+), 26 deletions(-) diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index fae598f761..eb2ad332fa 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -291,26 +291,30 @@ export class CoderApi extends Api implements vscode.Disposable { watchTargets: string[], options?: ClientOptions, ) => { - return this.createReconnectingSocket(() => - this.createOneWayWebSocket({ - apiRoute: "/api/v2/notifications/inbox/watch", - searchParams: { - format: "plaintext", - templates: watchTemplates.join(","), - targets: watchTargets.join(","), - }, - options, - }), + return this.createReconnectingSocket( + "/api/v2/notifications/inbox/watch", + () => + this.createOneWayWebSocket({ + apiRoute: "/api/v2/notifications/inbox/watch", + searchParams: { + format: "plaintext", + templates: watchTemplates.join(","), + targets: watchTargets.join(","), + }, + options, + }), ); }; watchWorkspace = async (workspace: Workspace, options?: ClientOptions) => { - return this.createReconnectingSocket(() => - this.createStreamWithSseFallback({ - apiRoute: `/api/v2/workspaces/${workspace.id}/watch-ws`, - fallbackApiRoute: `/api/v2/workspaces/${workspace.id}/watch`, - options, - }), + return this.createReconnectingSocket( + `/api/v2/workspaces/${workspace.id}/watch-ws`, + () => + this.createStreamWithSseFallback({ + apiRoute: `/api/v2/workspaces/${workspace.id}/watch-ws`, + fallbackApiRoute: `/api/v2/workspaces/${workspace.id}/watch`, + options, + }), ); }; @@ -318,12 +322,14 @@ export class CoderApi extends Api implements vscode.Disposable { agentId: WorkspaceAgent["id"], options?: ClientOptions, ) => { - return this.createReconnectingSocket(() => - this.createStreamWithSseFallback({ - apiRoute: `/api/v2/workspaceagents/${agentId}/watch-metadata-ws`, - fallbackApiRoute: `/api/v2/workspaceagents/${agentId}/watch-metadata`, - options, - }), + return this.createReconnectingSocket( + `/api/v2/workspaceagents/${agentId}/watch-metadata-ws`, + () => + this.createStreamWithSseFallback({ + apiRoute: `/api/v2/workspaceagents/${agentId}/watch-metadata-ws`, + fallbackApiRoute: `/api/v2/workspaceagents/${agentId}/watch-metadata`, + options, + }), ); }; @@ -546,9 +552,11 @@ export class CoderApi extends Api implements vscode.Disposable { * Create a ReconnectingWebSocket and track it for lifecycle management. */ private async createReconnectingSocket( + apiRoute: string, socketFactory: SocketFactory, ): Promise> { const options: ReconnectingWebSocketOptions = { + route: apiRoute, onCertificateRefreshNeeded: async () => { const refreshCommand = getRefreshCommand(); if (!refreshCommand) { diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index c4c7484355..5a4e021205 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -116,6 +116,8 @@ export interface ReconnectingWebSocketOptions { maxBackoffMs?: number; jitterFactor?: number; telemetry: TelemetryReporter; + /** API route (pathname) of the socket, used to seed logging before the first connect resolves. */ + route: string; /** Callback invoked when a refreshable certificate error is detected. Returns true if refresh succeeded. */ onCertificateRefreshNeeded: () => Promise; /** Callback invoked when the connection fails terminally (not a transient drop). */ @@ -129,7 +131,10 @@ export class ReconnectingWebSocket< readonly #logger: Logger; readonly #telemetry: WebSocketTelemetry; readonly #options: Required< - Omit + Omit< + ReconnectingWebSocketOptions, + "telemetry" | "onConnectionFailure" | "route" + > >; readonly #onConnectionFailure?: ( reason: ConnectionStateReason, @@ -145,7 +150,7 @@ export class ReconnectingWebSocket< }; #currentSocket: UnidirectionalStream | null = null; - #lastRoute = "unknown"; // Cached route for logging when socket is closed + #lastRoute: string; // Cached route for logging when socket is closed #backoffMs: number; #reconnectTimeoutId: NodeJS.Timeout | null = null; #state: ConnectionState = ConnectionState.IDLE; @@ -189,6 +194,7 @@ export class ReconnectingWebSocket< onCertificateRefreshNeeded: options.onCertificateRefreshNeeded, }; this.#onConnectionFailure = options.onConnectionFailure; + this.#lastRoute = options.route; this.#backoffMs = this.#options.initialBackoffMs; this.#onDispose = onDispose; } diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index 1e188f2ff5..f2981e0665 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -600,7 +600,7 @@ describe("CoderApi", () => { expect(onConnectionFailure).toHaveBeenCalledWith( "unrecoverable_close", - expect.any(String), + `/api/v2/workspaceagents/${AGENT_ID}/watch-metadata-ws`, ); connection.close(); }); diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index 13d23bc300..df7fb297b3 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -133,7 +133,7 @@ describe("ReconnectingWebSocket", () => { expect(socketCreationAttempts).toBe(1); expect(onConnectionFailure).toHaveBeenCalledWith( "unrecoverable_http", - expect.any(String), + "/api/v2/test", ); ws.close(); @@ -958,6 +958,7 @@ interface FactoryOptions { onDispose?: () => void; onCertificateRefreshNeeded?: () => Promise; onConnectionFailure?: (reason: ConnectionStateReason, route: string) => void; + route?: string; telemetry?: TelemetryReporter; } @@ -1021,6 +1022,7 @@ async function fromFactory( createMockLogger(), { telemetry: options.telemetry ?? NOOP_TELEMETRY_REPORTER, + route: options.route ?? "/api/v2/test", onCertificateRefreshNeeded: options.onCertificateRefreshNeeded ?? (() => Promise.resolve(false)), onConnectionFailure: options.onConnectionFailure ?? vi.fn(), From 456a9dce978c9fc27c4c26db810c3c5f0693db1c Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:28:51 +0000 Subject: [PATCH 40/60] fix(logging): bound the buffer by characters and replay in chunks Body-level HTTP logging can pin tens to hundreds of MB in the ring, with args held as live references, and flush() sent one RPC per entry (up to 10k) inside the close handler. Format each entry into a single string at record time, hold a 2 MB character budget alongside the entry count, and replay 100 prefixed lines per channel call. --- src/logging/logBuffer.ts | 56 ++++++++++++++++++++++------- test/unit/logging/logBuffer.test.ts | 29 ++++++++++----- 2 files changed, 65 insertions(+), 20 deletions(-) diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 50eda9746a..0aa0240631 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -1,3 +1,5 @@ +import { safeStringify } from "./utils"; + import type { Logger } from "./logger"; /** @@ -18,6 +20,15 @@ type Level = keyof typeof SEVERITY; /** Sink methods that the output channel persists at any non-Off level. */ type ReplaySink = "info" | "warn" | "error"; +/** + * Character budget for the buffered text, independent of the entry count. Bounds + * worst-case memory when `httpClientLogLevel: body` makes each entry large. + */ +const MAX_BUFFERED_CHARS = 2_000_000; + +/** Entries replayed per channel call, so a flush is not one RPC per entry. */ +const REPLAY_CHUNK = 100; + /** Replays buffered below-level log entries on a connection failure. */ export interface ConnectionLogBuffer { flush(reason: string): void; @@ -26,8 +37,8 @@ export interface ConnectionLogBuffer { interface LogEntry { readonly atMs: number; readonly level: Level; - readonly message: string; - readonly args: unknown[]; + /** Message and args formatted once at record time; holds no live references. */ + readonly text: string; } /** @@ -36,6 +47,7 @@ interface LogEntry { */ export class BufferingLogger implements Logger, ConnectionLogBuffer { private entries: LogEntry[] = []; + private chars = 0; public constructor( private readonly inner: Logger, @@ -53,12 +65,10 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { this.inner.show(); } - /** Resize the ring, keeping the most recent entries. */ + /** Resize the ring, keeping the most recent entries within both budgets. */ public setCapacity(capacity: number): void { this.capacity = capacity; - if (this.entries.length > this.capacity) { - this.entries.splice(0, this.entries.length - this.capacity); - } + this.trim(); } /** @@ -77,14 +87,20 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { } const entries = this.entries; this.entries = []; + this.chars = 0; const sink = this.replaySink(); this.inner[sink]( `[buffered] connection failure (${reason}): replaying ${entries.length} buffered entries`, ); - for (const entry of entries) { - const line = `[buffered] ${new Date(entry.atMs).toISOString()} ${entry.level.toUpperCase()} ${entry.message}`; - this.inner[sink](line.replaceAll("\n", "\n[buffered] "), ...entry.args); + const lines = entries.map((entry) => + `[buffered] ${new Date(entry.atMs).toISOString()} ${entry.level.toUpperCase()} ${entry.text}`.replaceAll( + "\n", + "\n[buffered] ", + ), + ); + for (let i = 0; i < lines.length; i += REPLAY_CHUNK) { + this.inner[sink](lines.slice(i, i + REPLAY_CHUNK).join("\n")); } this.inner[sink](`[buffered] end of buffered logs (${reason})`); } @@ -116,9 +132,25 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { if (this.capacity === 0 || SEVERITY[level] >= this.channel.logLevel) { return; } - this.entries.push({ atMs: Date.now(), level, message, args }); - if (this.entries.length > this.capacity) { - this.entries.shift(); + const text = [message, ...args.map((arg) => safeStringify(arg) ?? "")].join( + " ", + ); + this.entries.push({ atMs: Date.now(), level, text }); + this.chars += text.length; + this.trim(); + } + + /** Evict oldest entries until both the count and character budgets hold. */ + private trim(): void { + while ( + this.entries.length > this.capacity || + this.chars > MAX_BUFFERED_CHARS + ) { + const removed = this.entries.shift(); + if (removed === undefined) { + break; + } + this.chars -= removed.text.length; } } } diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index a3be8052ba..e8d376d14a 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -129,6 +129,7 @@ describe("BufferingLogger", () => { interface CapacityCase { name: string; capacity: number; + values: string[]; shrinkTo?: number; present: string[]; absent: string[]; @@ -138,28 +139,41 @@ describe("BufferingLogger", () => { { name: "evicts the oldest entry when capacity is exceeded", capacity: 2, + values: ["one", "two", "three"], present: ["two", "three"], absent: ["one"], }, { name: "buffers nothing when capacity is zero", capacity: 0, + values: ["one", "two", "three"], present: [], absent: ["one", "two", "three"], }, { name: "keeps the most recent entries when shrunk via setCapacity", capacity: 10, + values: ["one", "two", "three"], shrinkTo: 1, present: ["three"], absent: ["one", "two"], }, - ])("$name", ({ capacity, shrinkTo, present, absent }) => { + { + name: "evicts oldest entries once the character budget is exceeded", + capacity: 100_000, + values: [ + `first ${"x".repeat(1_200_000)}`, + `second ${"x".repeat(1_200_000)}`, + ], + present: ["second "], + absent: ["first "], + }, + ])("$name", ({ capacity, values, shrinkTo, present, absent }) => { const { buffer, flush } = setup(INFO, capacity); - buffer.debug("one"); - buffer.debug("two"); - buffer.debug("three"); + for (const value of values) { + buffer.debug(value); + } if (shrinkTo !== undefined) { buffer.setCapacity(shrinkTo); } @@ -189,10 +203,9 @@ describe("BufferingLogger", () => { expect(entry).toBeDefined(); expect(entry?.message).toContain("2024-01-01T00:00:00.000Z"); expect(entry?.message).toContain("DEBUG first line"); - for (const line of entry?.message.split("\n") ?? []) { - expect(line.startsWith("[buffered] ")).toBe(true); - } - expect(entry?.args).toEqual([detail]); + // Args are formatted into the text at record time, not passed through. + expect(entry?.message).toContain("1006"); + expect(entry?.args).toEqual([]); }); it("clears after flush, no-ops when empty, and preserves entries flushed while Off", () => { From 6017d6bf3f744d9eff699c46e9ae009bd7b7854f Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:31:00 +0000 Subject: [PATCH 41/60] feat(logging): flush the connection log buffer into support bundles A bundle taken mid-outage had nothing, because an unreachable server retries forever without a terminal reason. Flush the buffer just before appending VS Code logs so the bundle carries the detail leading up to the failure, and reword the setting to cover both the terminal-failure and support-bundle triggers. Flushing after N failed reconnect attempts stays a follow-up: #1112. --- package.json | 2 +- src/commands.ts | 6 ++++++ test/unit/commands.supportBundle.test.ts | 9 +++++++-- 3 files changed, 14 insertions(+), 3 deletions(-) diff --git a/package.json b/package.json index b5cd12ab16..4298275660 100644 --- a/package.json +++ b/package.json @@ -216,7 +216,7 @@ "default": 250 }, "coder.connectionLogBuffer.size": { - "markdownDescription": "Maximum number of log entries below the Coder output channel's log level to keep in memory. When a connection fails, the extension writes them to the channel so a support bundle includes the detail leading up to the failure without debug logging enabled beforehand. Set to `0` to disable.", + "markdownDescription": "Maximum number of log entries below the Coder output channel's log level to keep in memory. When a connection fails terminally or you collect a support bundle, the extension writes them to the channel so the bundle includes the detail leading up to the failure without debug logging enabled beforehand. Set to `0` to disable.", "type": "number", "minimum": 0, "maximum": 10000, diff --git a/src/commands.ts b/src/commands.ts index 3ce889b52e..666e48bf6e 100644 --- a/src/commands.ts +++ b/src/commands.ts @@ -84,6 +84,7 @@ import type { MementoManager } from "./core/mementoManager"; import type { PathResolver } from "./core/pathResolver"; import type { SecretsManager, SessionAuth } from "./core/secretsManager"; import type { DeploymentManager } from "./deployment/deploymentManager"; +import type { ConnectionLogBuffer } from "./logging/logBuffer"; import type { Logger } from "./logging/logger"; import type { LoginCoordinator, LoginMethod } from "./login/loginCoordinator"; import type { TelemetryService } from "./telemetry/service"; @@ -168,6 +169,7 @@ export class Commands { private readonly authTelemetry: AuthTelemetry; private readonly diagnosticTelemetry: DiagnosticTelemetry; private readonly workspaceOpenTelemetry: WorkspaceOpenTelemetry; + private readonly connectionLogBuffer: ConnectionLogBuffer; // These will only be populated when actively connected to a workspace and are // used in commands. Because commands can be executed by the user, it is not @@ -193,6 +195,7 @@ export class Commands { this.telemetryService, ); this.logger = serviceContainer.getLogger(); + this.connectionLogBuffer = serviceContainer.getConnectionLogBuffer(); this.pathResolver = serviceContainer.getPathResolver(); this.mementoManager = serviceContainer.getMementoManager(); this.secretsManager = serviceContainer.getSecretsManager(); @@ -494,6 +497,9 @@ export class Commands { }); progress.report({ message: "Adding VS Code logs..." }); + // Flush buffered below-level connection logs so the bundle carries the + // detail leading up to a failure even without debug logging enabled. + this.connectionLogBuffer.flush("support_bundle"); await appendVsCodeLogs( outputUri.fsPath, { diff --git a/test/unit/commands.supportBundle.test.ts b/test/unit/commands.supportBundle.test.ts index d473b2f764..3a57fc645a 100644 --- a/test/unit/commands.supportBundle.test.ts +++ b/test/unit/commands.supportBundle.test.ts @@ -79,9 +79,11 @@ function setup(options: { cliVersion?: string } = {}) { vi.mocked(appendVsCodeLogs).mockResolvedValue(undefined); const logger = createMockLogger(); + const connectionLogBufferFlush = vi.fn(); const serviceContainer = { getTelemetryService: () => service, getLogger: () => logger, + getConnectionLogBuffer: () => ({ flush: connectionLogBufferFlush }), getPathResolver: () => ({ getGlobalConfigDir: () => "/cfg", getProxyLogPath: () => "/logs/proxy", @@ -111,7 +113,7 @@ function setup(options: { cliVersion?: string } = {}) { {} as DeploymentManager, ); - return { commands, client, logger, interaction }; + return { commands, client, logger, interaction, connectionLogBufferFlush }; } function setRemoteAuthority(value: string | undefined): void { @@ -136,10 +138,13 @@ function connectToWorkspace( describe("Commands.supportBundle", () => { it("collects the selected agent's bundle with remote log globs", async () => { - const { commands } = setup(); + const { commands, connectionLogBufferFlush } = setup(); await commands.supportBundle(agentItem("dev")); + // The buffered below-level connection logs are flushed into the bundle. + expect(connectionLogBufferFlush).toHaveBeenCalledWith("support_bundle"); + expect(cliExec.supportBundle).toHaveBeenCalledWith( expect.anything(), "owner/ws", From 91a446404b9240f0776821d7002c47adea293da4 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:31:51 +0000 Subject: [PATCH 42/60] fix(settings): guard the HTTP log-level reader against non-string values .toUpperCase() ran before the fallback, so a null or number in settings.json threw inside the axios interceptors and rejected every request. Return BASIC when the configured value is not a string. --- src/settings/logger.ts | 20 ++++++++++++-------- test/unit/settings/logger.test.ts | 7 +++++++ 2 files changed, 19 insertions(+), 8 deletions(-) diff --git a/src/settings/logger.ts b/src/settings/logger.ts index a7537af0c4..fef56318c8 100644 --- a/src/settings/logger.ts +++ b/src/settings/logger.ts @@ -33,14 +33,18 @@ export function readConnectionLogBufferSize( export function readHttpClientLogLevel( cfg: Pick, ): HttpClientLogLevel { - const value = cfg - .get( - HTTP_CLIENT_LOG_LEVEL_SETTING, - HttpClientLogLevel[HttpClientLogLevel.BASIC], - ) - .toUpperCase(); + const value = cfg.get( + HTTP_CLIENT_LOG_LEVEL_SETTING, + HttpClientLogLevel[HttpClientLogLevel.BASIC], + ); + // settings.json can hold a non-string (e.g. 2 or null) despite the schema; + // guard so the axios interceptors never throw on .toUpperCase(). + if (typeof value !== "string") { + return HttpClientLogLevel.BASIC; + } return ( - HttpClientLogLevel[value as keyof typeof HttpClientLogLevel] ?? - HttpClientLogLevel.BASIC + HttpClientLogLevel[ + value.toUpperCase() as keyof typeof HttpClientLogLevel + ] ?? HttpClientLogLevel.BASIC ); } diff --git a/test/unit/settings/logger.test.ts b/test/unit/settings/logger.test.ts index a0a6b484a2..0f7ccaef8c 100644 --- a/test/unit/settings/logger.test.ts +++ b/test/unit/settings/logger.test.ts @@ -62,4 +62,11 @@ describe("readHttpClientLogLevel", () => { HttpClientLogLevel.BASIC, ); }); + + it.each([2, null])( + "falls back to BASIC for a non-string value %p", + (value) => { + expect(readHttpClientLogLevel(cfg(value))).toBe(HttpClientLogLevel.BASIC); + }, + ); }); From d8c2176547336c51d8a5118db63bf4e6cf447c9e Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:33:39 +0000 Subject: [PATCH 43/60] refactor(core): funnel connection-failure flushes through ServiceContainer The extension and remote clients duplicated the same closure, and the ` ` key is what Support greps for. Expose a single onConnectionFailure arrow property on ServiceContainer and pass it from both CoderApi.create sites. --- src/core/container.ts | 9 +++++++++ src/extension.ts | 3 +-- src/remote/remote.ts | 5 +---- test/mocks/testHelpers.ts | 1 + 4 files changed, 12 insertions(+), 6 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index 9f7df9fc2a..ed5b8a0fd7 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -179,6 +179,15 @@ export class ServiceContainer implements vscode.Disposable { return this.logger; } + /** + * Flush the connection log buffer on a terminal socket failure. The + * ` ` key is what Support greps for, so both socket call + * sites share this one funnel. Arrow property so it can be passed by value. + */ + readonly onConnectionFailure = (reason: string, route: string): void => { + this.logger.flush(`${reason} ${route}`); + }; + getCliManager(): CliManager { return this.cliManager; } diff --git a/src/extension.ts b/src/extension.ts index 7abb66ae2f..8fe7630730 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -141,8 +141,7 @@ async function doActivate( deploymentSessionAuth?.token, output, telemetryService, - (reason, route) => - serviceContainer.getConnectionLogBuffer().flush(`${reason} ${route}`), + serviceContainer.onConnectionFailure, ); ctx.subscriptions.push(client); diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 2e441777cd..0e25606a40 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -280,10 +280,7 @@ export class Remote { token, this.logger, this.serviceContainer.getTelemetryService(), - (reason, route) => - this.serviceContainer - .getConnectionLogBuffer() - .flush(`${reason} ${route}`), + this.serviceContainer.onConnectionFailure, ); disposables.push(workspaceClient); diff --git a/test/mocks/testHelpers.ts b/test/mocks/testHelpers.ts index 3c194226b3..9817b5c4ab 100644 --- a/test/mocks/testHelpers.ts +++ b/test/mocks/testHelpers.ts @@ -646,6 +646,7 @@ export function createMockServiceContainer( getTelemetryService: () => telemetry, getLogger: () => logger, getConnectionLogBuffer: (): ConnectionLogBuffer => ({ flush: () => {} }), + onConnectionFailure: (_reason: string, _route: string) => {}, getSecretsManager: () => require("secretsManager", overrides.secretsManager), getMementoManager: () => From b4077b33e4b32185e8ceac91e9aab156450a9c0a Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:34:17 +0000 Subject: [PATCH 44/60] docs(websocket): clarify why a handshake 401 never flushes The exemption covers every 401, not only an OAuth-refreshable one, so say so in the code comment, CONTRIBUTING, and the test name: a 401 explains itself, and with OAuth a refresh reconnects the same socket. --- CONTRIBUTING.md | 4 +++- src/websocket/reconnectingWebSocket.ts | 4 ++-- test/unit/websocket/reconnectingWebSocket.test.ts | 2 +- 3 files changed, 6 insertions(+), 4 deletions(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 085c926c97..9d6a424d31 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -145,7 +145,9 @@ When a WebSocket fails terminally, a workspace fails to open, or you collect a support bundle, the extension replays the ring into the channel. Each replayed line carries a `[buffered]` marker with its original timestamp and level, so it lands on disk and in the bundle. Transient reconnects and intentional teardown -never flush. Nothing is recorded or flushed while the channel is at `Off`. +never flush, and neither does a handshake `401` (a 401 explains itself, and with +OAuth a refresh reconnects the same socket). Nothing is recorded or flushed +while the channel is at `Off`. The buffer size is set by `coder.connectionLogBuffer.size` (number of entries; `0` disables it) and lives in memory, so a hard kill or out-of-memory event diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index 5a4e021205..4cb36f97a5 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -543,8 +543,8 @@ export class ReconnectingWebSocket< `Unrecoverable HTTP error (${unrecoverableStatus}) during connection for ${this.#route}`, error, ); - // An expired token surfaces as 401, but OAuth refreshes and reconnects - // the same socket seconds later, so it is not a genuine outage to flush. + // A 401 explains itself, and with OAuth a refresh reconnects the same + // socket, so it never flushes. this.disconnectWithReason("unrecoverable_http", "error", { error, failure: unrecoverableStatus !== HttpStatusCode.UNAUTHORIZED, diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index df7fb297b3..7d841ba7c5 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -168,7 +168,7 @@ describe("ReconnectingWebSocket", () => { }, ); - it("does not flush on an unrecoverable 401 (token refresh reconnects the same socket)", async () => { + it("does not flush on an unrecoverable 401 (a 401 explains itself, and with OAuth a refresh reconnects the same socket)", async () => { const { ws, sockets, onConnectionFailure } = await createReconnectingWebSocket(); From cfda03dd7e9519f5fe7bf35b29e9d9953f1f8c21 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:35:05 +0000 Subject: [PATCH 45/60] test(logging): assert the buffer replay on the joined text Args are now formatted into each entry's text, so the [buffered] prefix really does land on every physical line. Drop the over-claim from the test name and assert on the joined replay text. --- test/unit/logging/logBuffer.test.ts | 18 +++++++++++------- 1 file changed, 11 insertions(+), 7 deletions(-) diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index e8d376d14a..72509be7ff 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -187,7 +187,7 @@ describe("BufferingLogger", () => { } }); - it("replays each entry with its record time, args, and a [buffered] prefix on every line", () => { + it("replays each entry with its record time and formatted args, prefixing every physical line", () => { const recordedAt = Date.parse("2024-01-01T00:00:00.000Z"); vi.spyOn(Date, "now").mockReturnValueOnce(recordedAt); const { buffer, calls, flush } = setup(INFO, 10); @@ -199,13 +199,17 @@ describe("BufferingLogger", () => { expect(lines[0]).toContain("connection failure (r)"); expect(lines[lines.length - 1]).toContain("end of buffered logs"); - const entry = calls.find((c) => c.message.includes("first line")); - expect(entry).toBeDefined(); - expect(entry?.message).toContain("2024-01-01T00:00:00.000Z"); - expect(entry?.message).toContain("DEBUG first line"); + const replay = calls.find((c) => c.message.includes("first line")); + expect(replay).toBeDefined(); + expect(replay?.message).toContain("2024-01-01T00:00:00.000Z"); + expect(replay?.message).toContain("DEBUG first line"); // Args are formatted into the text at record time, not passed through. - expect(entry?.message).toContain("1006"); - expect(entry?.args).toEqual([]); + expect(replay?.message).toContain("1006"); + expect(replay?.args).toEqual([]); + // Every physical line of the joined replay text carries the prefix. + for (const line of replay?.message.split("\n") ?? []) { + expect(line.startsWith("[buffered] ")).toBe(true); + } }); it("clears after flush, no-ops when empty, and preserves entries flushed while Off", () => { From 11eff875dc026aceb7f9172021589291512839a3 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:35:44 +0000 Subject: [PATCH 46/60] refactor(core): read the buffer size through one helper readConnectionLogBufferSize always returns a number, so the typeof guard on the config-change callback was dead. Hoist a readSize() helper, use it for the initial size and the watcher's getValue, and set the capacity straight from it on change. --- src/core/container.ts | 14 +++++--------- 1 file changed, 5 insertions(+), 9 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index ed5b8a0fd7..32064ff4b0 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -58,25 +58,21 @@ export class ServiceContainer implements vscode.Disposable { this.outputChannel = vscode.window.createOutputChannel("Coder", { log: true, }); + const readSize = () => + readConnectionLogBufferSize(vscode.workspace.getConfiguration()); this.logger = new BufferingLogger( prefixLogger(this.outputChannel, `[session ${shortId(sessionId)}]`), this.outputChannel, - readConnectionLogBufferSize(vscode.workspace.getConfiguration()), + readSize(), ); this.connectionLogBufferConfigSubscription = watchConfigurationChanges( [ { setting: CONNECTION_LOG_BUFFER_SIZE_SETTING, - getValue: () => - readConnectionLogBufferSize(vscode.workspace.getConfiguration()), + getValue: readSize, }, ], - (changes) => { - const size = changes.get(CONNECTION_LOG_BUFFER_SIZE_SETTING); - if (typeof size === "number") { - this.logger.setCapacity(size); - } - }, + () => this.logger.setCapacity(readSize()), ); this.pathResolver = new PathResolver( context.globalStorageUri.fsPath, From 8fb9373df8ed8ff0adc408513254ba0c0df0f16a Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:36:22 +0000 Subject: [PATCH 47/60] test(settings): fold the buffer-size cases into one table Combine the individual readConnectionLogBufferSize cases and the invalid- value table into a single it.each with { name, value, expected }. --- test/unit/settings/logger.test.ts | 83 ++++++++++++++++++++----------- 1 file changed, 54 insertions(+), 29 deletions(-) diff --git a/test/unit/settings/logger.test.ts b/test/unit/settings/logger.test.ts index 0f7ccaef8c..d1b20c7382 100644 --- a/test/unit/settings/logger.test.ts +++ b/test/unit/settings/logger.test.ts @@ -18,37 +18,62 @@ function cfg(value: unknown): Pick { } describe("readConnectionLogBufferSize", () => { - it("returns the configured value when in range", () => { - expect(readConnectionLogBufferSize(cfg(250))).toBe(250); - }); - - it("floors fractional values", () => { - expect(readConnectionLogBufferSize(cfg(250.9))).toBe(250); - }); - - it("treats zero as disabled", () => { - expect(readConnectionLogBufferSize(cfg(0))).toBe(0); - }); + interface Case { + name: string; + value: unknown; + expected: number; + } - it("clamps values above the maximum", () => { - expect(readConnectionLogBufferSize(cfg(1_000_000))).toBe( - MAX_CONNECTION_LOG_BUFFER_SIZE, - ); - }); - - it.each([-1, Infinity, Number.NaN, "2000", null, {}])( - "falls back to the default for invalid value %p", - (value) => { - expect(readConnectionLogBufferSize(cfg(value))).toBe( - DEFAULT_CONNECTION_LOG_BUFFER_SIZE, - ); + it.each([ + { + name: "returns the configured value when in range", + value: 250, + expected: 250, }, - ); - - it("uses the default when unset", () => { - expect(readConnectionLogBufferSize(cfg(undefined))).toBe( - DEFAULT_CONNECTION_LOG_BUFFER_SIZE, - ); + { name: "floors fractional values", value: 250.9, expected: 250 }, + { name: "treats zero as disabled", value: 0, expected: 0 }, + { + name: "clamps values above the maximum", + value: 1_000_000, + expected: MAX_CONNECTION_LOG_BUFFER_SIZE, + }, + { + name: "falls back to the default for a negative value", + value: -1, + expected: DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + }, + { + name: "falls back to the default for Infinity", + value: Infinity, + expected: DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + }, + { + name: "falls back to the default for NaN", + value: Number.NaN, + expected: DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + }, + { + name: "falls back to the default for a numeric string", + value: "2000", + expected: DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + }, + { + name: "falls back to the default for null", + value: null, + expected: DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + }, + { + name: "falls back to the default for an object", + value: {}, + expected: DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + }, + { + name: "uses the default when unset", + value: undefined, + expected: DEFAULT_CONNECTION_LOG_BUFFER_SIZE, + }, + ])("$name", ({ value, expected }) => { + expect(readConnectionLogBufferSize(cfg(value))).toBe(expected); }); }); From 6bfbb89fcabd40e42ad4d330b4f010aadd82eae4 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 19:38:56 +0000 Subject: [PATCH 48/60] test(websocket): fix the mock listener model and cover OneWayWebSocket createMockWebSocket kept one handler per event and ignored the handler on removal, so only the last of production's three close listeners survived; use a Set per event with identity removal and drop the unused fire helpers. Add a real OneWayWebSocket test that closes from a ws WebSocketServer with 1002 and asserts the callback receives the DOM CloseEvent code and reason. --- test/unit/api/coderApi.test.ts | 37 +++++++++-------- test/unit/websocket/oneWayWebSocket.test.ts | 44 +++++++++++++++++++++ 2 files changed, 65 insertions(+), 16 deletions(-) create mode 100644 test/unit/websocket/oneWayWebSocket.test.ts diff --git a/test/unit/api/coderApi.test.ts b/test/unit/api/coderApi.test.ts index f2981e0665..a4010c873b 100644 --- a/test/unit/api/coderApi.test.ts +++ b/test/unit/api/coderApi.test.ts @@ -1168,14 +1168,11 @@ const mockAdapterImpl = vi.hoisted( ); type MockWebSocket = Partial & { - fireOpen: () => void; fireClose: (event: { code: number; reason: string; wasClean?: boolean; }) => void; - fireError: (event: { error?: Error; message?: string }) => void; - fireMessage: (data: unknown) => void; }; interface MockWebSocketOptions { @@ -1188,25 +1185,30 @@ function createMockWebSocket( options: MockWebSocketOptions = {}, ): MockWebSocket { // OneWayWebSocket registers open/close/error via addEventListener and only - // message via on(), mirroring the DOM/ws split in production. - const domHandlers: Record void) | undefined> = {}; - const messageHandlers = new Set<(e: unknown) => void>(); + // message via on(), mirroring the DOM/ws split in production. A Set per event + // with identity removal matches how production adds and removes each listener. + const listeners: Record void>> = { + open: new Set(), + close: new Set(), + error: new Set(), + message: new Set(), + }; const mock: MockWebSocket = { url, on: vi.fn((event: string, handler: (e: unknown) => void) => { if (event === "message") { - messageHandlers.add(handler); + listeners.message.add(handler); } return mock as Ws; }), off: vi.fn((event: string, handler: (e: unknown) => void) => { if (event === "message") { - messageHandlers.delete(handler); + listeners.message.delete(handler); } return mock as Ws; }), addEventListener: vi.fn((event: string, handler: (e: unknown) => void) => { - domHandlers[event] = handler; + listeners[event]?.add(handler); if (event === "open" && !options.connectError) { setImmediate(() => handler(new Event("open"))); } @@ -1214,14 +1216,17 @@ function createMockWebSocket( setImmediate(() => handler(options.connectError)); } }), - removeEventListener: vi.fn((event: string) => { - domHandlers[event] = undefined; - }), + removeEventListener: vi.fn( + (event: string, handler: (e: unknown) => void) => { + listeners[event]?.delete(handler); + }, + ), close: vi.fn(), - fireOpen: () => domHandlers.open?.(new Event("open")), - fireClose: (event) => domHandlers.close?.(event), - fireError: (event) => domHandlers.error?.(event), - fireMessage: (data) => messageHandlers.forEach((handler) => handler(data)), + fireClose: (event) => { + for (const cb of listeners.close) { + cb(event); + } + }, }; return mock; } diff --git a/test/unit/websocket/oneWayWebSocket.test.ts b/test/unit/websocket/oneWayWebSocket.test.ts new file mode 100644 index 0000000000..ec784492e9 --- /dev/null +++ b/test/unit/websocket/oneWayWebSocket.test.ts @@ -0,0 +1,44 @@ +import { type AddressInfo } from "node:net"; +import { afterEach, beforeEach, describe, expect, it } from "vitest"; +import { WebSocketServer } from "ws"; + +import { OneWayWebSocket } from "@/websocket/oneWayWebSocket"; + +describe("OneWayWebSocket", () => { + let server: WebSocketServer; + let host: string; + + beforeEach(async () => { + server = new WebSocketServer({ port: 0 }); + await new Promise((resolve) => server.once("listening", resolve)); + const { port } = server.address() as AddressInfo; + host = `127.0.0.1:${port}`; + }); + + afterEach(async () => { + await new Promise((resolve) => server.close(() => resolve())); + }); + + it("delivers a DOM CloseEvent with code and reason to close listeners", async () => { + server.on("connection", (socket) => { + socket.close(1002, "protocol error"); + }); + + const ws = new OneWayWebSocket({ + location: { protocol: "http:", host }, + apiRoute: "/api/v2/test", + }); + + const event = await new Promise<{ code: number; reason: string }>( + (resolve) => { + ws.addEventListener("close", (e) => { + resolve({ code: e.code, reason: e.reason }); + }); + }, + ); + + expect(event.code).toBe(1002); + expect(event.reason).toBe("protocol error"); + ws.close(); + }); +}); From 06bfb69cc637e18d8c0e09ff801c57c0e3ab2f6c Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 21:03:18 +0000 Subject: [PATCH 49/60] test(commands): stub getConnectionLogBuffer in Commands mocks The support-bundle flush change made Commands call serviceContainer.getConnectionLogBuffer(), but the telemetry, netcheck, and updateWorkspace Commands mocks did not provide it, so their suites threw "getConnectionLogBuffer is not a function" in CI. --- test/unit/command/updateWorkspace.telemetry.test.ts | 1 + test/unit/commands.netcheck.test.ts | 1 + test/unit/commands.telemetry.test.ts | 1 + 3 files changed, 3 insertions(+) diff --git a/test/unit/command/updateWorkspace.telemetry.test.ts b/test/unit/command/updateWorkspace.telemetry.test.ts index a1776668c9..9747d86c65 100644 --- a/test/unit/command/updateWorkspace.telemetry.test.ts +++ b/test/unit/command/updateWorkspace.telemetry.test.ts @@ -30,6 +30,7 @@ function setup() { getDuplicateWorkspaceIpc: () => ({}), getSpeedtestPanelFactory: () => ({}), getNetcheckPanelFactory: () => ({}), + getConnectionLogBuffer: () => ({ flush: () => {} }), } as unknown as ServiceContainer; const commands = new Commands( container, diff --git a/test/unit/commands.netcheck.test.ts b/test/unit/commands.netcheck.test.ts index 9704f5da00..692d4172c7 100644 --- a/test/unit/commands.netcheck.test.ts +++ b/test/unit/commands.netcheck.test.ts @@ -39,6 +39,7 @@ function setup(options: { extensionBaseUrl?: string } = {}) { getDuplicateWorkspaceIpc: () => ({}), getSpeedtestPanelFactory: () => ({}), getNetcheckPanelFactory: () => ({}) as NetcheckPanelFactory, + getConnectionLogBuffer: () => ({ flush: () => {} }), } as unknown as ServiceContainer; const commands = new Commands( diff --git a/test/unit/commands.telemetry.test.ts b/test/unit/commands.telemetry.test.ts index ffb0d1c892..4af9514b28 100644 --- a/test/unit/commands.telemetry.test.ts +++ b/test/unit/commands.telemetry.test.ts @@ -120,6 +120,7 @@ function setup(options: SetupOptions = {}) { getDuplicateWorkspaceIpc: () => ({}) as DuplicateWorkspaceIpc, getSpeedtestPanelFactory: () => ({}) as SpeedtestPanelFactory, getNetcheckPanelFactory: () => ({}) as NetcheckPanelFactory, + getConnectionLogBuffer: () => ({ flush: () => {} }), } as ServiceContainer; const extensionClient = { From 6a574cbcde1704a6b13711f9a4fedcc2140cc351 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Tue, 15 Sep 2026 21:11:43 +0000 Subject: [PATCH 50/60] test(commands): type the telemetry mock's getConnectionLogBuffer The strict `as ServiceContainer` cast requires each property to match exactly, so annotate the getter's return as ConnectionLogBuffer to restore comparability and fix the TS2352 typecheck error. --- test/unit/commands.telemetry.test.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/test/unit/commands.telemetry.test.ts b/test/unit/commands.telemetry.test.ts index 4af9514b28..cd33132a5a 100644 --- a/test/unit/commands.telemetry.test.ts +++ b/test/unit/commands.telemetry.test.ts @@ -18,6 +18,7 @@ import type { PathResolver } from "@/core/pathResolver"; import type { SecretsManager, SessionAuth } from "@/core/secretsManager"; import type { DeploymentManager } from "@/deployment/deploymentManager"; import type { Deployment } from "@/deployment/types"; +import type { ConnectionLogBuffer } from "@/logging/logBuffer"; import type { LoginCoordinator, LoginResult } from "@/login/loginCoordinator"; import type { NetcheckPanelFactory } from "@/webviews/netcheck/netcheckPanelFactory"; import type { SpeedtestPanelFactory } from "@/webviews/speedtest/speedtestPanelFactory"; @@ -120,7 +121,7 @@ function setup(options: SetupOptions = {}) { getDuplicateWorkspaceIpc: () => ({}) as DuplicateWorkspaceIpc, getSpeedtestPanelFactory: () => ({}) as SpeedtestPanelFactory, getNetcheckPanelFactory: () => ({}) as NetcheckPanelFactory, - getConnectionLogBuffer: () => ({ flush: () => {} }), + getConnectionLogBuffer: (): ConnectionLogBuffer => ({ flush: () => {} }), } as ServiceContainer; const extensionClient = { From ff0f953b179d96fa2cd295a47d542ce4e19b0d97 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 16 Sep 2026 19:21:04 +0000 Subject: [PATCH 51/60] fix(commands): keep the buffer on a bundle flush and flush before the CLI A support bundle is a snapshot, so a missed entry should be recoverable by the next bundle or failure: flush("support_bundle") now retains the ring instead of clearing it. Move the flush above cliExec.supportBundle so the CLI's runtime gives LogOutputChannel time to write the lines to disk. Capture is still best-effort; the channel writes on its own schedule. --- src/commands.ts | 8 +++++--- src/logging/logBuffer.ts | 20 +++++++++++++------- test/unit/commands.supportBundle.test.ts | 11 +++++++++-- test/unit/logging/logBuffer.test.ts | 20 ++++++++++++++++++-- 4 files changed, 45 insertions(+), 14 deletions(-) diff --git a/src/commands.ts b/src/commands.ts index 666e48bf6e..9a337f7eb3 100644 --- a/src/commands.ts +++ b/src/commands.ts @@ -489,6 +489,11 @@ export class Commands { : []; progress.report({ message: "Collecting diagnostics..." }); + // Flush buffered below-level connection logs before the CLI runs so + // the channel has time to write them to disk; retain the ring so a + // later failure flush still replays them. Best-effort: the channel + // writes on its own schedule, so the tail may not land in this bundle. + this.connectionLogBuffer.flush("support_bundle", { retain: true }); await cliExec.supportBundle(env, workspaceId, { outputPath: outputUri.fsPath, agentName, @@ -497,9 +502,6 @@ export class Commands { }); progress.report({ message: "Adding VS Code logs..." }); - // Flush buffered below-level connection logs so the bundle carries the - // detail leading up to a failure even without debug logging enabled. - this.connectionLogBuffer.flush("support_bundle"); await appendVsCodeLogs( outputUri.fsPath, { diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 0aa0240631..61346ef2a8 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -31,7 +31,7 @@ const REPLAY_CHUNK = 100; /** Replays buffered below-level log entries on a connection failure. */ export interface ConnectionLogBuffer { - flush(reason: string): void; + flush(reason: string, options?: { readonly retain?: boolean }): void; } interface LogEntry { @@ -72,11 +72,15 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { } /** - * Replay buffered entries into the sink and clear them. No-op when empty. - * Clearing the buffer means a later flush only replays entries accumulated - * since this one, so consecutive failures never duplicate entries. + * Replay buffered entries into the sink. No-op when empty. Clears the ring by + * default, so consecutive failures never replay the same entries twice; pass + * `retain` for a snapshot flush (a support bundle) that must not disturb a + * later failure flush. */ - public flush(reason: string): void { + public flush( + reason: string, + options: { readonly retain?: boolean } = {}, + ): void { // The channel writes nothing at Off. Keep the entries for the next flush; // nothing new is recorded while Off. if (this.channel.logLevel === 0) { @@ -86,8 +90,10 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { return; } const entries = this.entries; - this.entries = []; - this.chars = 0; + if (!options.retain) { + this.entries = []; + this.chars = 0; + } const sink = this.replaySink(); this.inner[sink]( diff --git a/test/unit/commands.supportBundle.test.ts b/test/unit/commands.supportBundle.test.ts index 3a57fc645a..4f5c3d776e 100644 --- a/test/unit/commands.supportBundle.test.ts +++ b/test/unit/commands.supportBundle.test.ts @@ -142,8 +142,15 @@ describe("Commands.supportBundle", () => { await commands.supportBundle(agentItem("dev")); - // The buffered below-level connection logs are flushed into the bundle. - expect(connectionLogBufferFlush).toHaveBeenCalledWith("support_bundle"); + // The buffered below-level connection logs are replayed for the bundle, + // keeping the ring so a later failure flush still has them, and before the + // CLI runs so the channel has time to write them to disk. + expect(connectionLogBufferFlush).toHaveBeenCalledWith("support_bundle", { + retain: true, + }); + expect(connectionLogBufferFlush.mock.invocationCallOrder[0]).toBeLessThan( + vi.mocked(cliExec.supportBundle).mock.invocationCallOrder[0], + ); expect(cliExec.supportBundle).toHaveBeenCalledWith( expect.anything(), diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 72509be7ff..7484faa9e9 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -36,9 +36,12 @@ function setup(level: number, capacity: number) { const channel = { logLevel: level }; const buffer = new BufferingLogger(logger, channel, capacity); // Ignore the pass-through calls, then return only what the flush replayed. - const flush = (reason = "r"): string[] => { + const flush = ( + reason = "r", + options?: { readonly retain?: boolean }, + ): string[] => { calls.length = 0; - buffer.flush(reason); + buffer.flush(reason, options); return calls.map((c) => c.message); }; return { buffer, calls, channel, flush }; @@ -243,4 +246,17 @@ describe("BufferingLogger", () => { flush("back").some((l) => l.includes("buffered before going off")), ).toBe(true); }); + + it("retains the ring on a snapshot flush so a later flush replays it again", () => { + const { buffer, flush } = setup(INFO, 10); + + buffer.debug("snapshot me"); + // A retained flush replays the entry but keeps it buffered. + expect( + flush("bundle", { retain: true }).some((l) => l.includes("snapshot me")), + ).toBe(true); + // A following failure flush still replays the retained entry, then clears it. + expect(flush("failure").some((l) => l.includes("snapshot me"))).toBe(true); + expect(flush("again")).toHaveLength(0); + }); }); From a3482a5d0dc1da81cd4658b6a7a941a250c18990 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 16 Sep 2026 19:22:49 +0000 Subject: [PATCH 52/60] docs(logging): correct buffer wording, reason label, and changelog - Flush header reads "replaying N buffered entries (reason)"; the old "connection failure (reason)" was wrong for a support_bundle or a closeRemote() cancel. - Relabel all four closeRemote() callers remote_closed; two of them are cancels, not workspace_open_failed. - CONTRIBUTING: only the first physical line of an entry carries the timestamp and level; continuation lines carry the bare marker. Describe bundle capture as best-effort. - package.json: describe bundle capture as best-effort. - Drop the replaySink comment's "whatever the user's log level" claim; flush returns early at Off. - Add an Unreleased changelog entry for the setting and normal-close reconnect. --- CHANGELOG.md | 15 +++++++++++++++ CONTRIBUTING.md | 14 ++++++++------ package.json | 2 +- src/logging/logBuffer.ts | 4 ++-- src/remote/remote.ts | 4 +--- test/unit/logging/logBuffer.test.ts | 3 ++- 6 files changed, 29 insertions(+), 13 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 6dda93f906..151f27d112 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,21 @@ from published versions since it shows up in the VS Code extension changelog tab and is confusing to users. Add it back between releases if needed. --> +## Unreleased + +### Added + +- Add `coder.connectionLogBuffer.size` to keep recent below-level Coder output + channel entries in memory and replay them into the channel when a connection + fails terminally or you collect a support bundle, so Support can diagnose + connection failures without asking you to reproduce with debug logging on. Set + to `0` to disable. + +### Changed + +- Reconnect after server-initiated normal WebSocket closes (`1000`/`1001`) + instead of parking the socket. + ## [v1.16.3](https://github.com/coder/vscode-coder/releases/tag/v1.16.3) 2026-09-14 ### Changed diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 9d6a424d31..b443874eef 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -142,12 +142,14 @@ wraps the channel and keeps a bounded, in-memory ring of the entries that sit **below** the current level, which the channel would otherwise drop. When a WebSocket fails terminally, a workspace fails to open, or you collect a -support bundle, the extension replays the ring into the channel. Each replayed -line carries a `[buffered]` marker with its original timestamp and level, so it -lands on disk and in the bundle. Transient reconnects and intentional teardown -never flush, and neither does a handshake `401` (a 401 explains itself, and with -OAuth a refresh reconnects the same socket). Nothing is recorded or flushed -while the channel is at `Off`. +support bundle, the extension replays the ring into the channel. The first +physical line of each replayed entry carries a `[buffered]` marker with its +original timestamp and level, and any continuation lines carry the bare marker. +Capture is best-effort: the channel writes on its own schedule, so a bundle may +miss the most recent lines, but a later failure flush still replays them. +Transient reconnects and intentional teardown never flush, and neither does a +handshake `401` (a 401 explains itself, and with OAuth a refresh reconnects the +same socket). Nothing is recorded or flushed while the channel is at `Off`. The buffer size is set by `coder.connectionLogBuffer.size` (number of entries; `0` disables it) and lives in memory, so a hard kill or out-of-memory event diff --git a/package.json b/package.json index 4298275660..5e6b4c890e 100644 --- a/package.json +++ b/package.json @@ -216,7 +216,7 @@ "default": 250 }, "coder.connectionLogBuffer.size": { - "markdownDescription": "Maximum number of log entries below the Coder output channel's log level to keep in memory. When a connection fails terminally or you collect a support bundle, the extension writes them to the channel so the bundle includes the detail leading up to the failure without debug logging enabled beforehand. Set to `0` to disable.", + "markdownDescription": "Maximum number of log entries below the Coder output channel's log level to keep in memory. When a connection fails terminally or you collect a support bundle, the extension replays them into the channel so a bundle can carry the detail leading up to the failure without debug logging enabled beforehand. Capture is best-effort, since the channel writes on its own schedule. Set to `0` to disable.", "type": "number", "minimum": 0, "maximum": 10000, diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index 61346ef2a8..b7c3ec9c55 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -97,7 +97,7 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { const sink = this.replaySink(); this.inner[sink]( - `[buffered] connection failure (${reason}): replaying ${entries.length} buffered entries`, + `[buffered] replaying ${entries.length} buffered entries (${reason})`, ); const lines = entries.map((entry) => `[buffered] ${new Date(entry.atMs).toISOString()} ${entry.level.toUpperCase()} ${entry.text}`.replaceAll( @@ -121,7 +121,7 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { /** * The least-verbose sink method that is still written at the current level, - * so a flush is captured whatever the user's log level. + * so replayed entries are persisted rather than dropped again. */ private replaySink(): ReplaySink { const level = this.channel.logLevel; diff --git a/src/remote/remote.ts b/src/remote/remote.ts index 0e25606a40..ca7d96157f 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -1094,9 +1094,7 @@ export class Remote { // closeRemote ends the current remote session. public async closeRemote() { - this.serviceContainer - .getConnectionLogBuffer() - .flush("workspace_open_failed"); + this.serviceContainer.getConnectionLogBuffer().flush("remote_closed"); await vscode.commands.executeCommand("workbench.action.remote.close"); } diff --git a/test/unit/logging/logBuffer.test.ts b/test/unit/logging/logBuffer.test.ts index 7484faa9e9..323fc2e8a0 100644 --- a/test/unit/logging/logBuffer.test.ts +++ b/test/unit/logging/logBuffer.test.ts @@ -199,7 +199,8 @@ describe("BufferingLogger", () => { buffer.debug("first line\nsecond line", detail); const lines = flush(); - expect(lines[0]).toContain("connection failure (r)"); + expect(lines[0]).toContain("replaying"); + expect(lines[0]).toContain("(r)"); expect(lines[lines.length - 1]).toContain("end of buffered logs"); const replay = calls.find((c) => c.message.includes("first line")); From e53aad9c84479433aee1562c18d2393b90cb92b2 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 16 Sep 2026 19:23:51 +0000 Subject: [PATCH 53/60] refactor(instrumentation): drop the now-unreachable normal_close reason Reconnecting after server-initiated normal closes made normal_close unemittable, but it stayed in ConnectionStateReason and ConnectionDropCause and in the EVENTS.md tables, so anyone filtering on it got a silent zero rather than a signal the behavior changed. Remove it from both unions and both tables, and give the double-emit test an emittable reason. --- src/instrumentation/EVENTS.md | 12 ++++++------ src/instrumentation/websocket.ts | 2 -- test/unit/instrumentation/websocket.test.ts | 2 +- 3 files changed, 7 insertions(+), 9 deletions(-) diff --git a/src/instrumentation/EVENTS.md b/src/instrumentation/EVENTS.md index f42db9b421..9c5c5f42e5 100644 --- a/src/instrumentation/EVENTS.md +++ b/src/instrumentation/EVENTS.md @@ -428,7 +428,7 @@ Emitted by `WebSocketTelemetry`. These events share one value set, **ConnectionStateReason**: `initial_connect`, `manual_reconnect`, `certificate_refresh`, `scheduled_reconnect`, `open`, `disconnect`, `dispose`, `unrecoverable_close`, `unrecoverable_http`, -`certificate_error`, `connection_error`, `normal_close`, `unexpected_close`. +`certificate_error`, `connection_error`, `unexpected_close`. ### Logs @@ -451,11 +451,11 @@ These events share one value set, **ConnectionStateReason**: `initial_connect`, Emitted as an error log (with the `error` block) when a socket error caused the drop. -| Attribute | Values | -| -------------------------------------- | --------------------------------------------------------------------------------------------------------------- | -| `cause` | `manual_disconnect`, `replaced`, `unrecoverable_close`, `normal_close`, `unexpected_close`, `disposed`, `error` | -| `close_code` | WebSocket close code (when known) | -| `connection_duration_ms` (measurement) | time the connection was open | +| Attribute | Values | +| -------------------------------------- | ----------------------------------------------------------------------------------------------- | +| `cause` | `manual_disconnect`, `replaced`, `unrecoverable_close`, `unexpected_close`, `disposed`, `error` | +| `close_code` | WebSocket close code (when known) | +| `connection_duration_ms` (measurement) | time the connection was open | #### `connection.reconnect_resolved` diff --git a/src/instrumentation/websocket.ts b/src/instrumentation/websocket.ts index 4fcd45d062..98c54bab6f 100644 --- a/src/instrumentation/websocket.ts +++ b/src/instrumentation/websocket.ts @@ -16,14 +16,12 @@ export type ConnectionStateReason = | "unrecoverable_http" | "certificate_error" | "connection_error" - | "normal_close" | "unexpected_close"; export type ConnectionDropCause = | "manual_disconnect" | "replaced" | "unrecoverable_close" - | "normal_close" | "unexpected_close" | "disposed" | "error"; diff --git a/test/unit/instrumentation/websocket.test.ts b/test/unit/instrumentation/websocket.test.ts index a44d172013..c461cc4f70 100644 --- a/test/unit/instrumentation/websocket.test.ts +++ b/test/unit/instrumentation/websocket.test.ts @@ -104,7 +104,7 @@ describe("WebSocketTelemetry", () => { const { ws, sink } = setup(); ws.opened("/api/test"); - ws.dropped("normal_close"); + ws.dropped("unexpected_close"); ws.dropped("error"); expect(sink.eventsNamed("connection.dropped")).toHaveLength(1); From 1de6ab23f86435c931d6bc97eede39fcfc1e8d97 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 16 Sep 2026 19:25:14 +0000 Subject: [PATCH 54/60] refactor(websocket): collapse the OneWayWebSocket event switches addEventListener and removeEventListener each spent a five-case switch on non-message events that all do the same cast and call. The per-event overloads force the cast either way, so one cast covers open/close/error. --- src/websocket/oneWayWebSocket.ts | 57 ++++++-------------------------- 1 file changed, 10 insertions(+), 47 deletions(-) diff --git a/src/websocket/oneWayWebSocket.ts b/src/websocket/oneWayWebSocket.ts index af43fc37ca..0772d8f84f 100644 --- a/src/websocket/oneWayWebSocket.ts +++ b/src/websocket/oneWayWebSocket.ts @@ -85,30 +85,12 @@ export class OneWayWebSocket< // `ws` only exposes `.code`/`.reason` on the DOM-style CloseEvent from // addEventListener; the `on()` emitter passes them positionally, which - // leaves `event.code` undefined for consumers. - switch (event) { - case "open": - this.#socket.addEventListener( - "open", - callback as EventHandler, - ); - break; - case "close": - this.#socket.addEventListener( - "close", - callback as EventHandler, - ); - break; - case "error": - this.#socket.addEventListener( - "error", - callback as EventHandler, - ); - break; - case "message": - // Handled above via the early return. - break; - } + // leaves `event.code` undefined for consumers. The per-event overloads + // force a cast for any of these, so one cast covers all three. + this.#socket.addEventListener( + event as "open", + callback as EventHandler, + ); } removeEventListener( @@ -126,29 +108,10 @@ export class OneWayWebSocket< return; } - switch (event) { - case "open": - this.#socket.removeEventListener( - "open", - callback as EventHandler, - ); - break; - case "close": - this.#socket.removeEventListener( - "close", - callback as EventHandler, - ); - break; - case "error": - this.#socket.removeEventListener( - "error", - callback as EventHandler, - ); - break; - case "message": - // Handled above via the early return. - break; - } + this.#socket.removeEventListener( + event as "open", + callback as EventHandler, + ); } close(code?: number, reason?: string): void { From 270ff3bfd2b7d86e68356ca1ba9716a6903c5e3a Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 16 Sep 2026 19:26:49 +0000 Subject: [PATCH 55/60] test(websocket): pin handshakeStatus against real ws and EventSource handshakeStatus parses two libraries' internal error text, and neither is a contract; the existing tests hand-build the strings, so a reword on a bump would pass here and break in production. Drive a real ws client against a server answering 404 on the upgrade and a real EventSource against one answering 403, so a reword fails in CI instead. Reading the status from the libraries' public event APIs is tracked in #1118. --- test/unit/websocket/utils.test.ts | 55 +++++++++++++++++++++++++++++++ 1 file changed, 55 insertions(+) create mode 100644 test/unit/websocket/utils.test.ts diff --git a/test/unit/websocket/utils.test.ts b/test/unit/websocket/utils.test.ts new file mode 100644 index 0000000000..61d4cd1d4d --- /dev/null +++ b/test/unit/websocket/utils.test.ts @@ -0,0 +1,55 @@ +import { EventSource } from "eventsource"; +import http from "node:http"; +import { type AddressInfo } from "node:net"; +import { afterEach, describe, expect, it } from "vitest"; +import { WebSocket } from "ws"; + +import { handshakeStatus } from "@/websocket/utils"; + +// `handshakeStatus` parses two libraries' internal error text, and neither is a +// contract. Drive real clients against a rejecting server so a library reword +// fails here instead of silently turning every unrecoverable status into a +// retry-forever connection_error. +describe("handshakeStatus", () => { + let server: http.Server; + + const listen = (statusCode: number): Promise => { + server = http.createServer((_req, res) => { + res.statusCode = statusCode; + res.end(); + }); + return new Promise((resolve) => { + server.listen(0, "127.0.0.1", () => { + const { port } = server.address() as AddressInfo; + resolve(`127.0.0.1:${port}`); + }); + }); + }; + + afterEach(async () => { + await new Promise((resolve) => server.close(() => resolve())); + }); + + it("parses the status from a ws upgrade rejection", async () => { + const host = await listen(404); + const ws = new WebSocket(`ws://${host}`); + + const error = await new Promise((resolve) => { + ws.on("error", resolve); + }); + + expect(handshakeStatus(error)).toBe(404); + }); + + it("parses the status from an EventSource handshake rejection", async () => { + const host = await listen(403); + const source = new EventSource(`http://${host}`); + + const error = await new Promise((resolve) => { + source.onerror = (event) => resolve(event); + }); + source.close(); + + expect(handshakeStatus(error)).toBe(403); + }); +}); From 5b22f6399b629043b608419ad13191677e5a76ff Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 16 Sep 2026 19:30:04 +0000 Subject: [PATCH 56/60] refactor(logging): move the connection-failure funnel onto the buffer The container was otherwise pure getters; the onConnectionFailure funnel is behavior. Move the ` ` arrow onto BufferingLogger and add it to ConnectionLogBuffer, so the grep format sits next to the code that writes the line. Call sites read getConnectionLogBuffer().onConnectionFailure. Default the socket's onConnectionFailure option to a noop, so it lives in #options and drops the #onConnectionFailure field, the optional-call at the terminated funnel, and one member of the Required>. --- src/core/container.ts | 9 --------- src/extension.ts | 2 +- src/logging/logBuffer.ts | 13 +++++++++++++ src/remote/remote.ts | 2 +- src/websocket/reconnectingWebSocket.ts | 17 +++++++---------- test/mocks/testHelpers.ts | 6 ++++-- test/unit/commands.telemetry.test.ts | 5 ++++- 7 files changed, 30 insertions(+), 24 deletions(-) diff --git a/src/core/container.ts b/src/core/container.ts index 32064ff4b0..a39e26503b 100644 --- a/src/core/container.ts +++ b/src/core/container.ts @@ -175,15 +175,6 @@ export class ServiceContainer implements vscode.Disposable { return this.logger; } - /** - * Flush the connection log buffer on a terminal socket failure. The - * ` ` key is what Support greps for, so both socket call - * sites share this one funnel. Arrow property so it can be passed by value. - */ - readonly onConnectionFailure = (reason: string, route: string): void => { - this.logger.flush(`${reason} ${route}`); - }; - getCliManager(): CliManager { return this.cliManager; } diff --git a/src/extension.ts b/src/extension.ts index 8fe7630730..8feb074615 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -141,7 +141,7 @@ async function doActivate( deploymentSessionAuth?.token, output, telemetryService, - serviceContainer.onConnectionFailure, + serviceContainer.getConnectionLogBuffer().onConnectionFailure, ); ctx.subscriptions.push(client); diff --git a/src/logging/logBuffer.ts b/src/logging/logBuffer.ts index b7c3ec9c55..31e3679641 100644 --- a/src/logging/logBuffer.ts +++ b/src/logging/logBuffer.ts @@ -32,6 +32,7 @@ const REPLAY_CHUNK = 100; /** Replays buffered below-level log entries on a connection failure. */ export interface ConnectionLogBuffer { flush(reason: string, options?: { readonly retain?: boolean }): void; + readonly onConnectionFailure: (reason: string, route: string) => void; } interface LogEntry { @@ -61,6 +62,18 @@ export class BufferingLogger implements Logger, ConnectionLogBuffer { public readonly warn = this.wrap("warn"); public readonly error = this.wrap("error"); + /** + * Flush the buffer on a terminal socket failure, keyed by the + * ` ` string Support greps for. Arrow property so it can be + * passed by value as the socket's failure callback. + */ + public readonly onConnectionFailure = ( + reason: string, + route: string, + ): void => { + this.flush(`${reason} ${route}`); + }; + public show(): void { this.inner.show(); } diff --git a/src/remote/remote.ts b/src/remote/remote.ts index ca7d96157f..9c18dad9a9 100644 --- a/src/remote/remote.ts +++ b/src/remote/remote.ts @@ -280,7 +280,7 @@ export class Remote { token, this.logger, this.serviceContainer.getTelemetryService(), - this.serviceContainer.onConnectionFailure, + this.serviceContainer.getConnectionLogBuffer().onConnectionFailure, ); disposables.push(workspaceClient); diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index 4cb36f97a5..d67225283a 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -111,6 +111,9 @@ function reduceState( export type SocketFactory = () => Promise>; +/** Default failure callback for callers that do not observe connection failures. */ +const NOOP_CONNECTION_FAILURE = (): void => undefined; + export interface ReconnectingWebSocketOptions { initialBackoffMs?: number; maxBackoffMs?: number; @@ -131,15 +134,8 @@ export class ReconnectingWebSocket< readonly #logger: Logger; readonly #telemetry: WebSocketTelemetry; readonly #options: Required< - Omit< - ReconnectingWebSocketOptions, - "telemetry" | "onConnectionFailure" | "route" - > + Omit >; - readonly #onConnectionFailure?: ( - reason: ConnectionStateReason, - route: string, - ) => void; readonly #eventHandlers: { [K in WebSocketEventType]: Set>; } = { @@ -192,8 +188,9 @@ export class ReconnectingWebSocket< maxBackoffMs: options.maxBackoffMs ?? 30000, jitterFactor: options.jitterFactor ?? 0.1, onCertificateRefreshNeeded: options.onCertificateRefreshNeeded, + onConnectionFailure: + options.onConnectionFailure ?? NOOP_CONNECTION_FAILURE, }; - this.#onConnectionFailure = options.onConnectionFailure; this.#lastRoute = options.route; this.#backoffMs = this.#options.initialBackoffMs; this.#onDispose = onDispose; @@ -316,7 +313,7 @@ export class ReconnectingWebSocket< }); this.clearCurrentSocket(options.code, options.closeReason); if (options.failure) { - this.#onConnectionFailure?.(reason, this.#route); + this.#options.onConnectionFailure(reason, this.#route); } } diff --git a/test/mocks/testHelpers.ts b/test/mocks/testHelpers.ts index 9817b5c4ab..95e8d17d4c 100644 --- a/test/mocks/testHelpers.ts +++ b/test/mocks/testHelpers.ts @@ -645,8 +645,10 @@ export function createMockServiceContainer( return { getTelemetryService: () => telemetry, getLogger: () => logger, - getConnectionLogBuffer: (): ConnectionLogBuffer => ({ flush: () => {} }), - onConnectionFailure: (_reason: string, _route: string) => {}, + getConnectionLogBuffer: (): ConnectionLogBuffer => ({ + flush: () => {}, + onConnectionFailure: () => {}, + }), getSecretsManager: () => require("secretsManager", overrides.secretsManager), getMementoManager: () => diff --git a/test/unit/commands.telemetry.test.ts b/test/unit/commands.telemetry.test.ts index cd33132a5a..2e1c67c396 100644 --- a/test/unit/commands.telemetry.test.ts +++ b/test/unit/commands.telemetry.test.ts @@ -121,7 +121,10 @@ function setup(options: SetupOptions = {}) { getDuplicateWorkspaceIpc: () => ({}) as DuplicateWorkspaceIpc, getSpeedtestPanelFactory: () => ({}) as SpeedtestPanelFactory, getNetcheckPanelFactory: () => ({}) as NetcheckPanelFactory, - getConnectionLogBuffer: (): ConnectionLogBuffer => ({ flush: () => {} }), + getConnectionLogBuffer: (): ConnectionLogBuffer => ({ + flush: () => {}, + onConnectionFailure: () => {}, + }), } as ServiceContainer; const extensionClient = { From a108b82465fc48400488da423dbfec067a47828c Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 16 Sep 2026 19:31:58 +0000 Subject: [PATCH 57/60] refactor(api): hoist apiRoute per caller and tidy log-level and route All three watch callers passed the route twice, and two duplicated a template literal, so the createReconnectingSocket argument and the socket init could drift. Hoist a single apiRoute per caller and pass it by shorthand into the init. Restore getLogLevel's explicit HttpClientLogLevel return type, and expand the #lastRoute comment: it is not simply the seeded route, since the live URL diverges after an SSE fallback and after a followRedirects redirect. --- src/api/coderApi.ts | 60 +++++++++++++------------- src/websocket/reconnectingWebSocket.ts | 5 ++- 2 files changed, 34 insertions(+), 31 deletions(-) diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index eb2ad332fa..d47888517b 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -25,7 +25,10 @@ import { logResponse, } from "../logging/httpLogger"; import { HttpRequestsTelemetry } from "../logging/httpRequestsTelemetry"; -import { type RequestConfigWithMeta } from "../logging/types"; +import { + type RequestConfigWithMeta, + type HttpClientLogLevel, +} from "../logging/types"; import { sizeOf } from "../logging/utils"; import { AuthConfigTracker } from "../settings/authConfig"; import { getHeaderCommand } from "../settings/headers"; @@ -291,30 +294,28 @@ export class CoderApi extends Api implements vscode.Disposable { watchTargets: string[], options?: ClientOptions, ) => { - return this.createReconnectingSocket( - "/api/v2/notifications/inbox/watch", - () => - this.createOneWayWebSocket({ - apiRoute: "/api/v2/notifications/inbox/watch", - searchParams: { - format: "plaintext", - templates: watchTemplates.join(","), - targets: watchTargets.join(","), - }, - options, - }), + const apiRoute = "/api/v2/notifications/inbox/watch"; + return this.createReconnectingSocket(apiRoute, () => + this.createOneWayWebSocket({ + apiRoute, + searchParams: { + format: "plaintext", + templates: watchTemplates.join(","), + targets: watchTargets.join(","), + }, + options, + }), ); }; watchWorkspace = async (workspace: Workspace, options?: ClientOptions) => { - return this.createReconnectingSocket( - `/api/v2/workspaces/${workspace.id}/watch-ws`, - () => - this.createStreamWithSseFallback({ - apiRoute: `/api/v2/workspaces/${workspace.id}/watch-ws`, - fallbackApiRoute: `/api/v2/workspaces/${workspace.id}/watch`, - options, - }), + const apiRoute = `/api/v2/workspaces/${workspace.id}/watch-ws`; + return this.createReconnectingSocket(apiRoute, () => + this.createStreamWithSseFallback({ + apiRoute, + fallbackApiRoute: `/api/v2/workspaces/${workspace.id}/watch`, + options, + }), ); }; @@ -322,14 +323,13 @@ export class CoderApi extends Api implements vscode.Disposable { agentId: WorkspaceAgent["id"], options?: ClientOptions, ) => { - return this.createReconnectingSocket( - `/api/v2/workspaceagents/${agentId}/watch-metadata-ws`, - () => - this.createStreamWithSseFallback({ - apiRoute: `/api/v2/workspaceagents/${agentId}/watch-metadata-ws`, - fallbackApiRoute: `/api/v2/workspaceagents/${agentId}/watch-metadata`, - options, - }), + const apiRoute = `/api/v2/workspaceagents/${agentId}/watch-metadata-ws`; + return this.createReconnectingSocket(apiRoute, () => + this.createStreamWithSseFallback({ + apiRoute, + fallbackApiRoute: `/api/v2/workspaceagents/${agentId}/watch-metadata`, + options, + }), ); }; @@ -830,6 +830,6 @@ function getSize(headers: AxiosHeaders, data: unknown): number | undefined { return sizeOf(data); } -function getLogLevel() { +function getLogLevel(): HttpClientLogLevel { return readHttpClientLogLevel(vscode.workspace.getConfiguration()); } diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index d67225283a..f67a16d13e 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -146,7 +146,10 @@ export class ReconnectingWebSocket< }; #currentSocket: UnidirectionalStream | null = null; - #lastRoute: string; // Cached route for logging when socket is closed + // Route to log while no socket is connected. Kept because the live URL + // diverges from the seeded route after an SSE fallback and after a redirect + // (followRedirects), so it is not simply the seeded value. + #lastRoute: string; #backoffMs: number; #reconnectTimeoutId: NodeJS.Timeout | null = null; #state: ConnectionState = ConnectionState.IDLE; From 37d76b03457a63b8fa15f5f797578702ee83a678 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Thu, 17 Sep 2026 10:59:38 -0700 Subject: [PATCH 58/60] docs: explain callback EventHandler cast wrt TS' lack of support for correlated unions Co-authored-by: Ehab Younes --- src/websocket/oneWayWebSocket.ts | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/src/websocket/oneWayWebSocket.ts b/src/websocket/oneWayWebSocket.ts index 0772d8f84f..a08b24f046 100644 --- a/src/websocket/oneWayWebSocket.ts +++ b/src/websocket/oneWayWebSocket.ts @@ -85,8 +85,9 @@ export class OneWayWebSocket< // `ws` only exposes `.code`/`.reason` on the DOM-style CloseEvent from // addEventListener; the `on()` emitter passes them positionally, which - // leaves `event.code` undefined for consumers. The per-event overloads - // force a cast for any of these, so one cast covers all three. + // leaves `event.code` undefined for consumers. TypeScript cannot correlate + // `event` with `callback` across two parameters, so a cast is needed either + // way, and `ws` dispatches on the event name, so one cast covers all three. this.#socket.addEventListener( event as "open", callback as EventHandler, From 23e8555137a09243733e6ae73ae34a91b6d0758f Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Thu, 17 Sep 2026 11:02:20 -0700 Subject: [PATCH 59/60] docs: remove mention of socket parking from changelog Co-authored-by: Ehab Younes --- CHANGELOG.md | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 151f27d112..b1c4b35055 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -15,10 +15,12 @@ connection failures without asking you to reproduce with debug logging on. Set to `0` to disable. -### Changed +### Fixed -- Reconnect after server-initiated normal WebSocket closes (`1000`/`1001`) - instead of parking the socket. +- Stop retrying after an unrecoverable WebSocket close (`1002`/`1003`) and + replay the buffered connection logs instead. Close codes never reached the + reconnect logic, so these closes retried forever. Server-initiated normal + closes (`1000`/`1001`) keep reconnecting. ## [v1.16.3](https://github.com/coder/vscode-coder/releases/tag/v1.16.3) 2026-09-14 From a8ca24a0c5226ff5489b6e8f4336469f08524af9 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Thu, 17 Sep 2026 11:05:26 -0700 Subject: [PATCH 60/60] docs: expand `closeRemote` description to include canceled workspace opens Co-authored-by: Ehab Younes --- CONTRIBUTING.md | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index b443874eef..8c3cc7b3d1 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -141,10 +141,11 @@ a `BufferingLogger` ([`src/logging/logBuffer.ts`](src/logging/logBuffer.ts)) wraps the channel and keeps a bounded, in-memory ring of the entries that sit **below** the current level, which the channel would otherwise drop. -When a WebSocket fails terminally, a workspace fails to open, or you collect a -support bundle, the extension replays the ring into the channel. The first -physical line of each replayed entry carries a `[buffered]` marker with its -original timestamp and level, and any continuation lines carry the bare marker. +When a WebSocket fails terminally, a remote session closes after a failed or +canceled open, or you collect a support bundle, the extension replays the ring +into the channel. The first physical line of each replayed entry carries a +`[buffered]` marker with its original timestamp and level, and any continuation +lines carry the bare marker. Capture is best-effort: the channel writes on its own schedule, so a bundle may miss the most recent lines, but a later failure flush still replays them. Transient reconnects and intentional teardown never flush, and neither does a