From 6938bc926b0b0c8d14fc662c46a3419c8831516b Mon Sep 17 00:00:00 2001 From: Justin George Date: Wed, 2 Jul 2025 19:23:29 -0700 Subject: [PATCH 1/6] Add updated workflow and spec for logging adapter implementation --- .claude/scopes/LoggingAdapter.md | 244 +++++++++++++++++++++++++++++++ CLAUDE.md | 51 +++++++ 2 files changed, 295 insertions(+) create mode 100644 .claude/scopes/LoggingAdapter.md diff --git a/.claude/scopes/LoggingAdapter.md b/.claude/scopes/LoggingAdapter.md new file mode 100644 index 00000000..67d85a4d --- /dev/null +++ b/.claude/scopes/LoggingAdapter.md @@ -0,0 +1,244 @@ +# Logging Adapter Specification + +## Purpose & User Problem + +The vscode-coder extension currently handles logging through the Storage class, where logging functionality is commingled with storage concerns. The `writeToCoderOutputChannel` method exists in the Storage class alongside file system operations, secret management, and other unrelated functionality. This makes it difficult to: + +- **Debug user-reported issues**: When users report bugs, especially client connection issues that don't reproduce locally, there's no consistent way to enable detailed logging to help diagnose the problem +- **Centralize logging logic**: Logging is tied to the Storage class, which also manages secrets, URLs, CLI binaries, and file operations - a clear violation of single responsibility +- **Control verbosity**: Users can't easily enable debug-level logging when needed without modifying code +- **Standardize output**: While `writeToCoderOutputChannel` adds timestamps, other parts use direct `output.appendLine` calls +- **Expand debugging capabilities**: Adding new diagnostic logging for specific subsystems (like client connections) requires passing the Storage instance around +- **Maintain separation of concerns**: The Storage class has become a "god object" that handles too many responsibilities + +## Success Criteria + +1. **Centralized Logging**: All log output goes through a single adapter +2. **Log Levels**: Support for `debug` and `info` levels + - Additional levels can be added in future iterations +3. **Type Safety**: Fully typed TypeScript implementation + - No `any` types in the logger module or modified files + - No `@ts-ignore` or `eslint-disable` comments + - All types explicitly defined or properly inferred +4. **Testable**: + - Unit tests use `ArrayAdapter` for fast, isolated testing + - ArrayAdapter provides immutable snapshots via `getSnapshot()` to prevent test interference + - Integration tests use `OutputChannelAdapter` to verify VS Code integration + - Test isolation for concurrent test suites: + - `setAdapter()` throws if adapter already set (prevents test conflicts) + - `withAdapter()` provides safe temporary adapter swapping with automatic revert + - Ideal for Vitest's concurrent test execution + - `reset()` and `setAdapter()` methods restricted to test environment (NODE_ENV === 'test') + - `reset()` properly disposes of configuration change listeners to prevent memory leaks + - Methods throw error if called in production for safety +5. **Performance**: Minimal overhead for logging operations + - Measured relative to a no-op adapter baseline + - Debug calls when disabled: < 10% overhead vs no-op + - Debug calls when enabled: < 10x overhead vs no-op (including formatting) + - Info calls: < 5x overhead vs no-op + - Measurement methodology: + - Use `performance.now()` from Node's `perf_hooks` + - Compare against `NoOpAdapter` that does nothing + - Run 10,000 iterations, discard outliers, use median + - CI passes if within percentage thresholds (not absolute times) +6. **Fault Tolerance**: Logger never throws exceptions + - Silently swallows OutputChannel errors (e.g., disposed channel on reload) + - Logging failures must not crash the extension + - No error propagation from the logging subsystem + - Accepts that OutputChannel writes may interleave under concurrent access +7. **Live Configuration**: Monitor `coder.verbose` setting changes without requiring extension restart + - Supports workspace, folder, and global configuration levels + - Uses the most specific configuration available + +## Scope & Constraints + +### In Scope +- Extract logging functionality from the Storage class into a dedicated logging adapter +- Create a logging adapter/service with support for debug and info levels +- Convert all existing `writeToCoderOutputChannel` and `output.appendLine` calls to use the adapter +- Maintain integration with VS Code's OutputChannel ("Coder") + - OutputChannel is created in `extension.ts` and passed to both Logger and Storage + - Logger uses it for logging via OutputChannelAdapter + - Storage continues to use it for progress reporting (e.g., binary downloads) +- Provide a simple API for logging (e.g., `logger.debug("message")`, `logger.info("message")`) + - Callers only provide the message content, not formatting + - Only string messages accepted (no automatic object serialization) + - Callers must stringify objects/errors before logging (e.g., using template literals) +- Allow runtime configuration of log levels +- Handle all formatting (timestamps, level tags, etc.) within the logger +- Remove only the `writeToCoderOutputChannel` method from Storage class + +### Out of Scope +- External logging services integration (future enhancement) +- File-based logging (all logs go to VS Code OutputChannel) +- Log file rotation or persistence +- Structured logging formats (JSON, etc.) +- Performance metrics or telemetry +- Custom UI for viewing logs (uses VS Code's built-in OutputChannel UI) +- Synchronization of concurrent writes (OutputChannel writes may interleave) +- Automatic object/error serialization (callers must convert to strings) + +## Technical Considerations + +### Architecture +- Singleton pattern for the logger instance +- Interface-based design with pluggable adapters: + - `LogAdapter` interface for output handling + - `OutputChannelAdapter` for VS Code OutputChannel integration + - `ArrayAdapter` for testing (stores logs in memory) +- OutputChannel ownership and lifecycle: + - Created once in `extension.ts` activate method + - Passed to OutputChannelAdapter constructor + - Also passed to Storage for non-logging uses (progress reporting) + - Single channel shared between Logger and Storage + - Note: VS Code OutputChannel is async; concurrent writes may interleave + - This is acceptable for debugging/diagnostic purposes + - In browser/web extensions, OutputChannel maps to in-memory buffer (no file I/O) +- Configuration through VS Code settings: + - `coder.verbose`: boolean setting to enable debug logging (default: false) + - When true: shows debug level logs + - When false: shows info level and above only + - Respects workspace folder-specific settings (uses most specific configuration) +- Configuration monitoring using `vscode.workspace.onDidChangeConfiguration` + - Only responds to changes in `coder.verbose` specifically + - Ignores all other configuration changes to avoid unnecessary processing + - Updates when workspace folders are added/removed or active editor changes +- **Centralized formatting**: All log formatting (timestamps, level tags, source location) happens within the logger implementation, not at call sites + +### API Design +```typescript +interface LogAdapter { + write(message: string): void + clear(): void +} + +interface Logger { + log(message: string, severity?: LogLevel): void // Core method, defaults to INFO + debug(message: string): void // String only - no object serialization + info(message: string): void // String only - no object serialization + setLevel(level: LogLevel): void + setAdapter(adapter: LogAdapter): void // For testing only - throws if adapter already set + withAdapter(adapter: LogAdapter, fn: () => T): T // Safe temporary adapter swap + reset(): void // For testing only - throws if NODE_ENV !== 'test', disposes listeners +} + +enum LogLevel { + DEBUG = 0, + INFO = 1, + NONE = 2 // Disables all logging +} + +// Example implementations +class OutputChannelAdapter implements LogAdapter { + constructor(private outputChannel: vscode.OutputChannel) {} + write(message: string): void { + try { + this.outputChannel.appendLine(message) + } catch { + // Silently ignore - channel may be disposed + } + } + clear(): void { + try { + this.outputChannel.clear() + } catch { + // Silently ignore - channel may be disposed + } + } +} + +class ArrayAdapter implements LogAdapter { + private logs: string[] = [] + + write(message: string): void { + this.logs.push(message) + } + + clear(): void { + this.logs = [] + } + + getSnapshot(): readonly string[] { + return [...this.logs] // Return defensive copy + } +} + +class NoOpAdapter implements LogAdapter { + write(message: string): void { + // Intentionally empty - baseline for performance tests + } + + clear(): void { + // Intentionally empty - baseline for performance tests + } +} +``` + +### Log Format +- **Standard format**: `[LEVEL] TIMESTAMP MESSAGE` + - Timestamp in UTC ISO-8601 format (e.g., `2024-01-15T10:30:45.123Z`) + - Example: `[info] 2024-01-15T10:30:45.123Z Starting extension...` + - Example: `[debug] 2024-01-15T10:30:45.456Z Processing file: example.ts` + +- **Debug mode enhancement**: When `coder.verbose` is true, debug logs include source location: + ``` + [debug] 2024-01-15T10:30:45.456Z Processing file: example.ts + at processFile (src/utils/fileHandler.ts:45) + ``` + - Note: In browser/web extensions, `Error().stack` may be empty, disabling source location + +### Implementation Plan + +1. Create the logger module at `src/logger.ts` with: + - Singleton pattern implementation + - LogAdapter interface and implementations (OutputChannelAdapter, ArrayAdapter) + - Logger initialization accepts OutputChannel (not created internally) + - Configuration reading from VS Code settings (`coder.verbose`) + - Use `workspace.getConfiguration()` to respect folder-specific settings + - Configuration change listener using `workspace.onDidChangeConfiguration` + - Filter to only handle `coder.verbose` changes using `affectsConfiguration()` + - Re-read configuration on folder/editor changes to respect local settings + - Timestamp formatting in UTC ISO-8601 (using `new Date().toISOString()`) and level prefixes + - Debug mode with source location tracking (file/line info) + - Gracefully handle empty `Error().stack` in browser environments + - Test method guards: `reset()` and `setAdapter()` check `process.env.NODE_ENV === 'test'` + - `setAdapter()` throws if adapter already installed (prevents concurrent test conflicts) + - `withAdapter()` implementation: + ```typescript + withAdapter(adapter: LogAdapter, fn: () => T): T { + const previous = this.adapter + this.adapter = adapter + try { + return fn() + } finally { + this.adapter = previous + } + } + ``` + - `reset()` implementation must dispose configuration listener to prevent memory leaks +2. Create comprehensive tests at `src/logger.test.ts`: + - Unit tests using ArrayAdapter for logic testing + - Separate integration tests for OutputChannelAdapter + - Performance benchmarks: + - Create NoOpAdapter as baseline + - Measure relative performance using `performance.now()` + - Ensure overhead stays within specified percentages + - Test both cold and warm paths +3. Update `extension.ts`: + - Create OutputChannel in activate method + - Initialize Logger with OutputChannel via OutputChannelAdapter + - Continue passing OutputChannel to Storage (for progress reporting) +4. Extract and refactor the existing `writeToCoderOutputChannel` logic from Storage class +5. Remove ONLY the `writeToCoderOutputChannel` method from Storage (keep OutputChannel for other uses) +6. Systematically replace each `writeToCoderOutputChannel` call with appropriate logger methods +7. For `output.appendLine` calls in Storage, evaluate each: + - Logging messages → convert to logger calls + - Progress/status messages → keep as direct OutputChannel calls +8. Verify functionality with existing tests +9. Run linting (`yarn lint`) and ensure code quality + +### File Locations +- Logger implementation: `src/logger.ts` +- Tests: `src/logger.test.ts` +- Type definitions included in the logger file + diff --git a/CLAUDE.md b/CLAUDE.md index 04c75edc..7acd9bb9 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -25,3 +25,54 @@ - Error handling: wrap and type errors appropriately - Use async/await for promises, avoid explicit Promise construction where possible - Test files must be named `*.test.ts` and use Vitest + +## Development Workflow: Spec → Code + +THESE INSTRUCTIONS ARE CRITICAL! + +They dramatically improve the quality of the work you create. + +### Phase 1: Requirements First + +When asked to implement any feature or make changes, ALWAYS start by asking: +"Should I create a Spec for this task first?" + +IFF user agrees: + +- Create a markdown file in `.claude/scopes/FeatureName.md` +- Interview the user to clarify: +- Purpose & user problem +- Success criteria +- Scope & constraints +- Technical considerations +- Out of scope items + +### Phase 2: Review & Refine + +After drafting the Spec: + +- Present it to the user +- Ask: "Does this capture your intent? Any changes needed?" +- Iterate until user approves +- End with: "Spec looks good? Type 'GO!' when ready to implement" + +### Phase 3: Implementation + +ONLY after user types "GO!" or explicitly approves: + +- Begin coding based on the Spec +- Reference the Spec for decisions +- Update Spec if scope changes, but ask user first. + +### File Organization + +``` + +.claude/ +├── scopes/ +│ ├── FeatureName.md # Shared/committed Specs +│ └── OtherFeature.md # Other Specs, for future or past work + +``` + +**Remember: Think first, ask clarifying questions, _then_ code. The Spec is your north star.** From 721bceb50a226bc201ddacd3748d1490de076a7a Mon Sep 17 00:00:00 2001 From: Justin George Date: Wed, 2 Jul 2025 20:12:07 -0700 Subject: [PATCH 2/6] feat: implement centralized logging adapter MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Implement a centralized logging system to improve debugging capabilities and separate logging concerns from the Storage class. - Add logger module with configurable debug/info levels - Support runtime configuration via coder.verbose setting - Provide OutputChannelAdapter for VS Code integration - Add ArrayAdapter for isolated unit testing - Include performance benchmarks in tests - Maintain backward compatibility via Storage delegation - Update all components to use centralized logger The logger responds to configuration changes without requiring extension restart and includes source location tracking for debug messages. 🤖 Generated with [Claude Code](https://claude.ai/code) Co-Authored-By: Claude --- src/api.ts | 2 +- src/commands.ts | 5 +- src/error.test.ts | 27 ++- src/error.ts | 8 +- src/extension.ts | 27 ++- src/headers.test.ts | 103 +++++---- src/headers.ts | 12 +- src/inbox.ts | 9 +- src/logger.test.ts | 476 ++++++++++++++++++++++++++++++++++++++ src/logger.ts | 198 ++++++++++++++++ src/remote.ts | 63 ++--- src/storage.ts | 14 +- src/workspaceMonitor.ts | 7 +- src/workspacesProvider.ts | 3 +- 14 files changed, 802 insertions(+), 152 deletions(-) create mode 100644 src/logger.test.ts create mode 100644 src/logger.ts diff --git a/src/api.ts b/src/api.ts index 22de2618..986fc84e 100644 --- a/src/api.ts +++ b/src/api.ts @@ -105,7 +105,7 @@ export function makeCoderSdk( restClient.getAxiosInstance().interceptors.response.use( (r) => r, async (err) => { - throw await CertificateError.maybeWrap(err, baseUrl, storage); + throw await CertificateError.maybeWrap(err, baseUrl); }, ); diff --git a/src/commands.ts b/src/commands.ts index d6734376..0f89de1a 100644 --- a/src/commands.ts +++ b/src/commands.ts @@ -10,6 +10,7 @@ import * as vscode from "vscode"; import { makeCoderSdk, needToken } from "./api"; import { extractAgents } from "./api-helper"; import { CertificateError } from "./error"; +import { logger } from "./logger"; import { Storage } from "./storage"; import { toRemoteAuthority, toSafeHost } from "./util"; import { OpenableTreeItem } from "./workspacesProvider"; @@ -245,9 +246,7 @@ export class Commands { } catch (err) { const message = getErrorMessage(err, "no response from the server"); if (isAutologin) { - this.storage.writeToCoderOutputChannel( - `Failed to log in to Coder server: ${message}`, - ); + logger.info(`Failed to log in to Coder server: ${message}`); } else { this.vscodeProposed.window.showErrorMessage( "Failed to log in to Coder server", diff --git a/src/error.test.ts b/src/error.test.ts index 3c4a50c3..eb710b0e 100644 --- a/src/error.test.ts +++ b/src/error.test.ts @@ -19,16 +19,19 @@ const isElectron = // TODO: Remove the vscode mock once we revert the testing framework. beforeAll(() => { vi.mock("vscode", () => { - return {}; + return { + workspace: { + getConfiguration: vi.fn().mockReturnValue({ + get: vi.fn().mockReturnValue(false), + }), + onDidChangeConfiguration: vi.fn().mockReturnValue({ + dispose: vi.fn(), + }), + }, + }; }); }); -const logger = { - writeToCoderOutputChannel(message: string) { - throw new Error(message); - }, -}; - const disposers: (() => void)[] = []; afterAll(() => { disposers.forEach((d) => d()); @@ -89,7 +92,7 @@ it("detects partial chains", async () => { try { await request; } catch (error) { - const wrapped = await CertificateError.maybeWrap(error, address, logger); + const wrapped = await CertificateError.maybeWrap(error, address); expect(wrapped instanceof CertificateError).toBeTruthy(); expect((wrapped as CertificateError).x509Err).toBe(X509_ERR.PARTIAL_CHAIN); } @@ -126,7 +129,7 @@ it("detects self-signed certificates without signing capability", async () => { try { await request; } catch (error) { - const wrapped = await CertificateError.maybeWrap(error, address, logger); + const wrapped = await CertificateError.maybeWrap(error, address); expect(wrapped instanceof CertificateError).toBeTruthy(); expect((wrapped as CertificateError).x509Err).toBe(X509_ERR.NON_SIGNING); } @@ -157,7 +160,7 @@ it("detects self-signed certificates", async () => { try { await request; } catch (error) { - const wrapped = await CertificateError.maybeWrap(error, address, logger); + const wrapped = await CertificateError.maybeWrap(error, address); expect(wrapped instanceof CertificateError).toBeTruthy(); expect((wrapped as CertificateError).x509Err).toBe(X509_ERR.UNTRUSTED_LEAF); } @@ -200,7 +203,7 @@ it("detects an untrusted chain", async () => { try { await request; } catch (error) { - const wrapped = await CertificateError.maybeWrap(error, address, logger); + const wrapped = await CertificateError.maybeWrap(error, address); expect(wrapped instanceof CertificateError).toBeTruthy(); expect((wrapped as CertificateError).x509Err).toBe( X509_ERR.UNTRUSTED_CHAIN, @@ -247,7 +250,7 @@ it("falls back with different error", async () => { try { await request; } catch (error) { - const wrapped = await CertificateError.maybeWrap(error, "1", logger); + const wrapped = await CertificateError.maybeWrap(error, "1"); expect(wrapped instanceof CertificateError).toBeFalsy(); expect((wrapped as Error).message).toMatch(/failed with status code 500/); } diff --git a/src/error.ts b/src/error.ts index 53cc3389..610ac546 100644 --- a/src/error.ts +++ b/src/error.ts @@ -3,6 +3,7 @@ import { isApiError, isApiErrorResponse } from "coder/site/src/api/errors"; import * as forge from "node-forge"; import * as tls from "tls"; import * as vscode from "vscode"; +import { logger } from "./logger"; // X509_ERR_CODE represents error codes as returned from BoringSSL/OpenSSL. export enum X509_ERR_CODE { @@ -21,10 +22,6 @@ export enum X509_ERR { UNTRUSTED_CHAIN = "Your Coder deployment's certificate chain does not appear to be trusted by this system. The root of the certificate chain must be added to this system's trust store. ", } -export interface Logger { - writeToCoderOutputChannel(message: string): void; -} - interface KeyUsage { keyCertSign: boolean; } @@ -47,7 +44,6 @@ export class CertificateError extends Error { static async maybeWrap( err: T, address: string, - logger: Logger, ): Promise { if (isAxiosError(err)) { switch (err.code) { @@ -59,7 +55,7 @@ export class CertificateError extends Error { await CertificateError.determineVerifyErrorCause(address); return new CertificateError(err.message, cause); } catch (error) { - logger.writeToCoderOutputChannel( + logger.debug( `Failed to parse certificate from ${address}: ${error}`, ); break; diff --git a/src/extension.ts b/src/extension.ts index 05eb7319..c2a31136 100644 --- a/src/extension.ts +++ b/src/extension.ts @@ -7,6 +7,7 @@ import { makeCoderSdk, needToken } from "./api"; import { errToStr } from "./api-helper"; import { Commands } from "./commands"; import { CertificateError, getErrorDetail } from "./error"; +import { logger } from "./logger"; import { Remote } from "./remote"; import { Storage } from "./storage"; import { toSafeHost } from "./util"; @@ -48,6 +49,10 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { } const output = vscode.window.createOutputChannel("Coder"); + + // Initialize logger with the output channel + logger.initialize(output); + const storage = new Storage( output, ctx.globalState, @@ -317,7 +322,7 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { } } catch (ex) { if (ex instanceof CertificateError) { - storage.writeToCoderOutputChannel(ex.x509Err || ex.message); + logger.info(ex.x509Err || ex.message); await ex.showModal("Failed to open workspace"); } else if (isAxiosError(ex)) { const msg = getErrorMessage(ex, "None"); @@ -326,7 +331,7 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { const method = ex.config?.method?.toUpperCase() || "request"; const status = ex.response?.status || "None"; const message = `API ${method} to '${urlString}' failed.\nStatus code: ${status}\nMessage: ${msg}\nDetail: ${detail}`; - storage.writeToCoderOutputChannel(message); + logger.info(message); await vscodeProposed.window.showErrorMessage( "Failed to open workspace", { @@ -337,7 +342,7 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { ); } else { const message = errToStr(ex, "No error message was provided"); - storage.writeToCoderOutputChannel(message); + logger.info(message); await vscodeProposed.window.showErrorMessage( "Failed to open workspace", { @@ -356,14 +361,12 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { // See if the plugin client is authenticated. const baseUrl = restClient.getAxiosInstance().defaults.baseURL; if (baseUrl) { - storage.writeToCoderOutputChannel( - `Logged in to ${baseUrl}; checking credentials`, - ); + logger.info(`Logged in to ${baseUrl}; checking credentials`); restClient .getAuthenticatedUser() .then(async (user) => { if (user && user.roles) { - storage.writeToCoderOutputChannel("Credentials are valid"); + logger.info("Credentials are valid"); vscode.commands.executeCommand( "setContext", "coder.authenticated", @@ -381,17 +384,13 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { myWorkspacesProvider.fetchAndRefresh(); allWorkspacesProvider.fetchAndRefresh(); } else { - storage.writeToCoderOutputChannel( - `No error, but got unexpected response: ${user}`, - ); + logger.info(`No error, but got unexpected response: ${user}`); } }) .catch((error) => { // This should be a failure to make the request, like the header command // errored. - storage.writeToCoderOutputChannel( - `Failed to check user authentication: ${error.message}`, - ); + logger.info(`Failed to check user authentication: ${error.message}`); vscode.window.showErrorMessage( `Failed to check user authentication: ${error.message}`, ); @@ -400,7 +399,7 @@ export async function activate(ctx: vscode.ExtensionContext): Promise { vscode.commands.executeCommand("setContext", "coder.loaded", true); }); } else { - storage.writeToCoderOutputChannel("Not currently logged in"); + logger.info("Not currently logged in"); vscode.commands.executeCommand("setContext", "coder.loaded", true); // Handle autologin, if not already logged in. diff --git a/src/headers.test.ts b/src/headers.test.ts index 5cf333f5..9ef80010 100644 --- a/src/headers.test.ts +++ b/src/headers.test.ts @@ -1,86 +1,94 @@ import * as os from "os"; -import { it, expect, describe, beforeEach, afterEach, vi } from "vitest"; +import { + it, + expect, + describe, + beforeEach, + afterEach, + vi, + beforeAll, +} from "vitest"; import { WorkspaceConfiguration } from "vscode"; import { getHeaderCommand, getHeaders } from "./headers"; -const logger = { - writeToCoderOutputChannel() { - // no-op - }, -}; +// Mock vscode module before importing anything that uses logger +beforeAll(() => { + vi.mock("vscode", () => { + return { + workspace: { + getConfiguration: vi.fn().mockReturnValue({ + get: vi.fn().mockReturnValue(false), + }), + onDidChangeConfiguration: vi.fn().mockReturnValue({ + dispose: vi.fn(), + }), + }, + }; + }); +}); it("should return no headers", async () => { - await expect(getHeaders(undefined, undefined, logger)).resolves.toStrictEqual( - {}, - ); - await expect( - getHeaders("localhost", undefined, logger), - ).resolves.toStrictEqual({}); - await expect(getHeaders(undefined, "command", logger)).resolves.toStrictEqual( - {}, - ); - await expect(getHeaders("localhost", "", logger)).resolves.toStrictEqual({}); - await expect(getHeaders("", "command", logger)).resolves.toStrictEqual({}); - await expect(getHeaders("localhost", " ", logger)).resolves.toStrictEqual( - {}, - ); - await expect(getHeaders(" ", "command", logger)).resolves.toStrictEqual({}); - await expect( - getHeaders("localhost", "printf ''", logger), - ).resolves.toStrictEqual({}); + await expect(getHeaders(undefined, undefined)).resolves.toStrictEqual({}); + await expect(getHeaders("localhost", undefined)).resolves.toStrictEqual({}); + await expect(getHeaders(undefined, "command")).resolves.toStrictEqual({}); + await expect(getHeaders("localhost", "")).resolves.toStrictEqual({}); + await expect(getHeaders("", "command")).resolves.toStrictEqual({}); + await expect(getHeaders("localhost", " ")).resolves.toStrictEqual({}); + await expect(getHeaders(" ", "command")).resolves.toStrictEqual({}); + await expect(getHeaders("localhost", "printf ''")).resolves.toStrictEqual({}); }); it("should return headers", async () => { await expect( - getHeaders("localhost", "printf 'foo=bar\\nbaz=qux'", logger), + getHeaders("localhost", "printf 'foo=bar\\nbaz=qux'"), ).resolves.toStrictEqual({ foo: "bar", baz: "qux", }); await expect( - getHeaders("localhost", "printf 'foo=bar\\r\\nbaz=qux'", logger), + getHeaders("localhost", "printf 'foo=bar\\r\\nbaz=qux'"), ).resolves.toStrictEqual({ foo: "bar", baz: "qux", }); await expect( - getHeaders("localhost", "printf 'foo=bar\\r\\n'", logger), + getHeaders("localhost", "printf 'foo=bar\\r\\n'"), ).resolves.toStrictEqual({ foo: "bar" }); await expect( - getHeaders("localhost", "printf 'foo=bar'", logger), + getHeaders("localhost", "printf 'foo=bar'"), ).resolves.toStrictEqual({ foo: "bar" }); await expect( - getHeaders("localhost", "printf 'foo=bar='", logger), + getHeaders("localhost", "printf 'foo=bar='"), ).resolves.toStrictEqual({ foo: "bar=" }); await expect( - getHeaders("localhost", "printf 'foo=bar=baz'", logger), + getHeaders("localhost", "printf 'foo=bar=baz'"), ).resolves.toStrictEqual({ foo: "bar=baz" }); - await expect( - getHeaders("localhost", "printf 'foo='", logger), - ).resolves.toStrictEqual({ foo: "" }); + await expect(getHeaders("localhost", "printf 'foo='")).resolves.toStrictEqual( + { foo: "" }, + ); }); it("should error on malformed or empty lines", async () => { await expect( - getHeaders("localhost", "printf 'foo=bar\\r\\n\\r\\n'", logger), - ).rejects.toMatch(/Malformed/); - await expect( - getHeaders("localhost", "printf '\\r\\nfoo=bar'", logger), + getHeaders("localhost", "printf 'foo=bar\\r\\n\\r\\n'"), ).rejects.toMatch(/Malformed/); await expect( - getHeaders("localhost", "printf '=foo'", logger), + getHeaders("localhost", "printf '\\r\\nfoo=bar'"), ).rejects.toMatch(/Malformed/); - await expect(getHeaders("localhost", "printf 'foo'", logger)).rejects.toMatch( + await expect(getHeaders("localhost", "printf '=foo'")).rejects.toMatch( + /Malformed/, + ); + await expect(getHeaders("localhost", "printf 'foo'")).rejects.toMatch( + /Malformed/, + ); + await expect(getHeaders("localhost", "printf ' =foo'")).rejects.toMatch( + /Malformed/, + ); + await expect(getHeaders("localhost", "printf 'foo =bar'")).rejects.toMatch( /Malformed/, ); await expect( - getHeaders("localhost", "printf ' =foo'", logger), - ).rejects.toMatch(/Malformed/); - await expect( - getHeaders("localhost", "printf 'foo =bar'", logger), - ).rejects.toMatch(/Malformed/); - await expect( - getHeaders("localhost", "printf 'foo foo=bar'", logger), + getHeaders("localhost", "printf 'foo foo=bar'"), ).rejects.toMatch(/Malformed/); }); @@ -92,13 +100,12 @@ it("should have access to environment variables", async () => { os.platform() === "win32" ? "printf url=%CODER_URL%" : "printf url=$CODER_URL", - logger, ), ).resolves.toStrictEqual({ url: coderUrl }); }); it("should error on non-zero exit", async () => { - await expect(getHeaders("localhost", "exit 10", logger)).rejects.toMatch( + await expect(getHeaders("localhost", "exit 10")).rejects.toMatch( /exited unexpectedly with code 10/, ); }); diff --git a/src/headers.ts b/src/headers.ts index 4d4b5f44..aa549f1b 100644 --- a/src/headers.ts +++ b/src/headers.ts @@ -2,12 +2,9 @@ import * as cp from "child_process"; import * as os from "os"; import * as util from "util"; import type { WorkspaceConfiguration } from "vscode"; +import { logger } from "./logger"; import { escapeCommandArg } from "./util"; -export interface Logger { - writeToCoderOutputChannel(message: string): void; -} - interface ExecException { code?: number; stderr?: string; @@ -59,7 +56,6 @@ export function getHeaderArgs(config: WorkspaceConfiguration): string[] { export async function getHeaders( url: string | undefined, command: string | undefined, - logger: Logger, ): Promise> { const headers: Record = {}; if ( @@ -78,11 +74,11 @@ export async function getHeaders( }); } catch (error) { if (isExecException(error)) { - logger.writeToCoderOutputChannel( + logger.info( `Header command exited unexpectedly with code ${error.code}`, ); - logger.writeToCoderOutputChannel(`stdout: ${error.stdout}`); - logger.writeToCoderOutputChannel(`stderr: ${error.stderr}`); + logger.info(`stdout: ${error.stdout}`); + logger.info(`stderr: ${error.stderr}`); throw new Error( `Header command exited unexpectedly with code ${error.code}`, ); diff --git a/src/inbox.ts b/src/inbox.ts index 709dfbd8..bdc3ec9b 100644 --- a/src/inbox.ts +++ b/src/inbox.ts @@ -8,6 +8,7 @@ import * as vscode from "vscode"; import { WebSocket } from "ws"; import { coderSessionTokenHeader } from "./api"; import { errToStr } from "./api-helper"; +import { logger } from "./logger"; import { type Storage } from "./storage"; // These are the template IDs of our notifications. @@ -63,7 +64,7 @@ export class Inbox implements vscode.Disposable { }); this.#socket.on("open", () => { - this.#storage.writeToCoderOutputChannel("Listening to Coder Inbox"); + logger.debug("Listening to Coder Inbox"); }); this.#socket.on("error", (error) => { @@ -86,9 +87,7 @@ export class Inbox implements vscode.Disposable { dispose() { if (!this.#disposed) { - this.#storage.writeToCoderOutputChannel( - "No longer listening to Coder Inbox", - ); + logger.debug("No longer listening to Coder Inbox"); this.#socket.close(); this.#disposed = true; } @@ -99,6 +98,6 @@ export class Inbox implements vscode.Disposable { error, "Got empty error while monitoring Coder Inbox", ); - this.#storage.writeToCoderOutputChannel(message); + logger.debug(message); } } diff --git a/src/logger.test.ts b/src/logger.test.ts new file mode 100644 index 00000000..8830d093 --- /dev/null +++ b/src/logger.test.ts @@ -0,0 +1,476 @@ +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; + +// Mock vscode module before importing logger +vi.mock("vscode", () => ({ + workspace: { + getConfiguration: vi.fn().mockReturnValue({ + get: vi.fn().mockReturnValue(false), + }), + onDidChangeConfiguration: vi.fn().mockReturnValue({ + dispose: vi.fn(), + }), + }, + Disposable: class { + dispose = vi.fn(); + }, +})); + +import * as vscode from "vscode"; +import { + ArrayAdapter, + LogLevel, + NoOpAdapter, + OutputChannelAdapter, + logger, +} from "./logger"; + +describe("Logger", () => { + beforeEach(() => { + process.env.NODE_ENV = "test"; + logger.reset(); + }); + + afterEach(() => { + logger.reset(); + vi.clearAllMocks(); + }); + + describe("ArrayAdapter", () => { + it("should store messages in array", () => { + const adapter = new ArrayAdapter(); + adapter.write("test message 1"); + adapter.write("test message 2"); + + const snapshot = adapter.getSnapshot(); + expect(snapshot).toEqual(["test message 1", "test message 2"]); + }); + + it("should clear messages", () => { + const adapter = new ArrayAdapter(); + adapter.write("test message"); + adapter.clear(); + + const snapshot = adapter.getSnapshot(); + expect(snapshot).toEqual([]); + }); + + it("should return immutable snapshot", () => { + const adapter = new ArrayAdapter(); + adapter.write("test message"); + + const snapshot1 = adapter.getSnapshot(); + const snapshot2 = adapter.getSnapshot(); + + expect(snapshot1).not.toBe(snapshot2); + expect(snapshot1).toEqual(snapshot2); + }); + }); + + describe("OutputChannelAdapter", () => { + it("should write to output channel", () => { + const mockChannel = { + appendLine: vi.fn(), + clear: vi.fn(), + } as unknown as vscode.OutputChannel; + + const adapter = new OutputChannelAdapter(mockChannel); + adapter.write("test message"); + + expect(mockChannel.appendLine).toHaveBeenCalledWith("test message"); + }); + + it("should clear output channel", () => { + const mockChannel = { + appendLine: vi.fn(), + clear: vi.fn(), + } as unknown as vscode.OutputChannel; + + const adapter = new OutputChannelAdapter(mockChannel); + adapter.clear(); + + expect(mockChannel.clear).toHaveBeenCalled(); + }); + + it("should not throw if output channel is disposed", () => { + const mockChannel = { + appendLine: vi.fn().mockImplementation(() => { + throw new Error("Channel disposed"); + }), + clear: vi.fn().mockImplementation(() => { + throw new Error("Channel disposed"); + }), + } as unknown as vscode.OutputChannel; + + const adapter = new OutputChannelAdapter(mockChannel); + + expect(() => adapter.write("test")).not.toThrow(); + expect(() => adapter.clear()).not.toThrow(); + }); + }); + + describe("NoOpAdapter", () => { + it("should do nothing", () => { + const adapter = new NoOpAdapter(); + expect(() => adapter.write("test")).not.toThrow(); + expect(() => adapter.clear()).not.toThrow(); + }); + }); + + describe("Logger core functionality", () => { + it("should format info messages correctly", () => { + const adapter = new ArrayAdapter(); + logger.setAdapter(adapter); + + const beforeTime = new Date().toISOString(); + logger.info("Test info message"); + const afterTime = new Date().toISOString(); + + const logs = adapter.getSnapshot(); + expect(logs).toHaveLength(1); + + const logMatch = logs[0].match(/\[info\] (\S+) Test info message/); + expect(logMatch).toBeTruthy(); + + const timestamp = logMatch![1]; + expect(timestamp >= beforeTime).toBe(true); + expect(timestamp <= afterTime).toBe(true); + }); + + it("should format debug messages correctly", () => { + const adapter = new ArrayAdapter(); + logger.setAdapter(adapter); + logger.setLevel(LogLevel.DEBUG); + + logger.debug("Test debug message"); + + const logs = adapter.getSnapshot(); + expect(logs).toHaveLength(1); + expect(logs[0]).toMatch(/\[debug\] \S+ Test debug message/); + }); + + it("should include source location in debug messages when verbose", () => { + const adapter = new ArrayAdapter(); + logger.setAdapter(adapter); + logger.setLevel(LogLevel.DEBUG); + + logger.debug("Test debug with location"); + + const logs = adapter.getSnapshot(); + expect(logs).toHaveLength(1); + expect(logs[0]).toContain("[debug]"); + expect(logs[0]).toContain("Test debug with location"); + // Should contain source location - may be in either format + expect(logs[0]).toMatch(/\n\s+at .+:\d+|\n\s+at .+ \(.+:\d+\)/); + }); + + it("should respect log levels", () => { + const adapter = new ArrayAdapter(); + logger.setAdapter(adapter); + logger.setLevel(LogLevel.INFO); + + logger.debug("Debug message"); + logger.info("Info message"); + + const logs = adapter.getSnapshot(); + expect(logs).toHaveLength(1); + expect(logs[0]).toContain("Info message"); + }); + + it("should handle NONE log level", () => { + const adapter = new ArrayAdapter(); + logger.setAdapter(adapter); + logger.setLevel(LogLevel.NONE); + + logger.debug("Debug message"); + logger.info("Info message"); + + const logs = adapter.getSnapshot(); + expect(logs).toHaveLength(0); + }); + }); + + 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 mockConfig = { + get: vi.fn().mockReturnValue(false), + }; + vi.mocked(vscode.workspace.getConfiguration).mockReturnValue( + mockConfig as unknown as vscode.WorkspaceConfiguration, + ); + + logger.reset(); + + // Change config to verbose + mockConfig.get.mockReturnValue(true); + configChangeCallback({ + affectsConfiguration: (section: string) => section === "coder.verbose", + } as vscode.ConfigurationChangeEvent); + + // Verify it reads the new config + expect(mockConfig.get).toHaveBeenCalledWith("verbose", false); + }); + + 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; + }, + ); + + const mockConfig = { + get: vi.fn().mockReturnValue(false), + }; + vi.mocked(vscode.workspace.getConfiguration).mockReturnValue( + mockConfig as unknown as vscode.WorkspaceConfiguration, + ); + + logger.reset(); + mockConfig.get.mockClear(); + + // Trigger non-verbose config change + configChangeCallback({ + affectsConfiguration: (section: string) => section === "other.setting", + } as vscode.ConfigurationChangeEvent); + + // Should not re-read config + expect(mockConfig.get).not.toHaveBeenCalled(); + }); + }); + + describe("Adapter management", () => { + it("should throw when setAdapter called in non-test environment", () => { + const originalEnv = process.env.NODE_ENV; + process.env.NODE_ENV = "production"; + try { + expect(() => logger.setAdapter(new ArrayAdapter())).toThrow( + "setAdapter can only be called in test environment", + ); + } finally { + process.env.NODE_ENV = originalEnv; + } + }); + + it("should throw when reset called in non-test environment", () => { + const originalEnv = process.env.NODE_ENV; + process.env.NODE_ENV = "production"; + try { + expect(() => logger.reset()).toThrow( + "reset can only be called in test environment", + ); + } finally { + process.env.NODE_ENV = originalEnv; + } + }); + + it("should throw when adapter already set", () => { + logger.setAdapter(new ArrayAdapter()); + expect(() => logger.setAdapter(new ArrayAdapter())).toThrow( + "Adapter already set. Use reset() first or withAdapter() for temporary changes", + ); + }); + + it("should allow temporary adapter changes with withAdapter", () => { + const adapter1 = new ArrayAdapter(); + const adapter2 = new ArrayAdapter(); + + logger.setAdapter(adapter1); + logger.info("Message 1"); + + const result = logger.withAdapter(adapter2, () => { + logger.info("Message 2"); + return "test result"; + }); + + logger.info("Message 3"); + + expect(result).toBe("test result"); + expect(adapter1.getSnapshot()).toEqual( + expect.arrayContaining([ + expect.stringContaining("Message 1"), + expect.stringContaining("Message 3"), + ]), + ); + expect(adapter2.getSnapshot()).toEqual( + expect.arrayContaining([expect.stringContaining("Message 2")]), + ); + }); + + it("should restore adapter even if function throws", () => { + const adapter1 = new ArrayAdapter(); + const adapter2 = new ArrayAdapter(); + + logger.setAdapter(adapter1); + + expect(() => + logger.withAdapter(adapter2, () => { + throw new Error("Test error"); + }), + ).toThrow("Test error"); + + logger.info("After error"); + expect(adapter1.getSnapshot()).toEqual( + expect.arrayContaining([expect.stringContaining("After error")]), + ); + expect(adapter2.getSnapshot()).toHaveLength(0); + }); + + it("should dispose configuration listener on reset", () => { + const mockDisposable = { dispose: vi.fn() }; + vi.mocked(vscode.workspace.onDidChangeConfiguration).mockReturnValue( + mockDisposable as unknown as vscode.Disposable, + ); + + logger.reset(); + logger.reset(); // Second reset should dispose the first listener + + expect(mockDisposable.dispose).toHaveBeenCalled(); + }); + }); + + describe("Initialize", () => { + it("should initialize with OutputChannel", () => { + const mockChannel = { + appendLine: vi.fn(), + clear: vi.fn(), + } as unknown as vscode.OutputChannel; + + logger.initialize(mockChannel); + + // Verify we can log after initialization + logger.info("Test message"); + expect(mockChannel.appendLine).toHaveBeenCalled(); + }); + + it("should throw if already initialized", () => { + const mockChannel = {} as vscode.OutputChannel; + logger.initialize(mockChannel); + + expect(() => logger.initialize(mockChannel)).toThrow( + "Logger already initialized", + ); + }); + }); + + describe("Performance", () => { + it("should have minimal overhead for disabled debug calls", () => { + const noOpAdapter = new NoOpAdapter(); + const arrayAdapter = new ArrayAdapter(); + + // Measure NoOp baseline + logger.setAdapter(noOpAdapter); + logger.setLevel(LogLevel.INFO); // Debug disabled + + const noOpStart = performance.now(); + for (let i = 0; i < 10000; i++) { + logger.debug(`Debug message ${i}`); + } + const noOpTime = performance.now() - noOpStart; + + // Measure with ArrayAdapter + logger.reset(); + logger.setAdapter(arrayAdapter); + logger.setLevel(LogLevel.INFO); // Debug disabled + + const arrayStart = performance.now(); + for (let i = 0; i < 10000; i++) { + logger.debug(`Debug message ${i}`); + } + const arrayTime = performance.now() - arrayStart; + + // Should have less than 10% overhead when disabled + const overhead = (arrayTime - noOpTime) / noOpTime; + expect(overhead).toBeLessThan(0.1); + expect(arrayAdapter.getSnapshot()).toHaveLength(0); // No messages logged + }); + + it("should have acceptable overhead for enabled debug calls", () => { + const noOpAdapter = new NoOpAdapter(); + const arrayAdapter = new ArrayAdapter(); + + // Measure NoOp baseline + logger.setAdapter(noOpAdapter); + logger.setLevel(LogLevel.DEBUG); // Debug enabled + + const noOpStart = performance.now(); + for (let i = 0; i < 1000; i++) { + logger.debug(`Debug message ${i}`); + } + const noOpTime = performance.now() - noOpStart; + + // Measure with ArrayAdapter + logger.reset(); + logger.setAdapter(arrayAdapter); + logger.setLevel(LogLevel.DEBUG); // Debug enabled + + const arrayStart = performance.now(); + for (let i = 0; i < 1000; i++) { + logger.debug(`Debug message ${i}`); + } + const arrayTime = performance.now() - arrayStart; + + // Should have less than 10x overhead when enabled + const overhead = arrayTime / noOpTime; + expect(overhead).toBeLessThan(10); + expect(arrayAdapter.getSnapshot()).toHaveLength(1000); // All messages logged + }); + + it("should have acceptable overhead for info calls", () => { + const noOpAdapter = new NoOpAdapter(); + const arrayAdapter = new ArrayAdapter(); + + // Measure NoOp baseline + logger.setAdapter(noOpAdapter); + + const noOpStart = performance.now(); + for (let i = 0; i < 1000; i++) { + logger.info(`Info message ${i}`); + } + const noOpTime = performance.now() - noOpStart; + + // Measure with ArrayAdapter + logger.reset(); + logger.setAdapter(arrayAdapter); + + const arrayStart = performance.now(); + for (let i = 0; i < 1000; i++) { + logger.info(`Info message ${i}`); + } + const arrayTime = performance.now() - arrayStart; + + // Should have less than 5x overhead for info + const overhead = arrayTime / noOpTime; + expect(overhead).toBeLessThan(5); + expect(arrayAdapter.getSnapshot()).toHaveLength(1000); // All messages logged + }); + }); +}); diff --git a/src/logger.ts b/src/logger.ts new file mode 100644 index 00000000..a1b8757d --- /dev/null +++ b/src/logger.ts @@ -0,0 +1,198 @@ +import * as vscode from "vscode"; + +export enum LogLevel { + DEBUG = 0, + INFO = 1, + NONE = 2, +} + +export interface LogAdapter { + write(message: string): void; + clear(): void; +} + +export class OutputChannelAdapter implements LogAdapter { + constructor(private outputChannel: vscode.OutputChannel) {} + + write(message: string): void { + try { + this.outputChannel.appendLine(message); + } catch { + // Silently ignore - channel may be disposed + } + } + + clear(): void { + try { + this.outputChannel.clear(); + } catch { + // Silently ignore - channel may be disposed + } + } +} + +export class ArrayAdapter implements LogAdapter { + private logs: string[] = []; + + write(message: string): void { + this.logs.push(message); + } + + clear(): void { + this.logs = []; + } + + getSnapshot(): readonly string[] { + return [...this.logs]; + } +} + +export class NoOpAdapter implements LogAdapter { + // eslint-disable-next-line @typescript-eslint/no-unused-vars + write(_message: string): void { + // Intentionally empty - baseline for performance tests + } + + clear(): void { + // Intentionally empty - baseline for performance tests + } +} + +class LoggerImpl { + private adapter: LogAdapter | null = null; + private level: LogLevel = LogLevel.INFO; + private configListener: vscode.Disposable | null = null; + + constructor() { + this.updateLogLevel(); + this.setupConfigListener(); + } + + private setupConfigListener(): void { + // In test environment, vscode.workspace might not be available + if (!vscode.workspace?.onDidChangeConfiguration) { + return; + } + this.configListener = vscode.workspace.onDidChangeConfiguration((e) => { + if (e.affectsConfiguration("coder.verbose")) { + this.updateLogLevel(); + } + }); + } + + private updateLogLevel(): void { + // In test environment, vscode.workspace might not be available + if (!vscode.workspace?.getConfiguration) { + this.level = LogLevel.INFO; + return; + } + const config = vscode.workspace.getConfiguration("coder"); + const verbose = config.get("verbose", false); + this.level = verbose ? LogLevel.DEBUG : LogLevel.INFO; + } + + private formatMessage(message: string, level: LogLevel): string { + const levelStr = LogLevel[level].toLowerCase(); + const timestamp = new Date().toISOString(); + let formatted = `[${levelStr}] ${timestamp} ${message}`; + + // Add source location for debug messages when verbose is enabled + if (level === LogLevel.DEBUG && this.level === LogLevel.DEBUG) { + const stack = new Error().stack; + if (stack) { + const lines = stack.split("\n"); + // Find the first line that's not from the logger itself + for (let i = 2; i < lines.length; i++) { + const line = lines[i]; + if (!line.includes("logger.ts") && !line.includes("Logger.")) { + const match = + line.match(/at\s+(.+)\s+\((.+):(\d+):(\d+)\)/) || + line.match(/at\s+(.+):(\d+):(\d+)/); + if (match) { + const location = + match.length === 5 + ? `${match[1]} (${match[2]}:${match[3]})` + : `${match[1]}:${match[2]}`; + formatted += `\n at ${location}`; + } + break; + } + } + } + } + + return formatted; + } + + log(message: string, severity: LogLevel = LogLevel.INFO): void { + if (!this.adapter || severity < this.level) { + return; + } + + const formatted = this.formatMessage(message, severity); + this.adapter.write(formatted); + } + + debug(message: string): void { + this.log(message, LogLevel.DEBUG); + } + + info(message: string): void { + this.log(message, LogLevel.INFO); + } + + setLevel(level: LogLevel): void { + this.level = level; + } + + setAdapter(adapter: LogAdapter): void { + if (process.env.NODE_ENV !== "test") { + throw new Error("setAdapter can only be called in test environment"); + } + if (this.adapter !== null) { + throw new Error( + "Adapter already set. Use reset() first or withAdapter() for temporary changes", + ); + } + this.adapter = adapter; + } + + withAdapter(adapter: LogAdapter, fn: () => T): T { + const previous = this.adapter; + this.adapter = adapter; + try { + return fn(); + } finally { + this.adapter = previous; + } + } + + reset(): void { + if (process.env.NODE_ENV !== "test") { + throw new Error("reset can only be called in test environment"); + } + this.adapter = null; + this.level = LogLevel.INFO; + if (this.configListener) { + this.configListener.dispose(); + this.configListener = null; + } + // Re-setup config listener for next test + this.updateLogLevel(); + this.setupConfigListener(); + } + + // Initialize with OutputChannel for production use + initialize(outputChannel: vscode.OutputChannel): void { + if (this.adapter !== null) { + throw new Error("Logger already initialized"); + } + this.adapter = new OutputChannelAdapter(outputChannel); + } +} + +// Export singleton instance +export const logger = new LoggerImpl(); + +// Export types for testing +export type Logger = typeof logger; diff --git a/src/remote.ts b/src/remote.ts index 4a13ae56..657cc5e9 100644 --- a/src/remote.ts +++ b/src/remote.ts @@ -22,6 +22,7 @@ import { Commands } from "./commands"; import { featureSetForVersion, FeatureSet } from "./featureSet"; import { getHeaderArgs } from "./headers"; import { Inbox } from "./inbox"; +import { logger } from "./logger"; import { SSHConfig, SSHValues, mergeSSHConfigValues } from "./sshConfig"; import { computeSSHProperties, sshSupportsSetEnv } from "./sshSupport"; import { Storage } from "./storage"; @@ -117,9 +118,7 @@ export class Remote { case "starting": case "stopping": writeEmitter = initWriteEmitterAndTerminal(); - this.storage.writeToCoderOutputChannel( - `Waiting for ${workspaceName}...`, - ); + logger.debug(`Waiting for ${workspaceName}...`); workspace = await waitForBuild( restClient, writeEmitter, @@ -131,9 +130,7 @@ export class Remote { return undefined; } writeEmitter = initWriteEmitterAndTerminal(); - this.storage.writeToCoderOutputChannel( - `Starting ${workspaceName}...`, - ); + logger.info(`Starting ${workspaceName}...`); workspace = await startWorkspaceIfStoppedOrFailed( restClient, globalConfigDir, @@ -150,9 +147,7 @@ export class Remote { return undefined; } writeEmitter = initWriteEmitterAndTerminal(); - this.storage.writeToCoderOutputChannel( - `Starting ${workspaceName}...`, - ); + logger.info(`Starting ${workspaceName}...`); workspace = await startWorkspaceIfStoppedOrFailed( restClient, globalConfigDir, @@ -175,7 +170,7 @@ export class Remote { ); } } - this.storage.writeToCoderOutputChannel( + logger.debug( `${workspaceName} status is now ${workspace.latest_build.status}`, ); } @@ -243,12 +238,8 @@ export class Remote { return; } - this.storage.writeToCoderOutputChannel( - `Using deployment URL: ${baseUrlRaw}`, - ); - this.storage.writeToCoderOutputChannel( - `Using deployment label: ${parts.label || "n/a"}`, - ); + logger.info(`Using deployment URL: ${baseUrlRaw}`); + logger.debug(`Using deployment label: ${parts.label || "n/a"}`); // We could use the plugin client, but it is possible for the user to log // out or log into a different deployment while still connected, which would @@ -314,14 +305,12 @@ export class Remote { // Next is to find the workspace from the URI scheme provided. let workspace: Workspace; try { - this.storage.writeToCoderOutputChannel( - `Looking for workspace ${workspaceName}...`, - ); + logger.debug(`Looking for workspace ${workspaceName}...`); workspace = await workspaceRestClient.getWorkspaceByOwnerAndName( parts.username, parts.workspace, ); - this.storage.writeToCoderOutputChannel( + logger.info( `Found workspace ${workspaceName} with status ${workspace.latest_build.status}`, ); this.commands.workspace = workspace; @@ -404,9 +393,7 @@ export class Remote { this.commands.workspace = workspace; // Pick an agent. - this.storage.writeToCoderOutputChannel( - `Finding agent for ${workspaceName}...`, - ); + logger.debug(`Finding agent for ${workspaceName}...`); const gotAgent = await this.commands.maybeAskAgent(workspace, parts.agent); if (!gotAgent) { // User declined to pick an agent. @@ -414,12 +401,10 @@ export class Remote { return; } let agent = gotAgent; // Reassign so it cannot be undefined in callbacks. - this.storage.writeToCoderOutputChannel( - `Found agent ${agent.name} with status ${agent.status}`, - ); + logger.info(`Found agent ${agent.name} with status ${agent.status}`); // Do some janky setting manipulation. - this.storage.writeToCoderOutputChannel("Modifying settings..."); + logger.debug("Modifying settings..."); const remotePlatforms = this.vscodeProposed.workspace .getConfiguration() .get>("remote.SSH.remotePlatform", {}); @@ -491,9 +476,7 @@ export class Remote { // write here is not necessarily catastrophic since the user will be // asked for the platform and the default timeout might be sufficient. mungedPlatforms = mungedConnTimeout = false; - this.storage.writeToCoderOutputChannel( - `Failed to configure settings: ${ex}`, - ); + logger.info(`Failed to configure settings: ${ex}`); } } @@ -521,9 +504,7 @@ export class Remote { // Wait for the agent to connect. if (agent.status === "connecting") { - this.storage.writeToCoderOutputChannel( - `Waiting for ${workspaceName}/${agent.name}...`, - ); + logger.debug(`Waiting for ${workspaceName}/${agent.name}...`); await vscode.window.withProgress( { title: "Waiting for the agent to connect...", @@ -552,9 +533,7 @@ export class Remote { }); }, ); - this.storage.writeToCoderOutputChannel( - `Agent ${agent.name} status is now ${agent.status}`, - ); + logger.info(`Agent ${agent.name} status is now ${agent.status}`); } // Make sure the agent is connected. @@ -584,7 +563,7 @@ export class Remote { // If we didn't write to the SSH config file, connecting would fail with // "Host not found". try { - this.storage.writeToCoderOutputChannel("Updating SSH config..."); + logger.debug("Updating SSH config..."); await this.updateSSHConfig( workspaceRestClient, parts.label, @@ -594,9 +573,7 @@ export class Remote { featureSet, ); } catch (error) { - this.storage.writeToCoderOutputChannel( - `Failed to configure SSH: ${error}`, - ); + logger.info(`Failed to configure SSH: ${error}`); throw error; } @@ -633,7 +610,7 @@ export class Remote { }), ); - this.storage.writeToCoderOutputChannel("Remote setup complete"); + logger.info("Remote setup complete"); // Returning the URL and token allows the plugin to authenticate its own // client, for example to display the list of workspaces belonging to this @@ -674,9 +651,7 @@ export class Remote { return ""; } await fs.mkdir(logDir, { recursive: true }); - this.storage.writeToCoderOutputChannel( - `SSH proxy diagnostics are being written to ${logDir}`, - ); + logger.info(`SSH proxy diagnostics are being written to ${logDir}`); return ` --log-dir ${escapeCommandArg(logDir)}`; } diff --git a/src/storage.ts b/src/storage.ts index 8453bc5d..8c981169 100644 --- a/src/storage.ts +++ b/src/storage.ts @@ -8,6 +8,7 @@ import * as vscode from "vscode"; import { errToStr } from "./api-helper"; import * as cli from "./cliManager"; import { getHeaderCommand, getHeaders } from "./headers"; +import { logger } from "./logger"; // Maximium number of recent URLs to store. const MAX_URLS = 10; @@ -507,12 +508,12 @@ export class Storage { : path.join(this.globalStorageUri.fsPath, "url"); } - public writeToCoderOutputChannel(message: string) { - this.output.appendLine(`[${new Date().toISOString()}] ${message}`); - // We don't want to focus on the output here, because the - // Coder server is designed to restart gracefully for users - // because of P2P connections, and we don't want to draw - // attention to it. + /** + * Compatibility method for Logger interface used by headers.ts and error.ts. + * Delegates to the logger module. + */ + public writeToCoderOutputChannel(message: string): void { + logger.info(message); } /** @@ -614,7 +615,6 @@ export class Storage { return getHeaders( url, getHeaderCommand(vscode.workspace.getConfiguration()), - this, ); } } diff --git a/src/workspaceMonitor.ts b/src/workspaceMonitor.ts index 18df50b2..a198efa1 100644 --- a/src/workspaceMonitor.ts +++ b/src/workspaceMonitor.ts @@ -5,6 +5,7 @@ import { EventSource } from "eventsource"; import * as vscode from "vscode"; import { createStreamingFetchAdapter } from "./api"; import { errToStr } from "./api-helper"; +import { logger } from "./logger"; import { Storage } from "./storage"; /** @@ -42,7 +43,7 @@ export class WorkspaceMonitor implements vscode.Disposable { this.name = `${workspace.owner_name}/${workspace.name}`; const url = this.restClient.getAxiosInstance().defaults.baseURL; const watchUrl = new URL(`${url}/api/v2/workspaces/${workspace.id}/watch`); - this.storage.writeToCoderOutputChannel(`Monitoring ${this.name}...`); + logger.debug(`Monitoring ${this.name}...`); const eventSource = new EventSource(watchUrl.toString(), { fetch: createStreamingFetchAdapter(this.restClient.getAxiosInstance()), @@ -85,7 +86,7 @@ export class WorkspaceMonitor implements vscode.Disposable { */ dispose() { if (!this.disposed) { - this.storage.writeToCoderOutputChannel(`Unmonitoring ${this.name}...`); + logger.debug(`Unmonitoring ${this.name}...`); this.statusBarItem.dispose(); this.eventSource.close(); this.disposed = true; @@ -202,7 +203,7 @@ export class WorkspaceMonitor implements vscode.Disposable { error, "Got empty error while monitoring workspace", ); - this.storage.writeToCoderOutputChannel(message); + logger.debug(message); } private updateContext(workspace: Workspace) { diff --git a/src/workspacesProvider.ts b/src/workspacesProvider.ts index a77b31ad..ec73e135 100644 --- a/src/workspacesProvider.ts +++ b/src/workspacesProvider.ts @@ -15,6 +15,7 @@ import { extractAgents, errToStr, } from "./api-helper"; +import { logger } from "./logger"; import { Storage } from "./storage"; export enum WorkspaceQuery { @@ -96,7 +97,7 @@ export class WorkspaceProvider */ private async fetch(): Promise { if (vscode.env.logLevel <= vscode.LogLevel.Debug) { - this.storage.writeToCoderOutputChannel( + logger.debug( `Fetching workspaces: ${this.getWorkspacesQuery || "no filter"}...`, ); } From 69951fe78c199e29d78f28e477363f5389cd7d20 Mon Sep 17 00:00:00 2001 From: Justin George Date: Wed, 2 Jul 2025 20:22:19 -0700 Subject: [PATCH 3/6] autoformat --- .claude/scopes/LoggingAdapter.md | 104 ++++++++++++++++--------------- 1 file changed, 54 insertions(+), 50 deletions(-) diff --git a/.claude/scopes/LoggingAdapter.md b/.claude/scopes/LoggingAdapter.md index 67d85a4d..2d6da3f3 100644 --- a/.claude/scopes/LoggingAdapter.md +++ b/.claude/scopes/LoggingAdapter.md @@ -20,7 +20,7 @@ The vscode-coder extension currently handles logging through the Storage class, - No `any` types in the logger module or modified files - No `@ts-ignore` or `eslint-disable` comments - All types explicitly defined or properly inferred -4. **Testable**: +4. **Testable**: - Unit tests use `ArrayAdapter` for fast, isolated testing - ArrayAdapter provides immutable snapshots via `getSnapshot()` to prevent test interference - Integration tests use `OutputChannelAdapter` to verify VS Code integration @@ -53,6 +53,7 @@ The vscode-coder extension currently handles logging through the Storage class, ## Scope & Constraints ### In Scope + - Extract logging functionality from the Storage class into a dedicated logging adapter - Create a logging adapter/service with support for debug and info levels - Convert all existing `writeToCoderOutputChannel` and `output.appendLine` calls to use the adapter @@ -69,6 +70,7 @@ The vscode-coder extension currently handles logging through the Storage class, - Remove only the `writeToCoderOutputChannel` method from Storage class ### Out of Scope + - External logging services integration (future enhancement) - File-based logging (all logs go to VS Code OutputChannel) - Log file rotation or persistence @@ -81,6 +83,7 @@ The vscode-coder extension currently handles logging through the Storage class, ## Technical Considerations ### Architecture + - Singleton pattern for the logger instance - Interface-based design with pluggable adapters: - `LogAdapter` interface for output handling @@ -106,80 +109,81 @@ The vscode-coder extension currently handles logging through the Storage class, - **Centralized formatting**: All log formatting (timestamps, level tags, source location) happens within the logger implementation, not at call sites ### API Design + ```typescript interface LogAdapter { - write(message: string): void - clear(): void + write(message: string): void; + clear(): void; } interface Logger { - log(message: string, severity?: LogLevel): void // Core method, defaults to INFO - debug(message: string): void // String only - no object serialization - info(message: string): void // String only - no object serialization - setLevel(level: LogLevel): void - setAdapter(adapter: LogAdapter): void // For testing only - throws if adapter already set - withAdapter(adapter: LogAdapter, fn: () => T): T // Safe temporary adapter swap - reset(): void // For testing only - throws if NODE_ENV !== 'test', disposes listeners + log(message: string, severity?: LogLevel): void; // Core method, defaults to INFO + debug(message: string): void; // String only - no object serialization + info(message: string): void; // String only - no object serialization + setLevel(level: LogLevel): void; + setAdapter(adapter: LogAdapter): void; // For testing only - throws if adapter already set + withAdapter(adapter: LogAdapter, fn: () => T): T; // Safe temporary adapter swap + reset(): void; // For testing only - throws if NODE_ENV !== 'test', disposes listeners } enum LogLevel { - DEBUG = 0, - INFO = 1, - NONE = 2 // Disables all logging + DEBUG = 0, + INFO = 1, + NONE = 2, // Disables all logging } // Example implementations class OutputChannelAdapter implements LogAdapter { - constructor(private outputChannel: vscode.OutputChannel) {} - write(message: string): void { - try { - this.outputChannel.appendLine(message) - } catch { - // Silently ignore - channel may be disposed - } - } - clear(): void { - try { - this.outputChannel.clear() - } catch { - // Silently ignore - channel may be disposed - } - } + constructor(private outputChannel: vscode.OutputChannel) {} + write(message: string): void { + try { + this.outputChannel.appendLine(message); + } catch { + // Silently ignore - channel may be disposed + } + } + clear(): void { + try { + this.outputChannel.clear(); + } catch { + // Silently ignore - channel may be disposed + } + } } class ArrayAdapter implements LogAdapter { - private logs: string[] = [] - - write(message: string): void { - this.logs.push(message) - } - - clear(): void { - this.logs = [] - } - - getSnapshot(): readonly string[] { - return [...this.logs] // Return defensive copy - } + private logs: string[] = []; + + write(message: string): void { + this.logs.push(message); + } + + clear(): void { + this.logs = []; + } + + getSnapshot(): readonly string[] { + return [...this.logs]; // Return defensive copy + } } class NoOpAdapter implements LogAdapter { - write(message: string): void { - // Intentionally empty - baseline for performance tests - } - - clear(): void { - // Intentionally empty - baseline for performance tests - } + write(message: string): void { + // Intentionally empty - baseline for performance tests + } + + clear(): void { + // Intentionally empty - baseline for performance tests + } } ``` ### Log Format + - **Standard format**: `[LEVEL] TIMESTAMP MESSAGE` - Timestamp in UTC ISO-8601 format (e.g., `2024-01-15T10:30:45.123Z`) - Example: `[info] 2024-01-15T10:30:45.123Z Starting extension...` - Example: `[debug] 2024-01-15T10:30:45.456Z Processing file: example.ts` - - **Debug mode enhancement**: When `coder.verbose` is true, debug logs include source location: ``` [debug] 2024-01-15T10:30:45.456Z Processing file: example.ts @@ -238,7 +242,7 @@ class NoOpAdapter implements LogAdapter { 9. Run linting (`yarn lint`) and ensure code quality ### File Locations + - Logger implementation: `src/logger.ts` - Tests: `src/logger.test.ts` - Type definitions included in the logger file - From 73b4458e65ae20ca09f64989889a08c1ca45f5d3 Mon Sep 17 00:00:00 2001 From: Justin George Date: Wed, 2 Jul 2025 20:41:03 -0700 Subject: [PATCH 4/6] Use universal info logging since existing logging is expected to be seen without config --- src/error.ts | 2 +- src/inbox.ts | 6 +++--- src/remote.ts | 16 ++++++++-------- src/workspaceMonitor.ts | 6 +++--- src/workspacesProvider.ts | 2 +- vitest.config.ts | 3 +++ 6 files changed, 19 insertions(+), 16 deletions(-) diff --git a/src/error.ts b/src/error.ts index 610ac546..e2ef93d4 100644 --- a/src/error.ts +++ b/src/error.ts @@ -55,7 +55,7 @@ export class CertificateError extends Error { await CertificateError.determineVerifyErrorCause(address); return new CertificateError(err.message, cause); } catch (error) { - logger.debug( + logger.info( `Failed to parse certificate from ${address}: ${error}`, ); break; diff --git a/src/inbox.ts b/src/inbox.ts index bdc3ec9b..a36ccc81 100644 --- a/src/inbox.ts +++ b/src/inbox.ts @@ -64,7 +64,7 @@ export class Inbox implements vscode.Disposable { }); this.#socket.on("open", () => { - logger.debug("Listening to Coder Inbox"); + logger.info("Listening to Coder Inbox"); }); this.#socket.on("error", (error) => { @@ -87,7 +87,7 @@ export class Inbox implements vscode.Disposable { dispose() { if (!this.#disposed) { - logger.debug("No longer listening to Coder Inbox"); + logger.info("No longer listening to Coder Inbox"); this.#socket.close(); this.#disposed = true; } @@ -98,6 +98,6 @@ export class Inbox implements vscode.Disposable { error, "Got empty error while monitoring Coder Inbox", ); - logger.debug(message); + logger.info(message); } } diff --git a/src/remote.ts b/src/remote.ts index 657cc5e9..6caebdcf 100644 --- a/src/remote.ts +++ b/src/remote.ts @@ -118,7 +118,7 @@ export class Remote { case "starting": case "stopping": writeEmitter = initWriteEmitterAndTerminal(); - logger.debug(`Waiting for ${workspaceName}...`); + logger.info(`Waiting for ${workspaceName}...`); workspace = await waitForBuild( restClient, writeEmitter, @@ -170,7 +170,7 @@ export class Remote { ); } } - logger.debug( + logger.info( `${workspaceName} status is now ${workspace.latest_build.status}`, ); } @@ -239,7 +239,7 @@ export class Remote { } logger.info(`Using deployment URL: ${baseUrlRaw}`); - logger.debug(`Using deployment label: ${parts.label || "n/a"}`); + logger.info(`Using deployment label: ${parts.label || "n/a"}`); // We could use the plugin client, but it is possible for the user to log // out or log into a different deployment while still connected, which would @@ -305,7 +305,7 @@ export class Remote { // Next is to find the workspace from the URI scheme provided. let workspace: Workspace; try { - logger.debug(`Looking for workspace ${workspaceName}...`); + logger.info(`Looking for workspace ${workspaceName}...`); workspace = await workspaceRestClient.getWorkspaceByOwnerAndName( parts.username, parts.workspace, @@ -393,7 +393,7 @@ export class Remote { this.commands.workspace = workspace; // Pick an agent. - logger.debug(`Finding agent for ${workspaceName}...`); + logger.info(`Finding agent for ${workspaceName}...`); const gotAgent = await this.commands.maybeAskAgent(workspace, parts.agent); if (!gotAgent) { // User declined to pick an agent. @@ -404,7 +404,7 @@ export class Remote { logger.info(`Found agent ${agent.name} with status ${agent.status}`); // Do some janky setting manipulation. - logger.debug("Modifying settings..."); + logger.info("Modifying settings..."); const remotePlatforms = this.vscodeProposed.workspace .getConfiguration() .get>("remote.SSH.remotePlatform", {}); @@ -504,7 +504,7 @@ export class Remote { // Wait for the agent to connect. if (agent.status === "connecting") { - logger.debug(`Waiting for ${workspaceName}/${agent.name}...`); + logger.info(`Waiting for ${workspaceName}/${agent.name}...`); await vscode.window.withProgress( { title: "Waiting for the agent to connect...", @@ -563,7 +563,7 @@ export class Remote { // If we didn't write to the SSH config file, connecting would fail with // "Host not found". try { - logger.debug("Updating SSH config..."); + logger.info("Updating SSH config..."); await this.updateSSHConfig( workspaceRestClient, parts.label, diff --git a/src/workspaceMonitor.ts b/src/workspaceMonitor.ts index a198efa1..23138035 100644 --- a/src/workspaceMonitor.ts +++ b/src/workspaceMonitor.ts @@ -43,7 +43,7 @@ export class WorkspaceMonitor implements vscode.Disposable { this.name = `${workspace.owner_name}/${workspace.name}`; const url = this.restClient.getAxiosInstance().defaults.baseURL; const watchUrl = new URL(`${url}/api/v2/workspaces/${workspace.id}/watch`); - logger.debug(`Monitoring ${this.name}...`); + logger.info(`Monitoring ${this.name}...`); const eventSource = new EventSource(watchUrl.toString(), { fetch: createStreamingFetchAdapter(this.restClient.getAxiosInstance()), @@ -86,7 +86,7 @@ export class WorkspaceMonitor implements vscode.Disposable { */ dispose() { if (!this.disposed) { - logger.debug(`Unmonitoring ${this.name}...`); + logger.info(`Unmonitoring ${this.name}...`); this.statusBarItem.dispose(); this.eventSource.close(); this.disposed = true; @@ -203,7 +203,7 @@ export class WorkspaceMonitor implements vscode.Disposable { error, "Got empty error while monitoring workspace", ); - logger.debug(message); + logger.info(message); } private updateContext(workspace: Workspace) { diff --git a/src/workspacesProvider.ts b/src/workspacesProvider.ts index ec73e135..08eb64ad 100644 --- a/src/workspacesProvider.ts +++ b/src/workspacesProvider.ts @@ -97,7 +97,7 @@ export class WorkspaceProvider */ private async fetch(): Promise { if (vscode.env.logLevel <= vscode.LogLevel.Debug) { - logger.debug( + logger.info( `Fetching workspaces: ${this.getWorkspacesQuery || "no filter"}...`, ); } diff --git a/vitest.config.ts b/vitest.config.ts index 2007fb45..8e8b254c 100644 --- a/vitest.config.ts +++ b/vitest.config.ts @@ -13,5 +13,8 @@ export default defineConfig({ "./src/test/**", ], environment: "node", + env: { + NODE_ENV: "test", + }, }, }); From 21357002dd1c36ae74bdc1cbf1eff145d970c2d9 Mon Sep 17 00:00:00 2001 From: Justin George Date: Wed, 2 Jul 2025 20:46:47 -0700 Subject: [PATCH 5/6] Remove spec file and update gitignore (mac cruft) --- .claude/scopes/LoggingAdapter.md | 248 ------------------------------- .gitignore | 1 + 2 files changed, 1 insertion(+), 248 deletions(-) delete mode 100644 .claude/scopes/LoggingAdapter.md diff --git a/.claude/scopes/LoggingAdapter.md b/.claude/scopes/LoggingAdapter.md deleted file mode 100644 index 2d6da3f3..00000000 --- a/.claude/scopes/LoggingAdapter.md +++ /dev/null @@ -1,248 +0,0 @@ -# Logging Adapter Specification - -## Purpose & User Problem - -The vscode-coder extension currently handles logging through the Storage class, where logging functionality is commingled with storage concerns. The `writeToCoderOutputChannel` method exists in the Storage class alongside file system operations, secret management, and other unrelated functionality. This makes it difficult to: - -- **Debug user-reported issues**: When users report bugs, especially client connection issues that don't reproduce locally, there's no consistent way to enable detailed logging to help diagnose the problem -- **Centralize logging logic**: Logging is tied to the Storage class, which also manages secrets, URLs, CLI binaries, and file operations - a clear violation of single responsibility -- **Control verbosity**: Users can't easily enable debug-level logging when needed without modifying code -- **Standardize output**: While `writeToCoderOutputChannel` adds timestamps, other parts use direct `output.appendLine` calls -- **Expand debugging capabilities**: Adding new diagnostic logging for specific subsystems (like client connections) requires passing the Storage instance around -- **Maintain separation of concerns**: The Storage class has become a "god object" that handles too many responsibilities - -## Success Criteria - -1. **Centralized Logging**: All log output goes through a single adapter -2. **Log Levels**: Support for `debug` and `info` levels - - Additional levels can be added in future iterations -3. **Type Safety**: Fully typed TypeScript implementation - - No `any` types in the logger module or modified files - - No `@ts-ignore` or `eslint-disable` comments - - All types explicitly defined or properly inferred -4. **Testable**: - - Unit tests use `ArrayAdapter` for fast, isolated testing - - ArrayAdapter provides immutable snapshots via `getSnapshot()` to prevent test interference - - Integration tests use `OutputChannelAdapter` to verify VS Code integration - - Test isolation for concurrent test suites: - - `setAdapter()` throws if adapter already set (prevents test conflicts) - - `withAdapter()` provides safe temporary adapter swapping with automatic revert - - Ideal for Vitest's concurrent test execution - - `reset()` and `setAdapter()` methods restricted to test environment (NODE_ENV === 'test') - - `reset()` properly disposes of configuration change listeners to prevent memory leaks - - Methods throw error if called in production for safety -5. **Performance**: Minimal overhead for logging operations - - Measured relative to a no-op adapter baseline - - Debug calls when disabled: < 10% overhead vs no-op - - Debug calls when enabled: < 10x overhead vs no-op (including formatting) - - Info calls: < 5x overhead vs no-op - - Measurement methodology: - - Use `performance.now()` from Node's `perf_hooks` - - Compare against `NoOpAdapter` that does nothing - - Run 10,000 iterations, discard outliers, use median - - CI passes if within percentage thresholds (not absolute times) -6. **Fault Tolerance**: Logger never throws exceptions - - Silently swallows OutputChannel errors (e.g., disposed channel on reload) - - Logging failures must not crash the extension - - No error propagation from the logging subsystem - - Accepts that OutputChannel writes may interleave under concurrent access -7. **Live Configuration**: Monitor `coder.verbose` setting changes without requiring extension restart - - Supports workspace, folder, and global configuration levels - - Uses the most specific configuration available - -## Scope & Constraints - -### In Scope - -- Extract logging functionality from the Storage class into a dedicated logging adapter -- Create a logging adapter/service with support for debug and info levels -- Convert all existing `writeToCoderOutputChannel` and `output.appendLine` calls to use the adapter -- Maintain integration with VS Code's OutputChannel ("Coder") - - OutputChannel is created in `extension.ts` and passed to both Logger and Storage - - Logger uses it for logging via OutputChannelAdapter - - Storage continues to use it for progress reporting (e.g., binary downloads) -- Provide a simple API for logging (e.g., `logger.debug("message")`, `logger.info("message")`) - - Callers only provide the message content, not formatting - - Only string messages accepted (no automatic object serialization) - - Callers must stringify objects/errors before logging (e.g., using template literals) -- Allow runtime configuration of log levels -- Handle all formatting (timestamps, level tags, etc.) within the logger -- Remove only the `writeToCoderOutputChannel` method from Storage class - -### Out of Scope - -- External logging services integration (future enhancement) -- File-based logging (all logs go to VS Code OutputChannel) -- Log file rotation or persistence -- Structured logging formats (JSON, etc.) -- Performance metrics or telemetry -- Custom UI for viewing logs (uses VS Code's built-in OutputChannel UI) -- Synchronization of concurrent writes (OutputChannel writes may interleave) -- Automatic object/error serialization (callers must convert to strings) - -## Technical Considerations - -### Architecture - -- Singleton pattern for the logger instance -- Interface-based design with pluggable adapters: - - `LogAdapter` interface for output handling - - `OutputChannelAdapter` for VS Code OutputChannel integration - - `ArrayAdapter` for testing (stores logs in memory) -- OutputChannel ownership and lifecycle: - - Created once in `extension.ts` activate method - - Passed to OutputChannelAdapter constructor - - Also passed to Storage for non-logging uses (progress reporting) - - Single channel shared between Logger and Storage - - Note: VS Code OutputChannel is async; concurrent writes may interleave - - This is acceptable for debugging/diagnostic purposes - - In browser/web extensions, OutputChannel maps to in-memory buffer (no file I/O) -- Configuration through VS Code settings: - - `coder.verbose`: boolean setting to enable debug logging (default: false) - - When true: shows debug level logs - - When false: shows info level and above only - - Respects workspace folder-specific settings (uses most specific configuration) -- Configuration monitoring using `vscode.workspace.onDidChangeConfiguration` - - Only responds to changes in `coder.verbose` specifically - - Ignores all other configuration changes to avoid unnecessary processing - - Updates when workspace folders are added/removed or active editor changes -- **Centralized formatting**: All log formatting (timestamps, level tags, source location) happens within the logger implementation, not at call sites - -### API Design - -```typescript -interface LogAdapter { - write(message: string): void; - clear(): void; -} - -interface Logger { - log(message: string, severity?: LogLevel): void; // Core method, defaults to INFO - debug(message: string): void; // String only - no object serialization - info(message: string): void; // String only - no object serialization - setLevel(level: LogLevel): void; - setAdapter(adapter: LogAdapter): void; // For testing only - throws if adapter already set - withAdapter(adapter: LogAdapter, fn: () => T): T; // Safe temporary adapter swap - reset(): void; // For testing only - throws if NODE_ENV !== 'test', disposes listeners -} - -enum LogLevel { - DEBUG = 0, - INFO = 1, - NONE = 2, // Disables all logging -} - -// Example implementations -class OutputChannelAdapter implements LogAdapter { - constructor(private outputChannel: vscode.OutputChannel) {} - write(message: string): void { - try { - this.outputChannel.appendLine(message); - } catch { - // Silently ignore - channel may be disposed - } - } - clear(): void { - try { - this.outputChannel.clear(); - } catch { - // Silently ignore - channel may be disposed - } - } -} - -class ArrayAdapter implements LogAdapter { - private logs: string[] = []; - - write(message: string): void { - this.logs.push(message); - } - - clear(): void { - this.logs = []; - } - - getSnapshot(): readonly string[] { - return [...this.logs]; // Return defensive copy - } -} - -class NoOpAdapter implements LogAdapter { - write(message: string): void { - // Intentionally empty - baseline for performance tests - } - - clear(): void { - // Intentionally empty - baseline for performance tests - } -} -``` - -### Log Format - -- **Standard format**: `[LEVEL] TIMESTAMP MESSAGE` - - Timestamp in UTC ISO-8601 format (e.g., `2024-01-15T10:30:45.123Z`) - - Example: `[info] 2024-01-15T10:30:45.123Z Starting extension...` - - Example: `[debug] 2024-01-15T10:30:45.456Z Processing file: example.ts` -- **Debug mode enhancement**: When `coder.verbose` is true, debug logs include source location: - ``` - [debug] 2024-01-15T10:30:45.456Z Processing file: example.ts - at processFile (src/utils/fileHandler.ts:45) - ``` - - Note: In browser/web extensions, `Error().stack` may be empty, disabling source location - -### Implementation Plan - -1. Create the logger module at `src/logger.ts` with: - - Singleton pattern implementation - - LogAdapter interface and implementations (OutputChannelAdapter, ArrayAdapter) - - Logger initialization accepts OutputChannel (not created internally) - - Configuration reading from VS Code settings (`coder.verbose`) - - Use `workspace.getConfiguration()` to respect folder-specific settings - - Configuration change listener using `workspace.onDidChangeConfiguration` - - Filter to only handle `coder.verbose` changes using `affectsConfiguration()` - - Re-read configuration on folder/editor changes to respect local settings - - Timestamp formatting in UTC ISO-8601 (using `new Date().toISOString()`) and level prefixes - - Debug mode with source location tracking (file/line info) - - Gracefully handle empty `Error().stack` in browser environments - - Test method guards: `reset()` and `setAdapter()` check `process.env.NODE_ENV === 'test'` - - `setAdapter()` throws if adapter already installed (prevents concurrent test conflicts) - - `withAdapter()` implementation: - ```typescript - withAdapter(adapter: LogAdapter, fn: () => T): T { - const previous = this.adapter - this.adapter = adapter - try { - return fn() - } finally { - this.adapter = previous - } - } - ``` - - `reset()` implementation must dispose configuration listener to prevent memory leaks -2. Create comprehensive tests at `src/logger.test.ts`: - - Unit tests using ArrayAdapter for logic testing - - Separate integration tests for OutputChannelAdapter - - Performance benchmarks: - - Create NoOpAdapter as baseline - - Measure relative performance using `performance.now()` - - Ensure overhead stays within specified percentages - - Test both cold and warm paths -3. Update `extension.ts`: - - Create OutputChannel in activate method - - Initialize Logger with OutputChannel via OutputChannelAdapter - - Continue passing OutputChannel to Storage (for progress reporting) -4. Extract and refactor the existing `writeToCoderOutputChannel` logic from Storage class -5. Remove ONLY the `writeToCoderOutputChannel` method from Storage (keep OutputChannel for other uses) -6. Systematically replace each `writeToCoderOutputChannel` call with appropriate logger methods -7. For `output.appendLine` calls in Storage, evaluate each: - - Logging messages → convert to logger calls - - Progress/status messages → keep as direct OutputChannel calls -8. Verify functionality with existing tests -9. Run linting (`yarn lint`) and ensure code quality - -### File Locations - -- Logger implementation: `src/logger.ts` -- Tests: `src/logger.test.ts` -- Type definitions included in the logger file diff --git a/.gitignore b/.gitignore index 75f80c5f..faf84830 100644 --- a/.gitignore +++ b/.gitignore @@ -6,3 +6,4 @@ /coverage/ *.vsix yarn-error.log +.DS_Store \ No newline at end of file From 991c6093ee9582fe4946f022d9eac0167b1a3894 Mon Sep 17 00:00:00 2001 From: Justin George Date: Wed, 2 Jul 2025 20:54:43 -0700 Subject: [PATCH 6/6] autoformat --- vitest.config.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/vitest.config.ts b/vitest.config.ts index 8e8b254c..11fbfa44 100644 --- a/vitest.config.ts +++ b/vitest.config.ts @@ -15,6 +15,6 @@ export default defineConfig({ environment: "node", env: { NODE_ENV: "test", - }, + }, }, });