Skip to content
Open
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": {

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please add this key to COLLECTED_SETTINGS in src/supportBundle/settings.ts. Otherwise Support cannot tell from the bundle whether buffering was disabled or its capacity changed.

"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
Comment on lines +218 to +222

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please describe this as a maximum number of entries, not lines or bytes; one entry can contain multiple lines and arguments. Should we also set an upper limit on the configurable capacity? If so, enforce the same limit in normalizeCapacity() and test it.

},
"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;

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please keep a single field typed as BufferingLogger rather than storing the same instance twice. Both getters can return that field while still exposing Logger and ConnectionLogBuffer respectively.

this.disposables.push(
this.connectionLogBuffer,
vscode.workspace.onDidChangeConfiguration((event) => {
if (event.affectsConfiguration(CONNECTION_LOG_BUFFER_SIZE_KEY)) {
this.connectionLogBuffer.setCapacity(readConnectionLogBufferSize());
}
}),
);
Comment on lines +67 to 74

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Once the log-level subscription is removed, only the configuration subscription needs cleanup here. Please store it in a named field and dispose it explicitly, matching the surrounding services. A generic disposables array suggests it owns all service cleanup when it only owns a subset.

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;
Comment on lines +232 to +233

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please move these constants below the imports, before the class.


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),

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This only wires the shared client. Please pass the callback to workspaceClient in remote.ts too, since that client owns the remote workspace’s streams. Add a test verifying that its terminal socket failures flush the buffer. HTTP-only clients can still omit the callback.

);
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> = {

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please use Readonly<Record<Level, string>> here so the labels cannot be reassigned. SEVERITY is already readonly through as const.

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 {

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could we call this LogEntry? Its fields describe a log entry; none are specific to buffering.

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.
Comment on lines +48 to +58

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please shorten this to the behavior that matters: “Buffers entries below the current log level and replays them on failure at a level the output channel persists.” The implementation explains the rest. Please also avoid em-dashes in the added comments.

*/
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,
Comment on lines +71 to +72

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The injected clock mainly supports suppression tests. Once suppression is removed, can we use Date.now() directly and fake time in timestamp tests? Please retain an assertion that replay includes the original timestamp, not the flush time.

) {
this.capacity = normalizeCapacity(capacity);
this.currentLevel = levelSource.getLogLevel();
this.levelSubscription = levelSource.onDidChangeLogLevel((level) => {
this.currentLevel = level;
});
Comment on lines +75 to +78

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we accept a single getLogLevel: () => number callback and call it from both record() and replayEmitter()? That removes LogLevelSource, the cached level, the change subscription, and its cleanup, while keeping the logger independent of VS Code.

}

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;
}
Comment on lines +125 to +127

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If failure A flushes, then new logs arrive before failure B one second later, B’s logs remain buffered with no later write scheduled.

Please remove the suppression window and its state. Clearing the buffer already prevents duplicate replay. Add a test showing that two consecutive failures each flush their newly accumulated entries.

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