Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
32 changes: 32 additions & 0 deletions CONTRIBUTING.md
Original file line number Diff line number Diff line change
Expand Up @@ -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:
Expand Down
6 changes: 6 additions & 0 deletions package.json
Original file line number Diff line number Diff line change
Expand Up @@ -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",
Expand Down
7 changes: 7 additions & 0 deletions src/api/coderApi.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand Down Expand Up @@ -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);
Expand All @@ -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();
Expand All @@ -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] =
Expand Down Expand Up @@ -548,6 +554,7 @@ export class CoderApi extends Api implements vscode.Disposable {
}
return refreshCertificates(refreshCommand, this.output);
},
onConnectionFailure: this.onConnectionFailure,
telemetry: this.telemetry,
};

Expand Down
46 changes: 43 additions & 3 deletions src/core/container.ts
Original file line number Diff line number Diff line change
@@ -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";
Expand Down Expand Up @@ -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;
Expand All @@ -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,
Expand Down Expand Up @@ -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;
}
Expand Down Expand Up @@ -193,10 +218,25 @@ 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 {
this.outputChannel.dispose();
}
}
}

const CONNECTION_LOG_BUFFER_SIZE_KEY = "coder.connectionLogBuffer.size";
const DEFAULT_CONNECTION_LOG_BUFFER_SIZE = 1000;

function readConnectionLogBufferSize(): number {
return vscode.workspace
.getConfiguration()
.get<number>(
CONNECTION_LOG_BUFFER_SIZE_KEY,
DEFAULT_CONNECTION_LOG_BUFFER_SIZE,
);
}
1 change: 1 addition & 0 deletions src/extension.ts
Original file line number Diff line number Diff line change
Expand Up @@ -143,6 +143,7 @@ async function doActivate(
deploymentSessionAuth?.token,
output,
telemetryService,
(reason) => serviceContainer.getConnectionLogBuffer().flush(reason),
);
ctx.subscriptions.push(client);

Expand Down
177 changes: 177 additions & 0 deletions src/logging/logBuffer.ts
Original file line number Diff line number Diff line change
@@ -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<Level, string> = {
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();
}
}
}
4 changes: 4 additions & 0 deletions src/remote/workspaceStateMachine.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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";
Expand All @@ -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,
Expand All @@ -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}`;
Expand Down Expand Up @@ -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":
Expand Down
Loading