diff --git a/CHANGELOG.md b/CHANGELOG.md index c09aea12..9127b22c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ ### Fixed - Logging in or out in one VS Code window now properly updates the authentication status in all other open windows. +- Fix an issue with JSON stringification errors occurring when logging circular objects. ### Added diff --git a/src/api/coderApi.ts b/src/api/coderApi.ts index 1d73ef00..1d523b60 100644 --- a/src/api/coderApi.ts +++ b/src/api/coderApi.ts @@ -1,4 +1,9 @@ -import { type AxiosInstance } from "axios"; +import { + type AxiosResponseHeaders, + type AxiosInstance, + type AxiosHeaders, + type AxiosResponseTransformer, +} from "axios"; import { Api } from "coder/site/src/api/api"; import { type GetInboxNotificationResponse, @@ -23,6 +28,7 @@ import { type RequestConfigWithMeta, HttpClientLogLevel, } from "../logging/types"; +import { sizeOf } from "../logging/utils"; import { WsLogger } from "../logging/wsLogger"; import { OneWayWebSocket, @@ -207,7 +213,24 @@ function addLoggingInterceptors(client: AxiosInstance, logger: Logger) { (config) => { const configWithMeta = config as RequestConfigWithMeta; configWithMeta.metadata = createRequestMeta(); - logRequest(logger, configWithMeta, getLogLevel()); + + config.transformRequest = [ + ...wrapRequestTransform( + config.transformRequest || client.defaults.transformRequest || [], + configWithMeta, + ), + (data) => { + // Log after setting the raw request size + logRequest(logger, configWithMeta, getLogLevel()); + return data; + }, + ]; + + config.transformResponse = wrapResponseTransform( + config.transformResponse || client.defaults.transformResponse || [], + configWithMeta, + ); + return config; }, (error: unknown) => { @@ -228,6 +251,59 @@ function addLoggingInterceptors(client: AxiosInstance, logger: Logger) { ); } +function wrapRequestTransform( + transformer: AxiosResponseTransformer | AxiosResponseTransformer[], + config: RequestConfigWithMeta, +): AxiosResponseTransformer[] { + return [ + (data: unknown, headers: AxiosHeaders) => { + const transformerArray = Array.isArray(transformer) + ? transformer + : [transformer]; + + // Transform the request first then get the size (measure what's sent over the wire) + const result = transformerArray.reduce( + (d, fn) => fn.call(config, d, headers), + data, + ); + + config.rawRequestSize = getSize(config.headers, result); + + return result; + }, + ]; +} + +function wrapResponseTransform( + transformer: AxiosResponseTransformer | AxiosResponseTransformer[], + config: RequestConfigWithMeta, +): AxiosResponseTransformer[] { + return [ + (data: unknown, headers: AxiosResponseHeaders, status?: number) => { + // Get the size before transforming the response (measure what's sent over the wire) + config.rawResponseSize = getSize(headers, data); + + const transformerArray = Array.isArray(transformer) + ? transformer + : [transformer]; + + return transformerArray.reduce( + (d, fn) => fn.call(config, d, headers, status), + data, + ); + }, + ]; +} + +function getSize(headers: AxiosHeaders, data: unknown): number | undefined { + const contentLength = headers["content-length"]; + if (contentLength !== undefined) { + return parseInt(contentLength, 10); + } + + return sizeOf(data); +} + function getLogLevel(): HttpClientLogLevel { const logLevelStr = vscode.workspace .getConfiguration() diff --git a/src/core/cliManager.ts b/src/core/cliManager.ts index 1bb0afa1..4e8833fe 100644 --- a/src/core/cliManager.ts +++ b/src/core/cliManager.ts @@ -267,7 +267,7 @@ export class CliManager { if (Number.isNaN(contentLength)) { this.output.warn( "Got invalid or missing content length", - rawContentLength, + rawContentLength ?? "", ); } else { this.output.info("Got content length", prettyBytes(contentLength)); diff --git a/src/logging/formatters.ts b/src/logging/formatters.ts index 1ad45231..8247f9b1 100644 --- a/src/logging/formatters.ts +++ b/src/logging/formatters.ts @@ -1,6 +1,8 @@ import prettyBytes from "pretty-bytes"; -import type { InternalAxiosRequestConfig } from "axios"; +import { safeStringify } from "./utils"; + +import type { AxiosRequestConfig } from "axios"; const SENSITIVE_HEADERS = ["Coder-Session-Token", "Proxy-Authorization"]; @@ -18,35 +20,14 @@ export function formatTime(ms: number): string { } export function formatMethod(method: string | undefined): string { - return (method ?? "GET").toUpperCase(); + return method?.toUpperCase() || "GET"; } -/** - * Formats content-length for display. Returns the header value if available, - * otherwise estimates size by serializing the data body (prefixed with ~). - */ -export function formatContentLength( - headers: Record, - data: unknown, -): string { - const len = headers["content-length"]; - if (len && typeof len === "string") { - const bytes = parseInt(len, 10); - return isNaN(bytes) ? "(?b)" : `(${prettyBytes(bytes)})`; - } - - // Estimate from data if no header - if (data !== undefined && data !== null) { - const estimated = Buffer.byteLength(JSON.stringify(data), "utf8"); - return `(~${prettyBytes(estimated)})`; - } - - return `(${prettyBytes(0)})`; +export function formatSize(size: number | undefined): string { + return size === undefined ? "(? B)" : `(${prettyBytes(size)})`; } -export function formatUri( - config: InternalAxiosRequestConfig | undefined, -): string { +export function formatUri(config: AxiosRequestConfig | undefined): string { return config?.url || ""; } @@ -66,7 +47,7 @@ export function formatHeaders(headers: Record): string { export function formatBody(body: unknown): string { if (body) { - return JSON.stringify(body); + return safeStringify(body) ?? ""; } else { return ""; } diff --git a/src/logging/httpLogger.ts b/src/logging/httpLogger.ts index 7e569cad..5634a165 100644 --- a/src/logging/httpLogger.ts +++ b/src/logging/httpLogger.ts @@ -5,9 +5,9 @@ import { getErrorDetail } from "../error"; import { formatBody, - formatContentLength, formatHeaders, formatMethod, + formatSize, formatTime, formatUri, } from "./formatters"; @@ -42,11 +42,10 @@ export function logRequest( return; } - const { requestId, method, url } = parseConfig(config); - const len = formatContentLength(config.headers, config.data); + const { requestId, method, url, requestSize } = parseConfig(config); const msg = [ - `→ ${shortId(requestId)} ${method} ${url} ${len}`, + `→ ${shortId(requestId)} ${method} ${url} ${requestSize}`, ...buildExtraLogs(config.headers, config.data, logLevel), ]; logger.trace(msg.join("\n")); @@ -64,11 +63,12 @@ export function logResponse( return; } - const { requestId, method, url, time } = parseConfig(response.config); - const len = formatContentLength(response.headers, response.data); + const { requestId, method, url, time, responseSize } = parseConfig( + response.config, + ); const msg = [ - `← ${shortId(requestId)} ${response.status} ${method} ${url} ${len} ${time}`, + `← ${shortId(requestId)} ${response.status} ${method} ${url} ${responseSize} ${time}`, ...buildExtraLogs(response.headers, response.data, logLevel), ]; logger.trace(msg.join("\n")); @@ -150,6 +150,8 @@ function parseConfig(config: RequestConfigWithMeta | undefined): { method: string; url: string; time: string; + requestSize: string; + responseSize: string; } { const meta = config?.metadata; return { @@ -157,5 +159,7 @@ function parseConfig(config: RequestConfigWithMeta | undefined): { method: formatMethod(config?.method), url: formatUri(config), time: meta ? formatTime(Date.now() - meta.startedAt) : "?ms", + requestSize: formatSize(config?.rawRequestSize), + responseSize: formatSize(config?.rawResponseSize), }; } diff --git a/src/logging/types.ts b/src/logging/types.ts index d1ee51ca..30837a0d 100644 --- a/src/logging/types.ts +++ b/src/logging/types.ts @@ -14,4 +14,6 @@ export interface RequestMeta { export type RequestConfigWithMeta = InternalAxiosRequestConfig & { metadata?: RequestMeta; + rawRequestSize?: number; + rawResponseSize?: number; }; diff --git a/src/logging/utils.ts b/src/logging/utils.ts index c371f65e..5deadaaf 100644 --- a/src/logging/utils.ts +++ b/src/logging/utils.ts @@ -1,21 +1,37 @@ import { Buffer } from "node:buffer"; import crypto from "node:crypto"; +import util from "node:util"; export function shortId(id: string): string { return id.slice(0, 8); } +export function createRequestId(): string { + return crypto.randomUUID().replace(/-/g, ""); +} + +/** + * Returns the byte size of the data if it can be determined from the data's intrinsic properties, + * otherwise returns undefined (e.g., for plain objects and arrays that would require serialization). + */ export function sizeOf(data: unknown): number | undefined { if (data === null || data === undefined) { return 0; } - if (typeof data === "string") { - return Buffer.byteLength(data); + if (typeof data === "boolean") { + return 4; + } + if (typeof data === "number") { + return 8; } - if (Buffer.isBuffer(data)) { - return data.length; + if (typeof data === "string" || typeof data === "bigint") { + return Buffer.byteLength(data.toString()); } - if (data instanceof ArrayBuffer || ArrayBuffer.isView(data)) { + if ( + Buffer.isBuffer(data) || + data instanceof ArrayBuffer || + ArrayBuffer.isView(data) + ) { return data.byteLength; } if ( @@ -28,6 +44,19 @@ export function sizeOf(data: unknown): number | undefined { return undefined; } -export function createRequestId(): string { - return crypto.randomUUID().replace(/-/g, ""); +export function safeStringify(data: unknown): string | null { + try { + return util.inspect(data, { + showHidden: false, + depth: Infinity, + maxArrayLength: Infinity, + maxStringLength: Infinity, + breakLength: Infinity, + compact: true, + getters: false, // avoid side-effects + }); + } catch { + // Should rarely happen but just in case + return null; + } } diff --git a/src/logging/wsLogger.ts b/src/logging/wsLogger.ts index b33118b7..fd6acd00 100644 --- a/src/logging/wsLogger.ts +++ b/src/logging/wsLogger.ts @@ -77,6 +77,6 @@ export class WsLogger { private formatBytes(): string { const bytes = prettyBytes(this.byteCount); - return this.unknownByteCount ? `>=${bytes}` : bytes; + return this.unknownByteCount ? `>= ${bytes}` : bytes; } } diff --git a/test/mocks/testHelpers.ts b/test/mocks/testHelpers.ts index 5cfe44e5..2ef46716 100644 --- a/test/mocks/testHelpers.ts +++ b/test/mocks/testHelpers.ts @@ -1,6 +1,8 @@ import { vi } from "vitest"; import * as vscode from "vscode"; +import { type Logger } from "@/logging/logger"; + /** * Mock configuration provider that integrates with the vscode workspace configuration mock. * Use this to set configuration values that will be returned by vscode.workspace.getConfiguration(). @@ -286,3 +288,13 @@ export class InMemorySecretStorage implements vscode.SecretStorage { this.listeners.forEach((listener) => listener(event)); } } + +export function createMockLogger(): Logger { + return { + trace: vi.fn(), + debug: vi.fn(), + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + }; +} diff --git a/test/unit/core/cliManager.test.ts b/test/unit/core/cliManager.test.ts index 2d76e8d4..3e1dfb0d 100644 --- a/test/unit/core/cliManager.test.ts +++ b/test/unit/core/cliManager.test.ts @@ -12,10 +12,10 @@ import * as vscode from "vscode"; import { CliManager } from "@/core/cliManager"; import * as cliUtils from "@/core/cliUtils"; import { PathResolver } from "@/core/pathResolver"; -import { type Logger } from "@/logging/logger"; import * as pgp from "@/pgp"; import { + createMockLogger, MockConfigurationProvider, MockProgressReporter, MockUserInteraction, @@ -625,16 +625,6 @@ describe("CliManager", () => { }); }); - function createMockLogger(): Logger { - return { - trace: vi.fn(), - debug: vi.fn(), - info: vi.fn(), - warn: vi.fn(), - error: vi.fn(), - }; - } - function createMockApi(version: string, url: string): Api { const axios = { defaults: { baseURL: url }, @@ -740,10 +730,11 @@ describe("CliManager", () => { content: string, options: { chunkSize?: number; delay?: number } = {}, ): IncomingMessage { - const { chunkSize = 8, delay = 0 } = options; + const { chunkSize = 8, delay = 1 } = options; const buffer = Buffer.from(content); let position = 0; + let closeCallback: ((...args: unknown[]) => void) | null = null; return { on: vi.fn((event: string, callback: (...args: unknown[]) => void) => { @@ -759,13 +750,20 @@ describe("CliManager", () => { callback(chunk); if (position < buffer.length) { setTimeout(sendChunk, delay); + } else { + // All chunks sent - use setImmediate to ensure close happens + // after all synchronous operations and I/O callbacks complete + setImmediate(() => { + if (closeCallback) { + closeCallback(); + } + }); } } }; setTimeout(sendChunk, delay); } else if (event === "close") { - // Just close after a delay - setTimeout(() => callback(), 10); + closeCallback = callback; } }), destroy: vi.fn(), diff --git a/test/unit/logging/formatters.test.ts b/test/unit/logging/formatters.test.ts new file mode 100644 index 00000000..1cd4fedf --- /dev/null +++ b/test/unit/logging/formatters.test.ts @@ -0,0 +1,122 @@ +import { describe, expect, it } from "vitest"; + +import { + formatBody, + formatHeaders, + formatMethod, + formatSize, + formatTime, + formatUri, +} from "@/logging/formatters"; + +describe("Logging formatters", () => { + it("formats time in appropriate units", () => { + expect(formatTime(500)).toBe("500ms"); + expect(formatTime(1000)).toBe("1.00s"); + expect(formatTime(5500)).toBe("5.50s"); + expect(formatTime(60000)).toBe("1.00m"); + expect(formatTime(150000)).toBe("2.50m"); + expect(formatTime(3600000)).toBe("1.00h"); + expect(formatTime(7255000)).toBe("2.02h"); + }); + + describe("formatMethod", () => { + it("normalizes HTTP methods to uppercase", () => { + expect(formatMethod("get")).toBe("GET"); + expect(formatMethod("post")).toBe("POST"); + expect(formatMethod("PUT")).toBe("PUT"); + expect(formatMethod("delete")).toBe("DELETE"); + }); + + it("defaults to GET for falsy values", () => { + expect(formatMethod(undefined)).toBe("GET"); + expect(formatMethod("")).toBe("GET"); + }); + }); + + describe("formatSize", () => { + it("formats byte sizes using pretty-bytes", () => { + expect(formatSize(1024)).toContain("1.02 kB"); + expect(formatSize(0)).toBe("(0 B)"); + }); + + it("returns placeholder for undefined", () => { + expect(formatSize(undefined)).toBe("(? B)"); + }); + }); + + describe("formatUri", () => { + it("returns URL when present", () => { + expect(formatUri({ url: "https://example.com/api" })).toBe( + "https://example.com/api", + ); + expect(formatUri({ url: "/relative/path" })).toBe("/relative/path"); + }); + + it("returns placeholder for missing URL", () => { + expect(formatUri(undefined)).toContain("no url"); + expect(formatUri({})).toContain("no url"); + expect(formatUri({ url: "" })).toContain("no url"); + }); + }); + + describe("formatHeaders", () => { + it("formats headers as key-value pairs", () => { + const headers = { + "content-type": "application/json", + accept: "text/html", + }; + const result = formatHeaders(headers); + expect(result).toContain("content-type: application/json"); + expect(result).toContain("accept: text/html"); + }); + + it("redacts sensitive headers", () => { + const sensitiveHeaders = ["Coder-Session-Token", "Proxy-Authorization"]; + + sensitiveHeaders.forEach((header) => { + const result = formatHeaders({ [header]: "secret-value" }); + expect(result).toContain(`${header}: `); + expect(result).not.toContain("secret-value"); + }); + }); + + it("returns placeholder for empty headers", () => { + expect(formatHeaders({})).toBe(""); + }); + }); + + describe("formatBody", () => { + it("formats various body types", () => { + expect(formatBody({ key: "value" })).toContain("key: 'value'"); + expect(formatBody("plain text")).toContain("plain text"); + expect(formatBody([1, 2, 3])).toContain("1"); + expect(formatBody(123)).toContain("123"); + expect(formatBody(true)).toContain("true"); + }); + + it("handles circular references gracefully", () => { + const circular: Record = { a: 1 }; + circular.self = circular; + const result = formatBody(circular); + expect(result).toBeTruthy(); + expect(result).not.toContain("invalid body"); + expect(result).toContain("a: 1"); + }); + + it("handles deep nesting", () => { + const deep = { + level1: { level2: { level3: { level4: { value: "deep" } } } }, + }; + const result = formatBody(deep); + expect(result).toContain("level4: { value: 'deep' }"); + }); + + it("returns placeholder for empty values", () => { + const emptyValues = [null, undefined, "", 0, false]; + emptyValues.forEach((value) => { + expect(formatBody(value)).toContain("no body"); + }); + }); + }); +}); diff --git a/test/unit/logging/httpLogger.test.ts b/test/unit/logging/httpLogger.test.ts new file mode 100644 index 00000000..81cfbed8 --- /dev/null +++ b/test/unit/logging/httpLogger.test.ts @@ -0,0 +1,112 @@ +import { AxiosError, type AxiosHeaders, type AxiosResponse } from "axios"; +import { describe, expect, it, vi } from "vitest"; + +import { + createRequestMeta, + logError, + logRequest, + logResponse, +} from "@/logging/httpLogger"; +import { + HttpClientLogLevel, + type RequestConfigWithMeta, +} from "@/logging/types"; + +import { createMockLogger } from "../../mocks/testHelpers"; + +describe("REST HTTP Logger", () => { + describe("log level behavior", () => { + const config = { + method: "POST", + url: "https://api.example.com/endpoint", + headers: { + "content-type": "application/json", + } as unknown as AxiosHeaders, + data: { key: "value" }, + metadata: createRequestMeta(), + } as RequestConfigWithMeta; + + it("respects NONE level for trace logs", () => { + const logger = createMockLogger(); + + logRequest(logger, config, HttpClientLogLevel.NONE); + logResponse( + logger, + { status: 200 } as AxiosResponse, + HttpClientLogLevel.NONE, + ); + logError(logger, new Error("test"), HttpClientLogLevel.NONE); + + expect(logger.trace).not.toHaveBeenCalled(); + expect(logger.error).toHaveBeenCalled(); // always log errors + }); + + it("includes headers at HEADERS level but not at BASIC", () => { + const logger = createMockLogger(); + + logRequest(logger, config, HttpClientLogLevel.BASIC); + expect(logger.trace).not.toHaveBeenCalledWith( + expect.stringContaining("content-type"), + ); + + vi.clearAllMocks(); + logRequest(logger, config, HttpClientLogLevel.HEADERS); + expect(logger.trace).toHaveBeenCalledWith( + expect.stringContaining("content-type"), + ); + }); + + it("includes body at BODY level but not at HEADERS", () => { + const logger = createMockLogger(); + + logRequest(logger, config, HttpClientLogLevel.HEADERS); + expect(logger.trace).not.toHaveBeenCalledWith( + expect.stringContaining("key: 'value'"), + ); + + vi.clearAllMocks(); + logRequest(logger, config, HttpClientLogLevel.BODY); + expect(logger.trace).toHaveBeenCalledWith( + expect.stringContaining("key: 'value'"), + ); + }); + }); + + describe("error handling", () => { + it("distinguishes between network errors and response errors", () => { + const logger = createMockLogger(); + + const networkError = new AxiosError("Some Network Error", "ECONNREFUSED"); + networkError.config = { + metadata: createRequestMeta(), + } as RequestConfigWithMeta; + + logError(logger, networkError, HttpClientLogLevel.BASIC); + expect(logger.error).toHaveBeenCalledWith( + expect.stringContaining("Some Network Error"), + ); + + // Response error (4xx/5xx) + vi.clearAllMocks(); + const responseError = new AxiosError("Bad Request"); + responseError.config = { + metadata: createRequestMeta(), + } as RequestConfigWithMeta; + responseError.response = { status: 400 } as AxiosResponse; + + logError(logger, responseError, HttpClientLogLevel.BASIC); + expect(logger.error).toHaveBeenCalledWith(expect.stringContaining("400")); + expect(logger.error).toHaveBeenCalledWith( + expect.stringContaining("Bad Request"), + ); + }); + + it("handles non-Axios errors", () => { + const logger = createMockLogger(); + const error = new Error("Generic error"); + + logError(logger, error, HttpClientLogLevel.BASIC); + expect(logger.error).toHaveBeenCalledWith("Request error", error); + }); + }); +}); diff --git a/test/unit/logging/utils.test.ts b/test/unit/logging/utils.test.ts new file mode 100644 index 00000000..3adbeecb --- /dev/null +++ b/test/unit/logging/utils.test.ts @@ -0,0 +1,106 @@ +import { describe, expect, it } from "vitest"; + +import { + createRequestId, + serializeValue, + shortId, + sizeOf, +} from "@/logging/utils"; + +describe("Logging utils", () => { + describe("shortId", () => { + it("truncates long strings to 8 characters", () => { + expect(shortId("abcdefghijklmnop")).toBe("abcdefgh"); + expect(shortId("12345678")).toBe("12345678"); + expect(shortId("123456789")).toBe("12345678"); + }); + + it("returns short strings unchanged", () => { + expect(shortId("short")).toBe("short"); + expect(shortId("")).toBe(""); + expect(shortId("1234567")).toBe("1234567"); + }); + }); + + describe("sizeOf", () => { + it.each([ + // Primitives return a fixed value + [null, 0], + [undefined, 0], + [42, 8], + [3.14, 8], + [false, 4], + // Strings + ["hello", 5], + ["✓", 3], + ["unicode: ✓", 12], + // Buffers + [Buffer.from("test"), 4], + [BigInt(12345), 5], + [BigInt(0), 1], + [Buffer.alloc(100), 100], + [Buffer.from([]), 0], + // Typed-arrays + [new ArrayBuffer(50), 50], + [new Uint8Array([1, 2, 3, 4]), 4], + [new Int32Array([1, 2, 3]), 12], + [new Float64Array([1.0, 2.0]), 16], + // Objects/untyped-arrays return undefined + [{ size: 1024 }, 1024], + [{ size: 0 }, 0], + [{ size: "not a number" }, undefined], + [[], undefined], + [[1, 2, 3], undefined], + [["a", "b", "c"], undefined], + [{}, undefined], + [{ foo: "bar" }, undefined], + [{ nested: { value: 123 } }, undefined], + ])("returns size for %s", (data: unknown, bytes: number | undefined) => { + expect(sizeOf(data)).toBe(bytes); + }); + + it("handles circular references safely", () => { + const circular: Record = { a: 1 }; + circular.self = circular; + expect(sizeOf(circular)).toBeUndefined(); + + const arr: unknown[] = [1, 2, 3]; + arr.push(arr); + expect(sizeOf(arr)).toBeUndefined(); + }); + }); + + describe("serializeValue", () => { + it("formats various data types", () => { + expect(serializeValue({ key: "value" })).toContain("key: 'value'"); + expect(serializeValue("plain text")).toContain("plain text"); + expect(serializeValue([1, 2, 3])).toContain("1"); + expect(serializeValue(123)).toContain("123"); + expect(serializeValue(true)).toContain("true"); + }); + + it("handles circular references safely", () => { + const circular: Record = { a: 1 }; + circular.self = circular; + const result = serializeValue(circular); + expect(result).toBeTruthy(); + expect(result).toContain("a: 1"); + }); + + it("handles deep nesting", () => { + const deep = { + level1: { level2: { level3: { level4: { value: "deep" } } } }, + }; + const result = serializeValue(deep); + expect(result).toContain("level4: { value: 'deep' }"); + }); + }); + + describe("createRequestId", () => { + it("generates valid UUID format without dashes", () => { + const id = createRequestId(); + expect(id).toHaveLength(32); + expect(id).not.toContain("-"); + }); + }); +}); diff --git a/test/unit/logging/wsLogger.test.ts b/test/unit/logging/wsLogger.test.ts new file mode 100644 index 00000000..5bf9d5b1 --- /dev/null +++ b/test/unit/logging/wsLogger.test.ts @@ -0,0 +1,71 @@ +import { describe, expect, it } from "vitest"; + +import { WsLogger } from "@/logging/wsLogger"; + +import { createMockLogger } from "../../mocks/testHelpers"; + +describe("WS Logger", () => { + it("tracks message count and byte size", () => { + const logger = createMockLogger(); + const wsLogger = new WsLogger(logger, "wss://example.com"); + + wsLogger.logOpen(); + wsLogger.logMessage("hello"); + wsLogger.logMessage("world"); + wsLogger.logMessage(Buffer.from("test")); + wsLogger.logClose(); + + expect(logger.trace).toHaveBeenCalledWith( + expect.stringContaining("3 msgs"), + ); + expect(logger.trace).toHaveBeenCalledWith(expect.stringContaining("14 B")); + }); + + it("handles unknown byte sizes with >= indicator", () => { + const logger = createMockLogger(); + const wsLogger = new WsLogger(logger, "wss://example.com"); + + wsLogger.logOpen(); + wsLogger.logMessage({ complex: "object" }); // Unknown size - no estimation + wsLogger.logMessage("known"); + wsLogger.logClose(); + + expect(logger.trace).toHaveBeenLastCalledWith( + expect.stringContaining(">= 5 B"), + ); + }); + + it("handles close before open gracefully", () => { + const logger = createMockLogger(); + const wsLogger = new WsLogger(logger, "wss://example.com"); + + // Closing without opening should not throw + expect(() => wsLogger.logClose()).not.toThrow(); + expect(logger.trace).toHaveBeenCalled(); + }); + + it("formats large message counts with compact notation", () => { + const logger = createMockLogger(); + const wsLogger = new WsLogger(logger, "wss://example.com"); + + wsLogger.logOpen(); + for (let i = 0; i < 1100; i++) { + wsLogger.logMessage("x"); + } + wsLogger.logClose(); + + expect(logger.trace).toHaveBeenLastCalledWith( + expect.stringMatching(/1[.,]1K\s*msgs/), + ); + }); + + it("logs errors with error object", () => { + const logger = createMockLogger(); + const wsLogger = new WsLogger(logger, "wss://example.com"); + const error = new Error("Connection failed"); + + wsLogger.logError(error, "Failed to connect"); + + expect(logger.error).toHaveBeenCalledWith(expect.any(String), error); + }); +});