// SPDX-License-Identifier: AGPL-3.0-only // Copyright (C) 2026 Giancarlo Erra - Altaire Limited import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; import { logger, setMcpLogSender } from "../../src/services/logger.js"; type SenderFn = Parameters[0]; describe("logger", () => { let stderrSpy: ReturnType; beforeEach(() => { stderrSpy = vi.spyOn(process.stderr, "write").mockImplementation(() => true); }); afterEach(() => { stderrSpy.mockRestore(); }); describe("log methods exist", () => { it("has debug method", () => { expect(typeof logger.debug).toBe("function"); }); it("has info method", () => { expect(typeof logger.info).toBe("function"); }); it("has warn method", () => { expect(typeof logger.warn).toBe("function"); }); it("has error method", () => { expect(typeof logger.error).toBe("function"); }); }); describe("info logging", () => { it("writes to stderr", () => { logger.info("test message"); expect(stderrSpy).toHaveBeenCalled(); }); it("outputs valid JSON", () => { logger.info("test message"); const output = stderrSpy.mock.calls[0]?.[0] as string; expect(() => JSON.parse(output)).not.toThrow(); }); it("includes timestamp, level, and data", () => { logger.info("hello world"); const output = stderrSpy.mock.calls[0]?.[0] as string; const parsed = JSON.parse(output); expect(parsed.timestamp).toBeDefined(); expect(parsed.level).toBe("info"); expect(parsed.data).toBe("hello world"); }); it("includes context fields when provided", () => { logger.info("test", { projectPath: "/test", count: 42 }); const output = stderrSpy.mock.calls[0]?.[0] as string; const parsed = JSON.parse(output); expect(parsed.projectPath).toBe("/test"); expect(parsed.count).toBe(42); }); it("outputs with trailing newline", () => { logger.info("test"); const output = stderrSpy.mock.calls[0]?.[0] as string; expect(output.endsWith("\n")).toBe(true); }); }); describe("warn logging", () => { it("writes with warn level", () => { logger.warn("warning message"); const output = stderrSpy.mock.calls[0]?.[0] as string; const parsed = JSON.parse(output); expect(parsed.level).toBe("warn"); expect(parsed.data).toBe("warning message"); }); }); describe("error logging", () => { it("writes with error level", () => { logger.error("error message"); const output = stderrSpy.mock.calls[0]?.[0] as string; const parsed = JSON.parse(output); expect(parsed.level).toBe("error"); expect(parsed.data).toBe("error message"); }); it("includes error context", () => { logger.error("failed", { error: "something broke", code: 500 }); const output = stderrSpy.mock.calls[0]?.[0] as string; const parsed = JSON.parse(output); expect(parsed.error).toBe("something broke"); expect(parsed.code).toBe(500); }); }); describe("timestamp format", () => { it("uses ISO 8601 format", () => { logger.info("timestamp test"); const output = stderrSpy.mock.calls[0]?.[0] as string; const parsed = JSON.parse(output); // ISO 8601: 2024-01-15T10:30:00.000Z expect(parsed.timestamp).toMatch(/^\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}/); }); }); describe("log level filtering", () => { it("does not emit debug messages at the default info level", () => { logger.debug("should be filtered"); expect(stderrSpy).not.toHaveBeenCalled(); }); it("emits info, warn, and error at the default info level", () => { logger.info("info msg"); logger.warn("warn msg"); logger.error("error msg"); expect(stderrSpy).toHaveBeenCalledTimes(3); }); }); describe("setMcpLogSender", () => { let senderMock: ReturnType; beforeEach(() => { senderMock = vi.fn(); setMcpLogSender(senderMock as SenderFn); }); afterEach(() => { // Reset so subsequent tests continue using the stderr path setMcpLogSender(null as unknown as SenderFn); }); it("routes logs through the MCP sender instead of stderr", () => { logger.info("mcp test"); expect(senderMock).toHaveBeenCalledOnce(); expect(stderrSpy).not.toHaveBeenCalled(); }); it("passes correct logger name, level, and data to the sender", () => { logger.info("hello"); expect(senderMock).toHaveBeenCalledWith({ level: "info", logger: "socraticode", data: "hello", }); }); it("maps warn level to 'warning' to comply with the MCP spec", () => { logger.warn("something off"); expect(senderMock).toHaveBeenCalledWith(expect.objectContaining({ level: "warning", })); }); it("keeps debug, info, error level names unchanged for MCP", () => { logger.error("boom"); expect(senderMock).toHaveBeenCalledWith(expect.objectContaining({ level: "error", })); }); it("embeds context fields in the data string when context is provided", () => { logger.info("msg", { foo: "bar", count: 3 }); const call = senderMock.mock.calls[0]?.[0] as { data: string }; expect(call.data).toContain("msg"); expect(call.data).toContain("foo"); expect(call.data).toContain("bar"); }); it("sends plain message string when no context is provided", () => { logger.info("plain message"); const call = senderMock.mock.calls[0]?.[0] as { data: string }; expect(call.data).toBe("plain message"); }); it("swallows exceptions thrown by the sender", () => { senderMock.mockImplementation(() => { throw new Error("transport closed"); }); expect(() => logger.info("test")).not.toThrow(); }); }); });