diff --git a/packages/utils/test/fixtures/logger-api-probe.ts b/packages/utils/test/fixtures/logger-api-probe.ts new file mode 100644 index 000000000..ad748c0bf --- /dev/null +++ b/packages/utils/test/fixtures/logger-api-probe.ts @@ -0,0 +1,15 @@ +import * as fs from "node:fs"; +import { logger as rootLogger } from "../../src/index"; +import * as directLogger from "../../src/logger"; + +const outputPath = process.argv[2]; +if (!outputPath) throw new Error("expected output path"); + +const keys = Object.keys(directLogger).sort(); +const identities = keys.every(key => { + const direct = directLogger as Record; + const root = rootLogger as Record; + return direct[key] === root[key]; +}); + +fs.writeFileSync(outputPath, JSON.stringify({ identities, keys })); diff --git a/packages/utils/test/fixtures/logger-cache-positive-control.ts b/packages/utils/test/fixtures/logger-cache-positive-control.ts new file mode 100644 index 000000000..ad9a58777 --- /dev/null +++ b/packages/utils/test/fixtures/logger-cache-positive-control.ts @@ -0,0 +1,9 @@ +import * as fs from "node:fs"; +import * as winston from "winston"; +import { snapshotLoggerRuntime } from "./logger-cache-snapshot"; + +const outputPath = process.argv[2]; +if (!outputPath) throw new Error("expected output path"); + +void winston; +fs.writeFileSync(outputPath, JSON.stringify(snapshotLoggerRuntime())); diff --git a/packages/utils/test/fixtures/logger-cache-probe.ts b/packages/utils/test/fixtures/logger-cache-probe.ts new file mode 100644 index 000000000..11159e73d --- /dev/null +++ b/packages/utils/test/fixtures/logger-cache-probe.ts @@ -0,0 +1,29 @@ +import * as fs from "node:fs"; +import * as logger from "../../src/logger"; +import { snapshotLoggerRuntime } from "./logger-cache-snapshot"; + +const scenario = process.argv[2]; +const outputPath = process.argv[3]; +const logsDir = process.argv[4]; + +if (!scenario || !outputPath) throw new Error("expected scenario and output path"); + +switch (scenario) { + case "import": + break; + case "console": + logger.setTransports({ console: true, file: false }); + logger.info("logger-cache-console"); + logger.setTransports({ console: false, file: false }); + break; + case "file": + if (!logsDir) throw new Error("file scenario requires logs directory"); + logger.setTransports({ console: false, file: logsDir }); + logger.info("logger-cache-file"); + logger.setTransports({ console: false, file: false }); + break; + default: + throw new Error(`unknown scenario: ${scenario}`); +} + +fs.writeFileSync(outputPath, JSON.stringify(snapshotLoggerRuntime())); diff --git a/packages/utils/test/fixtures/logger-cache-snapshot.ts b/packages/utils/test/fixtures/logger-cache-snapshot.ts new file mode 100644 index 000000000..97163251d --- /dev/null +++ b/packages/utils/test/fixtures/logger-cache-snapshot.ts @@ -0,0 +1,39 @@ +import * as fs from "node:fs"; +import * as nodeModule from "node:module"; + +interface ModuleConstructorWithCache { + readonly _cache: Record; +} + +export interface CacheFamily { + readonly modules: number; + readonly bytes: number; + readonly paths: string[]; +} + +export interface LoggerCacheSnapshot { + readonly winston: CacheFamily; + readonly fileStreamRotator: CacheFamily; + readonly moment: CacheFamily; +} + +const moduleCache = (nodeModule.Module as unknown as ModuleConstructorWithCache)._cache; + +function snapshotFamily(segment: string): CacheFamily { + const paths = Object.keys(moduleCache) + .filter(modulePath => modulePath.replaceAll("\\", "/").includes(segment)) + .sort(); + return { + modules: paths.length, + bytes: paths.reduce((total, modulePath) => total + fs.statSync(modulePath).size, 0), + paths, + }; +} + +export function snapshotLoggerRuntime(): LoggerCacheSnapshot { + return { + winston: snapshotFamily("/node_modules/winston/"), + fileStreamRotator: snapshotFamily("/node_modules/file-stream-rotator/"), + moment: snapshotFamily("/node_modules/moment/"), + }; +} diff --git a/packages/utils/test/fixtures/logger-contract-probe.ts b/packages/utils/test/fixtures/logger-contract-probe.ts new file mode 100644 index 000000000..4d687ba5c --- /dev/null +++ b/packages/utils/test/fixtures/logger-contract-probe.ts @@ -0,0 +1,226 @@ +import * as fs from "node:fs"; +import * as path from "node:path"; +import * as logger from "../../src/logger"; + +const scenario = process.argv[2]; +const primaryDir = process.argv[3]; +const secondaryDir = process.argv[4]; +const resultPath = process.argv[5]; + +if (!scenario || !primaryDir || !secondaryDir || !resultPath) { + throw new Error("expected scenario, primary directory, secondary directory, and result path"); +} + +function disableTransports(): void { + logger.setTransports({ console: false, file: false }); +} + +function writeResult(value: unknown): void { + fs.writeFileSync(resultPath, JSON.stringify(value)); +} + +switch (scenario) { + case "matrix": { + logger.setTransports({ console: false, file: primaryDir }); + logger.error("level-error", { ordinal: 1 }); + logger.warn("level-warn", { ordinal: 2 }); + logger.info("level-info", { ordinal: 3 }); + logger.debug("level-debug", { ordinal: 4 }); + + const hidden = Symbol("hidden"); + const context: Record & { [hidden]?: unknown } = { + stringValue: "text", + numberValue: 7, + booleanValue: false, + nullValue: null, + nested: { alpha: "a", values: [1, undefined, () => "omitted", Number.NaN] }, + undefinedValue: undefined, + functionValue: () => "omitted", + infinity: Number.POSITIVE_INFINITY, + nan: Number.NaN, + }; + context[hidden] = "omitted"; + logger.info("context-matrix", context); + logger.warn("reserved-primary", { + before: "first", + message: "metadata-message", + level: "context-level", + timestamp: "context-timestamp", + after: "last", + }); + logger.debug("reserved-falsy", { message: "", after: true }); + + const cause = new Error("downstream"); + cause.stack = "CAUSE_STACK"; + const error = new Error("upstream", { cause }) as Error & { code: string; detail: { retry: boolean } }; + error.name = "CustomError"; + error.stack = "OUTER_STACK"; + error.code = "E_FIXTURE"; + error.detail = { retry: false }; + logger.error("error-matrix", { error }); + disableTransports(); + break; + } + case "format-tokens": { + logger.setTransports({ console: false, file: primaryDir }); + for (const token of ["s", "c", "d", "j", "i", "f", "o", "O", "%"]) { + logger.info(`token-%${token}`, { value: 7 }); + } + logger.info("non-token-%q", { value: 7 }); + interface TokenCircularContext extends Record { + self?: TokenCircularContext; + } + const circular: TokenCircularContext = { kind: "circular" }; + circular.self = circular; + logger.info("circular-%s", circular); + logger.info("bigint-%d", { value: 1n }); + disableTransports(); + break; + } + case "serialization-failures": { + logger.setTransports({ console: false, file: primaryDir }); + interface CircularContext extends Record { + self?: CircularContext; + } + const circular: CircularContext = { kind: "circular" }; + circular.self = circular; + const bigintContext: Record = { value: 1n }; + const expectedContexts: Record[] = [circular, bigintContext]; + const events: Array<{ level: logger.LogLevel; message: string; sameContext: boolean; timestamp: string }> = []; + const dispose = logger.registerLogSink(event => { + const expected = expectedContexts[events.length]; + events.push({ + level: event.level, + message: event.message, + sameContext: event.context === expected, + timestamp: event.timestamp.toISOString(), + }); + }); + logger.info("circular-drop", circular); + logger.error("bigint-drop", bigintContext); + dispose(); + disableTransports(); + writeResult({ events }); + break; + } + case "default-file": + logger.info("mode-default", { mode: "default" }); + disableTransports(); + break; + case "file-only": + logger.setTransports({ console: false, file: primaryDir }); + logger.info("mode-file", { mode: "file" }); + disableTransports(); + break; + case "console-only": + logger.setTransports({ console: true, file: false }); + logger.info("mode-console", { mode: "console" }); + disableTransports(); + break; + case "both": + logger.setTransports({ console: true, file: primaryDir }); + logger.info("mode-both", { mode: "both" }); + disableTransports(); + break; + case "disabled-reenable": { + const contexts: Record[] = []; + const disabledContext = { mode: "disabled" }; + const dispose = logger.registerLogSink(event => { + if (event.context) contexts.push(event.context); + }); + const setReturn = logger.setTransports({ console: false, file: false }); + const logReturn = logger.warn("mode-disabled", disabledContext); + logger.setTransports({ console: false, file: primaryDir }); + logger.warn("mode-reenabled", { mode: "file" }); + const disposeReturn = dispose(); + disableTransports(); + writeResult({ + disabledSinkSameContext: contexts[0] === disabledContext, + sinkCount: contexts.length, + returnsUndefined: setReturn === undefined && logReturn === undefined && disposeReturn === undefined, + }); + break; + } + case "reconfigure": + logger.setTransports({ console: false, file: primaryDir }); + logger.info("directory-a", { destination: "a" }); + logger.setTransports({ console: false, file: secondaryDir }); + logger.info("directory-b", { destination: "b" }); + disableTransports(); + break; + case "reconfigure-failure": { + logger.setTransports({ console: false, file: primaryDir }); + logger.info("before-failed-reconfigure"); + const blockerPath = path.join(secondaryDir, "not-a-directory"); + fs.writeFileSync(blockerPath, "blocked"); + let reconfigureThrew = false; + try { + logger.setTransports({ console: false, file: path.join(blockerPath, "child") }); + } catch { + reconfigureThrew = true; + } + const sinkContext = { after: "failure" }; + let sinkSameContext = false; + let sinkCount = 0; + const dispose = logger.registerLogSink(event => { + sinkCount++; + sinkSameContext = event.context === sinkContext; + }); + logger.info("after-failed-reconfigure", sinkContext); + dispose(); + await Bun.sleep(20); + writeResult({ reconfigureThrew, sinkCount, sinkSameContext }); + break; + } + case "burst-close": + logger.setTransports({ console: false, file: primaryDir }); + for (let index = 0; index < 1_000; index++) logger.info("burst-close", { index }); + disableTransports(); + break; + case "burst-natural": + logger.setTransports({ console: false, file: primaryDir }); + for (let index = 0; index < 1_000; index++) logger.info("burst-natural", { index }); + break; + case "sink-order": { + logger.setTransports({ console: true, file: false }); + const sinkContext = { identity: "same" }; + const dispose = logger.registerLogSink(event => { + process.stdout.write(`SINK:${event.context === sinkContext}\n`); + throw new Error("sink failure must be isolated"); + }); + logger.info("sink-first", sinkContext); + dispose(); + logger.info("sink-disposed"); + disableTransports(); + break; + } + case "date-retention": { + const dates = [ + "2026-01-02T03:04:05.006Z", + "2026-01-03T03:04:05.006Z", + "2026-01-04T03:04:05.006Z", + "2026-01-05T03:04:05.006Z", + "2026-01-06T03:04:05.006Z", + "2026-01-07T03:04:05.006Z", + ]; + process.env.OMP_LOGGER_TEST_NOW = dates[0]; + logger.setTransports({ console: false, file: primaryDir }); + for (const [index, date] of dates.entries()) { + process.env.OMP_LOGGER_TEST_NOW = date; + logger.info(`date-${index + 1}`); + await Bun.sleep(10); + } + disableTransports(); + break; + } + case "size-rotation": + logger.setTransports({ console: false, file: primaryDir }); + logger.info("size-nine-mib", { payload: "x".repeat(9 * 1024 * 1024) }); + logger.info("size-half-mib", { payload: "y".repeat(512 * 1024) }); + logger.info("size-crosses-ten-mib", { payload: "z".repeat(1024 * 1024) }); + logger.info("rotation-trigger"); + disableTransports(); + break; + default: + throw new Error(`unknown scenario: ${scenario}`); +} diff --git a/packages/utils/test/fixtures/logger-fixed-date-preload.ts b/packages/utils/test/fixtures/logger-fixed-date-preload.ts new file mode 100644 index 000000000..987b09f4b --- /dev/null +++ b/packages/utils/test/fixtures/logger-fixed-date-preload.ts @@ -0,0 +1,21 @@ +const NativeDate = globalThis.Date; + +function fixtureNow(): number { + const value = process.env.OMP_LOGGER_TEST_NOW; + if (!value) throw new Error("OMP_LOGGER_TEST_NOW is required"); + const parsed = NativeDate.parse(value); + if (!Number.isFinite(parsed)) throw new Error(`invalid OMP_LOGGER_TEST_NOW: ${value}`); + return parsed; +} + +class FixedDate extends NativeDate { + constructor(value?: string | number) { + super(value === undefined ? fixtureNow() : value); + } + + static now(): number { + return fixtureNow(); + } +} + +globalThis.Date = FixedDate as DateConstructor; diff --git a/packages/utils/test/logger-contract.test.ts b/packages/utils/test/logger-contract.test.ts new file mode 100644 index 000000000..4bc25512b --- /dev/null +++ b/packages/utils/test/logger-contract.test.ts @@ -0,0 +1,358 @@ +import { afterEach, describe, expect, test } from "bun:test"; +import * as crypto from "node:crypto"; +import * as fs from "node:fs/promises"; +import * as os from "node:os"; +import * as path from "node:path"; + +const fixtureDir = path.join(import.meta.dir, "fixtures"); +const probePath = path.join(fixtureDir, "logger-contract-probe.ts"); +const preloadPath = path.join(fixtureDir, "logger-fixed-date-preload.ts"); +const apiProbePath = path.join(fixtureDir, "logger-api-probe.ts"); +const fixedNow = "2026-01-02T03:04:05.006Z"; +const fixedTimestamp = "2026-01-01T22:04:05.006-05:00"; +const roots: string[] = []; + +interface ScenarioResult { + readonly pid: number; + readonly root: string; + readonly primaryDir: string; + readonly secondaryDir: string; + readonly resultPath: string; + readonly stdout: string; + readonly stderr: string; +} + +interface AuditFile { + readonly keep: { readonly days: boolean; readonly amount: number }; + readonly auditLog: string; + readonly files: Array<{ readonly date: number; readonly name: string; readonly hash: string }>; + readonly hashType: string; +} + +afterEach(async () => { + await Promise.all(roots.splice(0).map(root => fs.rm(root, { recursive: true, force: true }))); +}); + +async function runScenario(scenario: string): Promise { + const root = await fs.mkdtemp(path.join(os.tmpdir(), "omp-logger-contract-")); + roots.push(root); + const primaryDir = path.join(root, "primary"); + const secondaryDir = path.join(root, "secondary"); + const resultPath = path.join(root, "result.json"); + await Promise.all([fs.mkdir(primaryDir), fs.mkdir(secondaryDir)]); + const proc = Bun.spawn( + [process.execPath, "--preload", preloadPath, probePath, scenario, primaryDir, secondaryDir, resultPath], + { + cwd: path.resolve(import.meta.dir, "../../.."), + env: { + ...process.env, + HOME: primaryDir, + PI_CONFIG_DIR: ".omp", + OMP_PROFILE: "", + PI_PROFILE: "", + XDG_DATA_HOME: "", + XDG_STATE_HOME: "", + XDG_CACHE_HOME: "", + OMP_LOGGER_TEST_NOW: fixedNow, + TZ: "Etc/GMT+5", + }, + stdout: "pipe", + stderr: "pipe", + }, + ); + const [stdout, stderr, exitCode] = await Promise.all([ + new Response(proc.stdout).text(), + new Response(proc.stderr).text(), + proc.exited, + ]); + expect(exitCode, stderr).toBe(0); + return { pid: proc.pid, root, primaryDir, secondaryDir, resultPath, stdout, stderr }; +} + +async function logFileNames(directory: string): Promise { + return (await fs.readdir(directory)).filter(name => /^omp\.\d{4}-\d{2}-\d{2}\.\d+\.log(?:\.\d+)?$/.test(name)).sort(); +} + +async function readSingleLog(directory: string): Promise<{ name: string; text: string }> { + const names = await logFileNames(directory); + expect(names).toHaveLength(1); + const name = names[0]; + if (!name) throw new Error("expected one log file"); + return { name, text: await fs.readFile(path.join(directory, name), "utf8") }; +} + +function expectedLine( + pid: number, + level: "error" | "warn" | "info" | "debug", + message: string, + context: Record = {}, + timestamp = fixedTimestamp, +): string { + return `${JSON.stringify({ timestamp, level, pid, message, ...context })}${os.EOL}`; +} + +describe("central logger byte contract", () => { + test("pins levels, metadata normalization, key order, timestamp, errors, pid, and EOL", async () => { + const result = await runScenario("matrix"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + const log = await readSingleLog(result.primaryDir); + expect(log.name).toBe(`omp.2026-01-01.${result.pid}.log`); + const expected = [ + expectedLine(result.pid, "error", "level-error", { ordinal: 1 }), + expectedLine(result.pid, "warn", "level-warn", { ordinal: 2 }), + expectedLine(result.pid, "info", "level-info", { ordinal: 3 }), + expectedLine(result.pid, "debug", "level-debug", { ordinal: 4 }), + expectedLine(result.pid, "info", "context-matrix", { + stringValue: "text", + numberValue: 7, + booleanValue: false, + nullValue: null, + nested: { alpha: "a", values: [1, null, null, null] }, + infinity: null, + nan: null, + }), + expectedLine(result.pid, "warn", "reserved-primary metadata-message", { before: "first", after: "last" }), + expectedLine(result.pid, "debug", "reserved-falsy", { after: true }), + expectedLine(result.pid, "error", "error-matrix", { + error: { + name: "CustomError", + message: "upstream", + stack: "OUTER_STACK", + code: "E_FIXTURE", + detail: { retry: false }, + cause: { name: "Error", message: "downstream", stack: "CAUSE_STACK" }, + }, + }), + ].join(""); + expect(log.text).toBe(expected); + expect(log.text.endsWith(os.EOL)).toBe(true); + expect(await fs.readFile(path.join(result.primaryDir, `.omp.${result.pid}-audit.json`), "utf8")).not.toBe(""); + }); + + test("treats Winston format tokens as a splat branch and omits context", async () => { + const result = await runScenario("format-tokens"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + const tokenMessages = ["token-%s", "token-%c", "token-%d", "token-%j", "token-%i", "token-%f", "token-%o", "token-%O", "token-%%"]; + const expected = [ + ...tokenMessages.map(message => expectedLine(result.pid, "info", message)), + expectedLine(result.pid, "info", "non-token-%q", { value: 7 }), + expectedLine(result.pid, "info", "circular-%s"), + expectedLine(result.pid, "info", "bigint-%d"), + ].join(""); + expect((await readSingleLog(result.primaryDir)).text).toBe(expected); + }); + + test("drops native JSON failures locally but sends original contexts to sinks", async () => { + const result = await runScenario("serialization-failures"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + const log = await readSingleLog(result.primaryDir); + expect(log.text).toBe(""); + const payload = JSON.parse(await fs.readFile(result.resultPath, "utf8")) as { + events: Array<{ level: string; message: string; sameContext: boolean; timestamp: string }>; + }; + expect(payload.events).toEqual([ + { level: "info", message: "circular-drop", sameContext: true, timestamp: fixedNow }, + { level: "error", message: "bigint-drop", sameContext: true, timestamp: fixedNow }, + ]); + }); +}); + +describe("central logger transport lifecycle", () => { + test("defaults to file-only without touching stdout or stderr", async () => { + const result = await runScenario("default-file"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + const defaultLogsDir = path.join(result.primaryDir, ".omp", "logs"); + const log = await readSingleLog(defaultLogsDir); + expect(log.text).toBe(expectedLine(result.pid, "info", "mode-default", { mode: "default" })); + }); + + test("emits file-only, console-only, and dual modes exactly once", async () => { + const fileOnly = await runScenario("file-only"); + const fileLine = expectedLine(fileOnly.pid, "info", "mode-file", { mode: "file" }); + expect(fileOnly.stdout).toBe(""); + expect(fileOnly.stderr).toBe(""); + expect((await readSingleLog(fileOnly.primaryDir)).text).toBe(fileLine); + + const consoleOnly = await runScenario("console-only"); + const consoleLine = expectedLine(consoleOnly.pid, "info", "mode-console", { mode: "console" }); + expect(consoleOnly.stdout).toBe(consoleLine); + expect(consoleOnly.stderr).toBe(""); + expect(await logFileNames(consoleOnly.primaryDir)).toEqual([]); + + const both = await runScenario("both"); + const bothLine = expectedLine(both.pid, "info", "mode-both", { mode: "both" }); + expect(both.stdout).toBe(bothLine); + expect(both.stderr).toBe(""); + expect((await readSingleLog(both.primaryDir)).text).toBe(bothLine); + }); + + test("keeps disabled mode silent, sends sinks, preserves void returns, and re-enables", async () => { + const result = await runScenario("disabled-reenable"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + expect((await readSingleLog(result.primaryDir)).text).toBe( + expectedLine(result.pid, "warn", "mode-reenabled", { mode: "file" }), + ); + const payload = JSON.parse(await fs.readFile(result.resultPath, "utf8")) as { + disabledSinkSameContext: boolean; + sinkCount: number; + returnsUndefined: boolean; + }; + expect(payload).toEqual({ disabledSinkSameContext: true, sinkCount: 2, returnsUndefined: true }); + }); + + test("closes A before reconfiguring to B and never cross-writes", async () => { + const result = await runScenario("reconfigure"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + expect((await readSingleLog(result.primaryDir)).text).toBe( + expectedLine(result.pid, "info", "directory-a", { destination: "a" }), + ); + expect((await readSingleLog(result.secondaryDir)).text).toBe( + expectedLine(result.pid, "info", "directory-b", { destination: "b" }), + ); + }); + + test("invalidates closed transports when warm replacement construction fails", async () => { + const result = await runScenario("reconfigure-failure"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + expect((await readSingleLog(result.primaryDir)).text).toBe( + expectedLine(result.pid, "info", "before-failed-reconfigure"), + ); + expect(await logFileNames(result.secondaryDir)).toEqual([]); + const payload = JSON.parse(await fs.readFile(result.resultPath, "utf8")) as { + reconfigureThrew: boolean; + sinkCount: number; + sinkSameContext: boolean; + }; + expect(payload).toEqual({ reconfigureThrew: true, sinkCount: 1, sinkSameContext: true }); + }); + + test("preserves burst order and drains on close and natural child exit", async () => { + for (const scenario of ["burst-close", "burst-natural"] as const) { + const result = await runScenario(scenario); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + const text = (await readSingleLog(result.primaryDir)).text; + expect(text.endsWith(os.EOL)).toBe(true); + const lines = text.split(os.EOL); + expect(lines.pop()).toBe(""); + expect(lines).toHaveLength(1_000); + for (const [index, line] of lines.entries()) { + const entry = JSON.parse(line) as { message: string; index: number }; + expect(entry).toMatchObject({ message: scenario, index }); + } + } + }); + + test("runs local console output before sinks and isolates throwing or disposed sinks", async () => { + const result = await runScenario("sink-order"); + const first = expectedLine(result.pid, "info", "sink-first", { identity: "same" }); + const second = expectedLine(result.pid, "info", "sink-disposed"); + expect(result.stdout).toBe(`${first}SINK:true\n${second}`); + expect(result.stderr).toBe(""); + }); +}); + +describe("DailyRotateFile option and retention contract", () => { + test("uses local-day names, a PID audit, SHA-256, and retains exactly five rotations", async () => { + const result = await runScenario("date-retention"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + const expectedNames = [2, 3, 4, 5, 6].map(day => `omp.2026-01-0${day}.${result.pid}.log`); + expect(await logFileNames(result.primaryDir)).toEqual(expectedNames); + for (const [offset, name] of expectedNames.entries()) { + const day = offset + 2; + const timestamp = `2026-01-0${day}T22:04:05.006-05:00`; + expect(await fs.readFile(path.join(result.primaryDir, name), "utf8")).toBe( + expectedLine(result.pid, "info", `date-${day}`, {}, timestamp), + ); + } + + const auditPath = path.join(result.primaryDir, `.omp.${result.pid}-audit.json`); + const audit = JSON.parse(await fs.readFile(auditPath, "utf8")) as AuditFile; + expect(audit.keep).toEqual({ days: false, amount: 5 }); + expect(audit.auditLog).toBe(auditPath); + expect(audit.hashType).toBe("sha256"); + expect(audit.files.map(file => file.name)).toEqual(expectedNames.map(name => path.join(result.primaryDir, name))); + for (const file of audit.files) { + const hash = crypto.createHash("sha256").update(`${file.name}LOG_FILE${file.date}`).digest("hex"); + expect(file.hash).toBe(hash); + expect(file.hash).toMatch(/^[0-9a-f]{64}$/); + } + }); + + test("crosses 10 MiB before rolling the following record to suffix .1", async () => { + const result = await runScenario("size-rotation"); + expect(result.stdout).toBe(""); + expect(result.stderr).toBe(""); + const baseName = `omp.2026-01-01.${result.pid}.log`; + const rotatedName = `${baseName}.1`; + expect(await logFileNames(result.primaryDir)).toEqual([baseName, rotatedName]); + const basePath = path.join(result.primaryDir, baseName); + const baseStat = await fs.stat(basePath); + const recordSize = (message: string, payloadSize: number): number => + `{"timestamp":"${fixedTimestamp}","level":"info","pid":${result.pid},"message":"${message}","payload":"`.length + + payloadSize + + `"}${os.EOL}`.length; + const expectedBytes = + recordSize("size-nine-mib", 9 * 1024 * 1024) + + recordSize("size-half-mib", 512 * 1024) + + recordSize("size-crosses-ten-mib", 1024 * 1024); + expect(baseStat.size).toBe(expectedBytes); + expect(baseStat.size).toBeGreaterThan(10 * 1024 * 1024); + expect(await fs.readFile(path.join(result.primaryDir, rotatedName), "utf8")).toBe( + expectedLine(result.pid, "info", "rotation-trigger"), + ); + const audit = JSON.parse( + await fs.readFile(path.join(result.primaryDir, `.omp.${result.pid}-audit.json`), "utf8"), + ) as AuditFile; + expect(audit.keep).toEqual({ days: false, amount: 5 }); + expect(audit.files.map(file => path.basename(file.name))).toEqual([baseName, rotatedName]); + }); +}); + +test("root and direct source entry points expose identical public logger functions", async () => { + const root = await fs.mkdtemp(path.join(os.tmpdir(), "omp-logger-api-")); + roots.push(root); + const outputPath = path.join(root, "result.json"); + const proc = Bun.spawn([process.execPath, apiProbePath, outputPath], { + cwd: path.resolve(import.meta.dir, "../../.."), + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([ + new Response(proc.stdout).text(), + new Response(proc.stderr).text(), + proc.exited, + ]); + expect(exitCode, stderr).toBe(0); + expect(stdout).toBe(""); + expect(stderr).toBe(""); + const payload = JSON.parse(await fs.readFile(outputPath, "utf8")) as { identities: boolean; keys: string[] }; + expect(payload).toEqual({ + identities: true, + keys: [ + "debug", + "endTiming", + "error", + "info", + "openSpanPath", + "printTimings", + "recordModuleLoadSpan", + "registerLogSink", + "setTransports", + "shouldExitAfterTimings", + "startTiming", + "startupMarker", + "time", + "timingModeIncludes", + "warn", + ], + }); +}); diff --git a/packages/utils/test/logger-runtime-closure.test.ts b/packages/utils/test/logger-runtime-closure.test.ts new file mode 100644 index 000000000..32eb2982a --- /dev/null +++ b/packages/utils/test/logger-runtime-closure.test.ts @@ -0,0 +1,100 @@ +import { afterEach, describe, expect, test } from "bun:test"; +import * as fs from "node:fs/promises"; +import * as os from "node:os"; +import * as path from "node:path"; +import type { LoggerCacheSnapshot } from "./fixtures/logger-cache-snapshot"; + +const fixtureDir = path.join(import.meta.dir, "fixtures"); +const probePath = path.join(fixtureDir, "logger-cache-probe.ts"); +const positiveControlPath = path.join(fixtureDir, "logger-cache-positive-control.ts"); +const roots: string[] = []; + +interface ProbeResult { + readonly snapshot: LoggerCacheSnapshot; + readonly stdout: string; + readonly stderr: string; +} + +afterEach(async () => { + await Promise.all(roots.splice(0).map(root => fs.rm(root, { recursive: true, force: true }))); +}); + +async function makeRoot(prefix: string): Promise { + const root = await fs.mkdtemp(path.join(os.tmpdir(), prefix)); + roots.push(root); + return root; +} + +async function runProbe(scenario: "import" | "console" | "file"): Promise { + const root = await makeRoot("omp-logger-cache-"); + const outputPath = path.join(root, "result.json"); + const logsDir = path.join(root, "logs"); + await fs.mkdir(logsDir); + const proc = Bun.spawn([process.execPath, probePath, scenario, outputPath, logsDir], { + cwd: path.resolve(import.meta.dir, "../../.."), + env: { ...process.env, TZ: "Etc/GMT+5" }, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([ + new Response(proc.stdout).text(), + new Response(proc.stderr).text(), + proc.exited, + ]); + expect(exitCode, stderr).toBe(0); + return { + snapshot: JSON.parse(await fs.readFile(outputPath, "utf8")) as LoggerCacheSnapshot, + stdout, + stderr, + }; +} + +async function runPositiveControl(): Promise { + const root = await makeRoot("omp-logger-cache-control-"); + const outputPath = path.join(root, "result.json"); + const proc = Bun.spawn([process.execPath, positiveControlPath, outputPath], { + cwd: path.resolve(import.meta.dir, "../../.."), + stdout: "pipe", + stderr: "pipe", + }); + const stderr = new Response(proc.stderr).text(); + expect(await proc.exited, await stderr).toBe(0); + return JSON.parse(await fs.readFile(outputPath, "utf8")) as LoggerCacheSnapshot; +} + +describe("central logger runtime closure", () => { + test("detector observes the direct Winston positive control", async () => { + const { winston } = await runPositiveControl(); + expect(winston.modules, JSON.stringify(winston)).toBeGreaterThan(0); + expect(winston.bytes, JSON.stringify(winston)).toBeGreaterThan(0); + }); + + for (const scenario of ["import", "console", "file"] as const) { + test(`${scenario} evaluates zero Winston runtime modules`, async () => { + const { snapshot } = await runProbe(scenario); + expect( + { modules: snapshot.winston.modules, bytes: snapshot.winston.bytes }, + JSON.stringify(snapshot.winston), + ).toEqual({ modules: 0, bytes: 0 }); + }); + } + + test("rotation engine stays lazy until a file transport is constructed", async () => { + const imported = await runProbe("import"); + const consoled = await runProbe("console"); + for (const result of [imported, consoled]) { + expect(result.snapshot.fileStreamRotator.modules, JSON.stringify(result.snapshot)).toBe(0); + expect(result.snapshot.moment.modules, JSON.stringify(result.snapshot)).toBe(0); + } + expect(imported.stdout).toBe(""); + expect(imported.stderr).toBe(""); + expect(consoled.stdout.endsWith(`${os.EOL}`)).toBe(true); + expect(consoled.stderr).toBe(""); + + const filed = await runProbe("file"); + expect(filed.snapshot.fileStreamRotator.modules, JSON.stringify(filed.snapshot)).toBeGreaterThan(0); + expect(filed.snapshot.moment.modules, JSON.stringify(filed.snapshot)).toBeGreaterThan(0); + expect(filed.stdout).toBe(""); + expect(filed.stderr).toBe(""); + }); +});