feat: implement debug logging with sensitive data masking

Add comprehensive debug logging throughout the codebase to aid in troubleshooting connection issues:

- Add process error handlers (uncaughtException, unhandledRejection)
- Add process signal handlers (SIGTERM, SIGINT, SIGHUP)
- Add memory pressure monitoring with heap usage alerts
- Implement sensitive data masking for logs (SSH keys, passwords, tokens)
- Add debug logging to SSH config operations with masked output
- Add connection lifecycle logging with unique connection IDs
- Add retry logic and backoff timing logs
- Add workspace disconnection event logging
- Refactor logger to separate vscode dependencies using adapter pattern
- Create ConfigProvider interface for test isolation
- Reorganize files into logical directories (config/, logging/, test/)
- All debug logs gated by coder.verbose flag

🤖 Generated with [Claude Code](https://claude.ai/code)

Co-Authored-By: Claude <noreply@anthropic.com>

Author: jaggederest

src/api.ts

@@ -17,6 +17,11 @@ import { getProxyForUrl } from "./proxy";
 import { Storage } from "./storage";
 import { expandPath } from "./util";
 
+// TODO: Add WebSocket connection logging
+// TODO: Add HTTP API call logging
+// TODO: Add certificate validation logging
+// TODO: Add token refresh logging
+
 export const coderSessionTokenHeader = "Coder-Session-Token";
 
 /**

src/config/index.ts

@@ -0,0 +1 @@
+export { VSCodeConfigProvider } from "./vscodeConfigProvider";

src/config/vscodeConfigProvider.ts

@@ -0,0 +1,18 @@
+import * as vscode from "vscode";
+import { ConfigProvider } from "../logger";
+
+export class VSCodeConfigProvider implements ConfigProvider {
+	getVerbose(): boolean {
+		const config = vscode.workspace.getConfiguration("coder");
+		return config.get<boolean>("verbose", false);
+	}
+
+	onVerboseChange(callback: () => void): { dispose: () => void } {
+		const disposable = vscode.workspace.onDidChangeConfiguration((e) => {
+			if (e.affectsConfiguration("coder.verbose")) {
+				callback();
+			}
+		});
+		return disposable;
+	}
+}

src/error.test.ts

@@ -246,7 +246,7 @@ it("falls back with different error", async () => {
 			servername: "localhost",
 		}),
 	});
-	await expect(request).rejects.toMatch(/failed with status code 500/);
+	await expect(request).rejects.toThrow(/failed with status code 500/);
 	try {
 		await request;
 	} catch (error) {

src/extension.ts

@@ -6,8 +6,10 @@ import * as vscode from "vscode";
 import { makeCoderSdk, needToken } from "./api";
 import { errToStr } from "./api-helper";
 import { Commands } from "./commands";
+import { VSCodeConfigProvider } from "./config";
 import { CertificateError, getErrorDetail } from "./error";
 import { logger } from "./logger";
+import { OutputChannelAdapter } from "./logging";
 import { Remote } from "./remote";
 import { Storage } from "./storage";
 import { toSafeHost } from "./util";
@@ -50,8 +52,58 @@ export async function activate(ctx: vscode.ExtensionContext): Promise<void> {
 
 	const output = vscode.window.createOutputChannel("Coder");
 
-	// Initialize logger with the output channel
-	logger.initialize(output);
+	// Initialize logger with the output channel and config provider
+	logger.initialize(new OutputChannelAdapter(output));
+	logger.setConfigProvider(new VSCodeConfigProvider());
+
+	// Set up error handlers for uncaught exceptions and unhandled rejections
+	process.on("uncaughtException", (error) => {
+		logger.debug(`[process#global] error: Uncaught exception - ${error.stack}`);
+		// Don't crash the extension - let VS Code handle it
+	});
+
+	process.on("unhandledRejection", (reason, promise) => {
+		logger.debug(
+			`[process#global] error: Unhandled rejection at ${promise} - reason: ${reason}`,
+		);
+	});
+
+	// Set up process signal handlers
+	const signals: NodeJS.Signals[] = ["SIGTERM", "SIGINT", "SIGHUP"];
+	signals.forEach((signal) => {
+		process.on(signal, () => {
+			logger.debug(`[process#global] disconnect: Received signal ${signal}`);
+		});
+	});
+
+	// Set up memory pressure monitoring
+	let memoryCheckInterval: NodeJS.Timeout | undefined;
+	const checkMemoryPressure = () => {
+		const usage = process.memoryUsage();
+		const heapUsedPercent = (usage.heapUsed / usage.heapTotal) * 100;
+		if (heapUsedPercent > 90) {
+			logger.debug(
+				`[process#global] error: High memory usage detected - heap used: ${heapUsedPercent.toFixed(
+					1,
+				)}% (${Math.round(usage.heapUsed / 1024 / 1024)}MB / ${Math.round(
+					usage.heapTotal / 1024 / 1024,
+				)}MB)`,
+			);
+		}
+	};
+
+	// Check memory every 30 seconds when verbose logging is enabled
+	const configProvider = new VSCodeConfigProvider();
+	if (configProvider.getVerbose()) {
+		memoryCheckInterval = setInterval(checkMemoryPressure, 30000);
+		ctx.subscriptions.push({
+			dispose: () => {
+				if (memoryCheckInterval) {
+					clearInterval(memoryCheckInterval);
+				}
+			},
+		});
+	}
 
 	const storage = new Storage(
 		output,

src/headers.test.ts

@@ -71,25 +71,25 @@ it("should return headers", async () => {
 it("should error on malformed or empty lines", async () => {
 	await expect(
 		getHeaders("localhost", "printf 'foo=bar\\r\\n\\r\\n'"),
-	).rejects.toMatch(/Malformed/);
+	).rejects.toThrow(/Malformed/);
 	await expect(
 		getHeaders("localhost", "printf '\\r\\nfoo=bar'"),
-	).rejects.toMatch(/Malformed/);
-	await expect(getHeaders("localhost", "printf '=foo'")).rejects.toMatch(
+	).rejects.toThrow(/Malformed/);
+	await expect(getHeaders("localhost", "printf '=foo'")).rejects.toThrow(
 		/Malformed/,
 	);
-	await expect(getHeaders("localhost", "printf 'foo'")).rejects.toMatch(
+	await expect(getHeaders("localhost", "printf 'foo'")).rejects.toThrow(
 		/Malformed/,
 	);
-	await expect(getHeaders("localhost", "printf '  =foo'")).rejects.toMatch(
+	await expect(getHeaders("localhost", "printf '  =foo'")).rejects.toThrow(
 		/Malformed/,
 	);
-	await expect(getHeaders("localhost", "printf 'foo  =bar'")).rejects.toMatch(
+	await expect(getHeaders("localhost", "printf 'foo  =bar'")).rejects.toThrow(
 		/Malformed/,
 	);
 	await expect(
 		getHeaders("localhost", "printf 'foo  foo=bar'"),
-	).rejects.toMatch(/Malformed/);
+	).rejects.toThrow(/Malformed/);
 });
 
 it("should have access to environment variables", async () => {
@@ -105,7 +105,7 @@ it("should have access to environment variables", async () => {
 });
 
 it("should error on non-zero exit", async () => {
-	await expect(getHeaders("localhost", "exit 10")).rejects.toMatch(
+	await expect(getHeaders("localhost", "exit 10")).rejects.toThrow(
 		/exited unexpectedly with code 10/,
 	);
 });

src/logger.test.ts

@@ -16,13 +16,9 @@ vi.mock("vscode", () => ({
 }));
 
 import * as vscode from "vscode";
-import {
-	ArrayAdapter,
-	LogLevel,
-	NoOpAdapter,
-	OutputChannelAdapter,
-	logger,
-} from "./logger";
+import { ArrayAdapter, LogLevel, NoOpAdapter, logger } from "./logger";
+import { OutputChannelAdapter } from "./logging";
+import { TestConfigProvider } from "./test";
 
 describe("Logger", () => {
 	beforeEach(() => {
@@ -191,79 +187,56 @@ describe("Logger", () => {
 
 	describe("Configuration", () => {
 		it("should read verbose setting on initialization", () => {
-			const mockConfig = {
-				get: vi.fn().mockReturnValue(true),
-			};
-			vi.mocked(vscode.workspace.getConfiguration).mockReturnValue(
-				mockConfig as unknown as vscode.WorkspaceConfiguration,
-			);
-
-			logger.reset(); // Reset triggers re-initialization
-
-			expect(vscode.workspace.getConfiguration).toHaveBeenCalledWith("coder");
-			expect(mockConfig.get).toHaveBeenCalledWith("verbose", false);
-		});
-
-		it("should update log level when configuration changes", () => {
-			let configChangeCallback: (
-				e: vscode.ConfigurationChangeEvent,
-			) => void = () => {};
-			const mockDisposable = { dispose: vi.fn() };
-
-			vi.mocked(vscode.workspace.onDidChangeConfiguration).mockImplementation(
-				(callback) => {
-					configChangeCallback = callback;
-					return mockDisposable as vscode.Disposable;
-				},
-			);
+			const adapter = new ArrayAdapter();
+			const configProvider = new TestConfigProvider();
 
-			const mockConfig = {
-				get: vi.fn().mockReturnValue(false),
-			};
-			vi.mocked(vscode.workspace.getConfiguration).mockReturnValue(
-				mockConfig as unknown as vscode.WorkspaceConfiguration,
-			);
+			logger.setAdapter(adapter);
+			logger.setConfigProvider(configProvider);
 
-			logger.reset();
+			// Test with verbose = false
+			configProvider.setVerbose(false);
+			logger.debug("Debug message");
+			logger.info("Info message");
 
-			// Change config to verbose
-			mockConfig.get.mockReturnValue(true);
-			configChangeCallback({
-				affectsConfiguration: (section: string) => section === "coder.verbose",
-			} as vscode.ConfigurationChangeEvent);
+			let logs = adapter.getSnapshot();
+			expect(logs.length).toBe(1); // Only info should be logged
+			expect(logs[0]).toContain("Info message");
 
-			// Verify it reads the new config
-			expect(mockConfig.get).toHaveBeenCalledWith("verbose", false);
+			// Clear and test with verbose = true
+			adapter.clear();
+			configProvider.setVerbose(true);
+			logger.debug("Debug message 2");
+			logger.info("Info message 2");
+
+			logs = adapter.getSnapshot();
+			expect(logs.length).toBe(2); // Both should be logged
+			expect(logs[0]).toContain("Debug message 2");
+			expect(logs[1]).toContain("Info message 2");
 		});
 
-		it("should ignore non-coder.verbose configuration changes", () => {
-			let configChangeCallback: (
-				e: vscode.ConfigurationChangeEvent,
-			) => void = () => {};
-			vi.mocked(vscode.workspace.onDidChangeConfiguration).mockImplementation(
-				(callback) => {
-					configChangeCallback = callback;
-					return { dispose: vi.fn() } as unknown as vscode.Disposable;
-				},
-			);
+		it("should update log level when configuration changes", () => {
+			const adapter = new ArrayAdapter();
+			const configProvider = new TestConfigProvider();
 
-			const mockConfig = {
-				get: vi.fn().mockReturnValue(false),
-			};
-			vi.mocked(vscode.workspace.getConfiguration).mockReturnValue(
-				mockConfig as unknown as vscode.WorkspaceConfiguration,
-			);
+			logger.setAdapter(adapter);
+			logger.setConfigProvider(configProvider);
 
-			logger.reset();
-			mockConfig.get.mockClear();
+			// Start with verbose = false
+			configProvider.setVerbose(false);
+			logger.debug("Debug 1");
+			logger.info("Info 1");
+
+			let logs = adapter.getSnapshot();
+			expect(logs.length).toBe(1); // Only info
 
-			// Trigger non-verbose config change
-			configChangeCallback({
-				affectsConfiguration: (section: string) => section === "other.setting",
-			} as vscode.ConfigurationChangeEvent);
+			// Change to verbose = true
+			adapter.clear();
+			configProvider.setVerbose(true);
+			logger.debug("Debug 2");
+			logger.info("Info 2");
 
-			// Should not re-read config
-			expect(mockConfig.get).not.toHaveBeenCalled();
+			logs = adapter.getSnapshot();
+			expect(logs.length).toBe(2); // Both logged
 		});
 	});
 
@@ -345,15 +318,33 @@ describe("Logger", () => {
 		});
 
 		it("should dispose configuration listener on reset", () => {
-			const mockDisposable = { dispose: vi.fn() };
-			vi.mocked(vscode.workspace.onDidChangeConfiguration).mockReturnValue(
-				mockDisposable as unknown as vscode.Disposable,
-			);
+			const adapter = new ArrayAdapter();
+			const configProvider = new TestConfigProvider();
+
+			logger.setAdapter(adapter);
+			logger.setConfigProvider(configProvider);
+
+			// Track if dispose was called
+			let disposed = false;
+			const originalOnVerboseChange =
+				configProvider.onVerboseChange.bind(configProvider);
+			configProvider.onVerboseChange = (callback: () => void) => {
+				const result = originalOnVerboseChange(callback);
+				return {
+					dispose: () => {
+						disposed = true;
+						result.dispose();
+					},
+				};
+			};
 
+			// Re-set config provider to register the wrapped listener
+			logger.setConfigProvider(configProvider);
+
+			// Reset should dispose the listener
 			logger.reset();
-			logger.reset(); // Second reset should dispose the first listener
 
-			expect(mockDisposable.dispose).toHaveBeenCalled();
+			expect(disposed).toBe(true);
 		});
 	});
 
@@ -364,7 +355,12 @@ describe("Logger", () => {
 				clear: vi.fn(),
 			} as unknown as vscode.OutputChannel;
 
-			logger.initialize(mockChannel);
+			const adapter = new OutputChannelAdapter(mockChannel);
+			logger.initialize(adapter);
+
+			// Set up config provider for test
+			const configProvider = new TestConfigProvider();
+			logger.setConfigProvider(configProvider);
 
 			// Verify we can log after initialization
 			logger.info("Test message");
@@ -373,9 +369,10 @@ describe("Logger", () => {
 
 		it("should throw if already initialized", () => {
 			const mockChannel = {} as vscode.OutputChannel;
-			logger.initialize(mockChannel);
+			const adapter = new OutputChannelAdapter(mockChannel);
+			logger.initialize(adapter);
 
-			expect(() => logger.initialize(mockChannel)).toThrow(
+			expect(() => logger.initialize(adapter)).toThrow(
 				"Logger already initialized",
 			);
 		});