feat(logging): tag logs with a per-session ID

src/core/container.ts

@@ -1,6 +1,7 @@
 import * as vscode from "vscode";
 
 import { AuthTelemetry } from "../instrumentation/auth";
+import { prefixLogger } from "../logging/prefixLogger";
 import { LoginCoordinator } from "../login/loginCoordinator";
 import { OAuthCallback } from "../oauth/oauthCallback";
 import { buildSession, extractExtensionVersion } from "../telemetry/event";
@@ -26,7 +27,9 @@ import type { Logger } from "../logging/logger";
  * Centralizes the creation and management of all core services.
  */
 export class ServiceContainer implements vscode.Disposable {
-	private readonly logger: vscode.LogOutputChannel;
+	private readonly outputChannel: vscode.LogOutputChannel;
+	private readonly sessionId: string;
+	private readonly logger: Logger;
 	private readonly pathResolver: PathResolver;
 	private readonly mementoManager: MementoManager;
 	private readonly secretsManager: SecretsManager;
@@ -42,7 +45,13 @@ export class ServiceContainer implements vscode.Disposable {
 	private readonly commandManager: CommandManager;
 
 	constructor(context: vscode.ExtensionContext) {
-		this.logger = vscode.window.createOutputChannel("Coder", { log: true });
+		this.outputChannel = vscode.window.createOutputChannel("Coder", {
+			log: true,
+		});
+		// One session ID per activation, shared by logs, API requests,
+		// telemetry, and the CLI so all data for a session correlates.
+		this.sessionId = newSessionId();
+		this.logger = prefixLogger(this.outputChannel, `[${this.sessionId}]`);
 		this.pathResolver = new PathResolver(
 			context.globalStorageUri.fsPath,
 			context.logUri.fsPath,
@@ -56,7 +65,7 @@ export class ServiceContainer implements vscode.Disposable {
 
 		const session = buildSession(
 			extractExtensionVersion(context.extension.packageJSON),
-			newSessionId(),
+			this.sessionId,
 		);
 		const localJsonlSink = LocalJsonlSink.start(
 			{
@@ -187,7 +196,7 @@ export class ServiceContainer implements vscode.Disposable {
 		try {
 			await this.telemetryService.dispose();
 		} finally {
-			this.logger.dispose();
+			this.outputChannel.dispose();
 		}
 	}
 }

src/logging/prefixLogger.ts

@@ -0,0 +1,18 @@
+import type { Logger } from "./logger";
+
+/**
+ * Wraps a {@link Logger} so every message is prefixed, letting all lines that
+ * share a prefix (a session ID, a workspace name) be found with one search.
+ * Extra arguments are forwarded untouched.
+ */
+export function prefixLogger(inner: Logger, prefix: string): Logger {
+	const tag = (message: string) => `${prefix} ${message}`;
+	return {
+		trace: (message, ...args) => inner.trace(tag(message), ...args),
+		debug: (message, ...args) => inner.debug(tag(message), ...args),
+		info: (message, ...args) => inner.info(tag(message), ...args),
+		warn: (message, ...args) => inner.warn(tag(message), ...args),
+		error: (message, ...args) => inner.error(tag(message), ...args),
+		show: () => inner.show(),
+	};
+}

test/unit/logging/prefixLogger.test.ts

@@ -0,0 +1,45 @@
+import { describe, expect, it } from "vitest";
+
+import { prefixLogger } from "@/logging/prefixLogger";
+
+import { createMockLogger } from "../../mocks/testHelpers";
+
+const PREFIX = "[0123456789abcdef0123456789abcdef]";
+
+describe("prefixLogger", () => {
+	it("prefixes every level with the given prefix", () => {
+		const inner = createMockLogger();
+		const logger = prefixLogger(inner, PREFIX);
+
+		logger.trace("trace msg");
+		logger.debug("debug msg");
+		logger.info("info msg");
+		logger.warn("warn msg");
+		logger.error("error msg");
+
+		expect(inner.trace).toHaveBeenCalledWith(`${PREFIX} trace msg`);
+		expect(inner.debug).toHaveBeenCalledWith(`${PREFIX} debug msg`);
+		expect(inner.info).toHaveBeenCalledWith(`${PREFIX} info msg`);
+		expect(inner.warn).toHaveBeenCalledWith(`${PREFIX} warn msg`);
+		expect(inner.error).toHaveBeenCalledWith(`${PREFIX} error msg`);
+	});
+
+	it("forwards additional arguments unchanged", () => {
+		const inner = createMockLogger();
+		const logger = prefixLogger(inner, PREFIX);
+		const err = new Error("boom");
+
+		logger.error("failed", err, 42);
+
+		expect(inner.error).toHaveBeenCalledWith(`${PREFIX} failed`, err, 42);
+	});
+
+	it("delegates show() to the underlying logger", () => {
+		const inner = createMockLogger();
+		const logger = prefixLogger(inner, PREFIX);
+
+		logger.show();
+
+		expect(inner.show).toHaveBeenCalledOnce();
+	});
+});