From a800f6ef9cfa7447fe2f8a8ba9f0a204c0875f84 Mon Sep 17 00:00:00 2001 From: Andrew Aquino Date: Wed, 26 Aug 2026 21:01:22 +0000 Subject: [PATCH 01/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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/20] 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