File
Blob: tests/worker/logger.test.ts
| 1 | import { describe, expect, it, vi } from "vitest"; |
| 2 | |
| 3 | import { createLogger, errorContext, parseLogLevel } from "@/worker/logger"; |
| 4 | |
| 5 | const firstJsonCall = (spy: { mock: { calls: Array<ReadonlyArray<unknown>> } }): Record<string, unknown> => { |
| 6 | const payload = spy.mock.calls[0]?.[0]; |
| 7 | if (typeof payload !== "string") { |
| 8 | throw new Error("expected logger to write a JSON string"); |
| 9 | } |
| 10 | return JSON.parse(payload) as Record<string, unknown>; |
| 11 | }; |
| 12 | |
| 13 | describe("structured worker logger", () => { |
| 14 | it("emits structured JSON and removes undefined fields", () => { |
| 15 | const logSpy = vi.spyOn(console, "log").mockImplementation(() => undefined); |
| 16 | const logger = createLogger("info", { requestId: "req_123", skippedBase: undefined, component: "test.component" }); |
| 17 | logger.info("thing_happened", { count: 2, skippedField: undefined }); |
| 18 | |
| 19 | expect(logSpy).toHaveBeenCalledTimes(1); |
| 20 | const entry = firstJsonCall(logSpy); |
| 21 | expect(entry).toMatchObject({ |
| 22 | level: "info", |
| 23 | component: "test.component", |
| 24 | event: "thing_happened", |
| 25 | requestId: "req_123", |
| 26 | count: 2, |
| 27 | }); |
| 28 | expect(typeof entry.ts).toBe("string"); |
| 29 | expect(entry).not.toHaveProperty("skippedBase"); |
| 30 | expect(entry).not.toHaveProperty("skippedField"); |
| 31 | logSpy.mockRestore(); |
| 32 | }); |
| 33 | |
| 34 | it("filters debug logs unless the level is debug; two loggers at different levels do not race", () => { |
| 35 | const logSpy = vi.spyOn(console, "log").mockImplementation(() => undefined); |
| 36 | |
| 37 | const infoLogger = createLogger("info", { component: "info.scope" }); |
| 38 | const debugLogger = createLogger("debug", { component: "debug.scope" }); |
| 39 | |
| 40 | infoLogger.debug("hidden"); |
| 41 | expect(logSpy).not.toHaveBeenCalled(); |
| 42 | |
| 43 | debugLogger.debug("visible"); |
| 44 | expect(logSpy).toHaveBeenCalledTimes(1); |
| 45 | expect(firstJsonCall(logSpy)).toMatchObject({ level: "debug", event: "visible", component: "debug.scope" }); |
| 46 | |
| 47 | logSpy.mockClear(); |
| 48 | |
| 49 | // The info logger keeps filtering even after a higher-verbosity peer |
| 50 | // logged. Without per-logger captured levels, a module-global mutable |
| 51 | // would race here. |
| 52 | infoLogger.debug("still hidden"); |
| 53 | expect(logSpy).not.toHaveBeenCalled(); |
| 54 | |
| 55 | logSpy.mockRestore(); |
| 56 | }); |
| 57 | |
| 58 | it("routes warn and error levels to matching console methods", () => { |
| 59 | const logSpy = vi.spyOn(console, "log").mockImplementation(() => undefined); |
| 60 | const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => undefined); |
| 61 | const errorSpy = vi.spyOn(console, "error").mockImplementation(() => undefined); |
| 62 | const logger = createLogger("info", { component: "test.component" }); |
| 63 | |
| 64 | logger.warn("warning"); |
| 65 | logger.error("failure"); |
| 66 | |
| 67 | expect(logSpy).not.toHaveBeenCalled(); |
| 68 | expect(warnSpy).toHaveBeenCalledTimes(1); |
| 69 | expect(errorSpy).toHaveBeenCalledTimes(1); |
| 70 | expect(firstJsonCall(warnSpy)).toMatchObject({ level: "warn", event: "warning" }); |
| 71 | expect(firstJsonCall(errorSpy)).toMatchObject({ level: "error", event: "failure" }); |
| 72 | |
| 73 | logSpy.mockRestore(); |
| 74 | warnSpy.mockRestore(); |
| 75 | errorSpy.mockRestore(); |
| 76 | }); |
| 77 | |
| 78 | it("merges child logger fields into entries", () => { |
| 79 | const logSpy = vi.spyOn(console, "log").mockImplementation(() => undefined); |
| 80 | const logger = createLogger("info", { component: "test.component", requestId: "req_123" }).child({ |
| 81 | userId: "user_123", |
| 82 | }); |
| 83 | |
| 84 | logger.info("child_event"); |
| 85 | |
| 86 | expect(firstJsonCall(logSpy)).toMatchObject({ |
| 87 | requestId: "req_123", |
| 88 | userId: "user_123", |
| 89 | }); |
| 90 | logSpy.mockRestore(); |
| 91 | }); |
| 92 | |
| 93 | it("formats error context and gates errorStack on the caller's level", () => { |
| 94 | const error = new Error("boom"); |
| 95 | |
| 96 | expect(errorContext(error, "info")).toMatchObject({ |
| 97 | errorName: "Error", |
| 98 | errorMessage: "boom", |
| 99 | }); |
| 100 | expect(errorContext(error, "info")).not.toHaveProperty("errorStack"); |
| 101 | expect(typeof errorContext(error, "debug").errorStack).toBe("string"); |
| 102 | expect(errorContext("plain failure", "info")).toEqual({ errorMessage: "plain failure" }); |
| 103 | }); |
| 104 | |
| 105 | it("parseLogLevel normalises unknown values to info", () => { |
| 106 | expect(parseLogLevel("DEBUG")).toBe("debug"); |
| 107 | expect(parseLogLevel("Warn")).toBe("warn"); |
| 108 | expect(parseLogLevel(undefined)).toBe("info"); |
| 109 | expect(parseLogLevel("trace")).toBe("info"); |
| 110 | }); |
| 111 | }); |