From 563301ad98018c7aa995068c49cf2cff4e636943 Mon Sep 17 00:00:00 2001 From: NagyVikt Date: Sun, 17 May 2026 19:20:38 +0200 Subject: [PATCH] feat(observability): structured logger + authmux diag bundle (X3) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Theme X3 (Observability v1) from docs/future/17-ROADMAP.md. - src/infra/log/logger.ts: zero-dep structured logger with debug/info/warn/error levels. Default human single-line on stderr; AUTHMUX_LOG=json switches to JSON-lines. AUTHMUX_LOG_LEVEL filters. child({correlationId}) injects an ID into every event; newCorrelationId() returns a 16-hex string. An in-memory ring buffer keeps the last 200 JSON events for diag. - Daemon evaluation cycles emit paired daemon.cycle.start / daemon.cycle.end events with a shared correlation id, action, and duration (no auth bytes). - src/commands/diag.ts: new "authmux diag" command writing authmux-diag-.tgz to cwd. Bundle contains version, node, platform, paths, accounts dir listing (filenames + sizes + mtimes ONLY — never contents), allowlisted env, and the last 200 log lines. Env table is allowlist-only (CODEX_AUTH_*, AUTHMUX_*, plus PATH/HOME/SHELL/TERM/ NODE_ENV/...); credential-shaped suffixes (_TOKEN/_KEY/_PASSWORD/ _SECRET/_COOKIE) are filtered even if the prefix matches. HOME's literal value never appears — only its length stand-in. - src/tests/logger.test.ts and src/tests/diag-redaction.test.ts: ring buffer, correlation IDs, JSON line shape, and the leak-guard proving OPENAI_API_KEY / MY_TOKEN / DB_PASSWORD / *_SECRET / *_KEY never reach the output while CODEX_AUTH_DEBUG / AUTHMUX_LOG do. Redaction list (never in bundle): auth.json, snapshot file contents, any env name matching the FORBIDDEN_SUFFIXES list, raw HOME value. Co-Authored-By: Claude Opus 4.7 (1M context) --- src/commands/diag.ts | 345 +++++++++++++++++++++++++ src/infra/log/logger.ts | 158 +++++++++++ src/lib/accounts/auto-switch/policy.ts | 54 ++++ src/tests/diag-redaction.test.ts | 75 ++++++ src/tests/logger.test.ts | 67 +++++ 5 files changed, 699 insertions(+) create mode 100644 src/commands/diag.ts create mode 100644 src/infra/log/logger.ts create mode 100644 src/tests/diag-redaction.test.ts create mode 100644 src/tests/logger.test.ts diff --git a/src/commands/diag.ts b/src/commands/diag.ts new file mode 100644 index 0000000..b9c4724 --- /dev/null +++ b/src/commands/diag.ts @@ -0,0 +1,345 @@ +// `authmux diag` — Theme X3 observability bundle. +// +// Produces a shareable diagnostic bundle for bug reports. Two hard rules +// (also enforced by `src/tests/diag-redaction.test.ts`): +// +// 1. Never read or include snapshot file contents. The accounts dir is +// listed by filename / size / mtime ONLY; the bundle's accounts table +// stats files but never opens them. +// 2. Never include `auth.json`. Even its existence flag is captured via +// `fs.statSync` — no read. Same rule for any *.json under accountsDir. +// +// The env table uses a hard-coded ALLOWLIST (see `collectEnvAllowlisted`) +// because a denylist is too easy to outflank by adding a new env var name. + +import { Flags } from "@oclif/core"; +import * as fs from "node:fs"; +import * as fsp from "node:fs/promises"; +import * as os from "node:os"; +import * as path from "node:path"; +import * as zlib from "node:zlib"; + +import { BaseCommand } from "../lib/base-command"; +import { getRecentLogLines } from "../infra/log/logger"; +import { + resolveAccountsDir, + resolveCodexDir, + resolveRegistryPath, + resolveSessionMapPath, +} from "../lib/config/paths"; + +// Env var name allowlist. Anything not in this list is dropped before the +// bundle is written. Tokens / keys / passwords / secrets never appear here. +const ENV_ALLOWLIST_LITERAL = new Set([ + "NODE_ENV", + "NODE_VERSION", + "PATH", + "HOME", + "SHELL", + "TERM", + "OS", + "PLATFORM", +]); + +// Prefixes that are considered safe (authmux/codex flag knobs only). +const ENV_ALLOWLIST_PREFIXES = ["CODEX_AUTH_", "AUTHMUX_"]; + +// Defense-in-depth: even if a future contributor adds one of these to the +// prefix lists by mistake, the suffix check below catches anything that +// looks remotely credential-shaped. +const FORBIDDEN_SUFFIXES = ["TOKEN", "KEY", "PASSWORD", "SECRET", "COOKIE"]; + +interface EnvEntry { + name: string; + value: string; +} + +export function collectEnvAllowlisted( + source: NodeJS.ProcessEnv = process.env, +): EnvEntry[] { + const out: EnvEntry[] = []; + for (const [rawName, rawValue] of Object.entries(source)) { + if (rawValue === undefined) continue; + const name = rawName; + if (isAllowlistedEnvName(name) === false) continue; + + let value = String(rawValue); + // PATH gets truncated to keep the bundle small and to avoid leaking + // unrelated tool installs. + if (name === "PATH" && value.length > 256) { + value = value.slice(0, 256) + "..."; + } + // HOME is reported by length only, never by value. The actual home + // dir often appears in support requests anyway, but redacting here + // keeps the diag bundle conservative. + if (name === "HOME") { + value = ``; + } + out.push({ name, value }); + } + out.sort((a, b) => a.name.localeCompare(b.name)); + return out; +} + +function isAllowlistedEnvName(name: string): boolean { + // Block credential-shaped names regardless of any prefix match. + for (const suffix of FORBIDDEN_SUFFIXES) { + if (name === suffix) return false; + if (name.endsWith("_" + suffix) || name.endsWith(suffix)) return false; + } + if (ENV_ALLOWLIST_LITERAL.has(name)) return true; + for (const prefix of ENV_ALLOWLIST_PREFIXES) { + if (name.startsWith(prefix)) return true; + } + return false; +} + +interface AccountsListing { + dir: string; + exists: boolean; + entries: Array<{ name: string; size: number; mtime: string }>; +} + +async function listAccountsDir(): Promise { + const dir = resolveAccountsDir(); + let exists = false; + try { + const st = await fsp.stat(dir); + exists = st.isDirectory(); + } catch { + exists = false; + } + if (!exists) return { dir, exists, entries: [] }; + + const names = await fsp.readdir(dir); + const entries: AccountsListing["entries"] = []; + for (const name of names) { + const full = path.join(dir, name); + try { + const st = await fsp.stat(full); + // Files only. Subdirs are surfaced as 0-byte entries with their + // mtime so users see backup vault presence. + entries.push({ + name, + size: st.isFile() ? st.size : 0, + mtime: new Date(st.mtimeMs).toISOString(), + }); + } catch { + // Skip unreadable entries. + } + } + entries.sort((a, b) => a.name.localeCompare(b.name)); + return { dir, exists, entries }; +} + +interface DiagBundle { + generatedAt: string; + authmuxVersion: string; + nodeVersion: string; + platform: { os: NodeJS.Platform; arch: string; release: string }; + paths: { + codexDir: string; + accountsDir: string; + registry: string; + sessions: string; + }; + env: EnvEntry[]; + accounts: AccountsListing; + logTail: string[]; +} + +async function readAuthmuxVersion(): Promise { + // Resolve relative to the compiled dist layout: `dist/commands/diag.js` + // → look up two levels for package.json. Falls back to "unknown". + const candidate = path.join(__dirname, "..", "..", "package.json"); + try { + const raw = await fsp.readFile(candidate, "utf8"); + const pkg = JSON.parse(raw) as { version?: string }; + return pkg.version ?? "unknown"; + } catch { + return "unknown"; + } +} + +export async function collectDiag(): Promise { + const version = await readAuthmuxVersion(); + const accounts = await listAccountsDir(); + return { + generatedAt: new Date().toISOString(), + authmuxVersion: version, + nodeVersion: process.version, + platform: { + os: process.platform, + arch: process.arch, + release: os.release(), + }, + paths: { + codexDir: resolveCodexDir(), + accountsDir: resolveAccountsDir(), + registry: resolveRegistryPath(), + sessions: resolveSessionMapPath(), + }, + env: collectEnvAllowlisted(), + accounts, + logTail: getRecentLogLines(), + }; +} + +function renderHumanSummary(b: DiagBundle): string { + const lines: string[] = []; + lines.push(`authmux diag — ${b.generatedAt}`); + lines.push(`version : ${b.authmuxVersion}`); + lines.push(`node : ${b.nodeVersion}`); + lines.push(`platform : ${b.platform.os} ${b.platform.arch} (${b.platform.release})`); + lines.push(""); + lines.push("paths"); + lines.push(` codex dir : ${b.paths.codexDir}`); + lines.push(` accounts dir : ${b.paths.accountsDir}`); + lines.push(` registry : ${b.paths.registry}`); + lines.push(` sessions : ${b.paths.sessions}`); + lines.push(""); + lines.push(`accounts dir entries: ${b.accounts.entries.length}`); + for (const e of b.accounts.entries) { + lines.push(` ${e.name} (size=${e.size}, mtime=${e.mtime})`); + } + lines.push(""); + lines.push("env (allowlisted)"); + for (const e of b.env) { + lines.push(` ${e.name}=${e.value}`); + } + lines.push(""); + lines.push(`log tail: ${b.logTail.length} line(s)`); + return lines.join("\n"); +} + +// Minimal in-memory ustar tar writer. We only need to pack a handful of +// small text files, so streaming/long-name handling is out of scope. +function tarEntry(filename: string, body: Buffer): Buffer { + if (Buffer.byteLength(filename) > 100) { + throw new Error(`diag: tar filename too long: ${filename}`); + } + const header = Buffer.alloc(512); + header.write(filename, 0, 100, "utf8"); + header.write("0000644", 100, 7, "utf8"); // mode + header.write("0000000", 108, 7, "utf8"); // uid + header.write("0000000", 116, 7, "utf8"); // gid + header.write(body.length.toString(8).padStart(11, "0"), 124, 11, "utf8"); + header.write(Math.floor(Date.now() / 1000).toString(8).padStart(11, "0"), 136, 11, "utf8"); + // checksum placeholder + header.write(" ", 148, 8, "utf8"); + header.write("0", 156, 1, "utf8"); // typeflag (normal file) + header.write("ustar\0", 257, 6, "utf8"); + header.write("00", 263, 2, "utf8"); + // compute checksum + let sum = 0; + for (let i = 0; i < 512; i++) sum += header[i]; + const checksum = sum.toString(8).padStart(6, "0") + "\0 "; + header.write(checksum, 148, 8, "utf8"); + + const padLen = (512 - (body.length % 512)) % 512; + return Buffer.concat([header, body, Buffer.alloc(padLen)]); +} + +function buildTarball(files: Array<{ name: string; body: string }>): Buffer { + const parts: Buffer[] = []; + for (const f of files) { + parts.push(tarEntry(f.name, Buffer.from(f.body, "utf8"))); + } + // Two 512-byte zero blocks mark end-of-archive. + parts.push(Buffer.alloc(1024)); + return Buffer.concat(parts); +} + +export interface WriteBundleResult { + outPath: string; + bytes: number; +} + +export async function writeDiagBundle( + bundle: DiagBundle, + cwd: string = process.cwd(), +): Promise { + const ts = bundle.generatedAt.replace(/[:.]/g, "-"); + const stem = `authmux-diag-${ts}`; + const outPath = path.join(cwd, `${stem}.tgz`); + + const files = [ + { name: `${stem}/summary.txt`, body: renderHumanSummary(bundle) }, + { name: `${stem}/bundle.json`, body: JSON.stringify(bundle, null, 2) }, + { name: `${stem}/log-tail.jsonl`, body: bundle.logTail.join("\n") + (bundle.logTail.length > 0 ? "\n" : "") }, + ]; + + const tar = buildTarball(files); + const gz = zlib.gzipSync(tar); + await fsp.writeFile(outPath, gz); + return { outPath, bytes: gz.length }; +} + +export default class DiagCommand extends BaseCommand { + static description = + "Write a redacted diagnostic bundle to the current dir (authmux-diag-.tgz)."; + + static flags = { + ...BaseCommand.jsonFlag, + "print-env": Flags.boolean({ + description: + "Print the allowlisted env table to stdout (for verification).", + default: false, + }), + } as const; + + // The diag command must work even when there is no auth.json yet, so + // suppress the BaseCommand's external-sync preflight. + protected readonly syncExternalAuthBeforeRun: boolean = false; + + async run(): Promise { + const { flags } = await this.parse(DiagCommand); + this.setJsonMode(flags); + + await this.runSafe(async () => { + const bundle = await collectDiag(); + + if (flags["print-env"]) { + for (const e of bundle.env) { + this.log(`${e.name}=${e.value}`); + } + return; + } + + let result: WriteBundleResult; + try { + result = await writeDiagBundle(bundle); + } catch (err) { + const msg = err instanceof Error ? err.message : String(err); + // Fallback: write a plain directory if tar packing fails. + const ts = bundle.generatedAt.replace(/[:.]/g, "-"); + const stem = `authmux-diag-${ts}`; + const dir = path.join(process.cwd(), stem); + fs.mkdirSync(dir, { recursive: true }); + await fsp.writeFile( + path.join(dir, "summary.txt"), + renderHumanSummary(bundle), + ); + await fsp.writeFile( + path.join(dir, "bundle.json"), + JSON.stringify(bundle, null, 2), + ); + await fsp.writeFile( + path.join(dir, "log-tail.jsonl"), + bundle.logTail.join("\n") + (bundle.logTail.length > 0 ? "\n" : ""), + ); + this.emit( + { ok: true, outPath: dir, fallback: true, error: msg }, + (d) => { + this.log(`wrote diag bundle (uncompressed): ${d.outPath}`); + }, + ); + return; + } + + this.emit(result, (d) => { + this.log(`wrote diag bundle: ${d.outPath} (${d.bytes} bytes)`); + }); + }); + } +} diff --git a/src/infra/log/logger.ts b/src/infra/log/logger.ts new file mode 100644 index 0000000..0d7021e --- /dev/null +++ b/src/infra/log/logger.ts @@ -0,0 +1,158 @@ +// Tiny structured logger for Theme X3 (Observability v1). +// +// Zero transitive deps; only `node:` built-ins. Default mode is a +// human-readable single line to stderr. `AUTHMUX_LOG=json` switches to +// JSON-lines (one event per line) so log aggregators can parse without +// a regex. The event shape is pin-compatible with `AuthmuxError.toJSON()` +// from N3 — both serialize a `code` (or a `msg`) plus a `details`-style +// bag of structured fields. +// +// A small in-memory ring buffer keeps the last 200 JSON-encoded lines for +// `authmux diag` to bundle. It never persists to disk. + +import { randomBytes } from "node:crypto"; + +export type LogLevel = "debug" | "info" | "warn" | "error"; + +export interface LogFields { + [key: string]: unknown; +} + +export interface Logger { + debug(msg: string, fields?: LogFields): void; + info(msg: string, fields?: LogFields): void; + warn(msg: string, fields?: LogFields): void; + error(msg: string, fields?: LogFields): void; + child(extra: LogFields): Logger; +} + +const LEVELS: Record = { + debug: 10, + info: 20, + warn: 30, + error: 40, +}; + +function resolveLevel(): LogLevel { + const raw = (process.env.AUTHMUX_LOG_LEVEL || "").trim().toLowerCase(); + if (raw === "debug" || raw === "info" || raw === "warn" || raw === "error") { + return raw; + } + return "info"; +} + +function resolveMode(): "json" | "pretty" { + const raw = (process.env.AUTHMUX_LOG || "").trim().toLowerCase(); + return raw === "json" ? "json" : "pretty"; +} + +// In-memory ring buffer of the last 200 JSON-line records. The buffer is +// always JSON-shaped regardless of the active mode so `authmux diag` can +// emit a uniform tail. +const RING_CAPACITY = 200; +const ring: string[] = []; + +function pushRing(line: string): void { + if (ring.length >= RING_CAPACITY) ring.shift(); + ring.push(line); +} + +export function getRecentLogLines(): string[] { + return ring.slice(); +} + +export function clearRecentLogLines(): void { + ring.length = 0; +} + +export function newCorrelationId(): string { + return randomBytes(8).toString("hex"); +} + +function writeLine(line: string): void { + // Stderr to keep stdout clean for command output / `--json` envelopes. + try { + process.stderr.write(line + "\n"); + } catch { + // best-effort + } +} + +function formatPretty( + level: LogLevel, + ts: string, + msg: string, + fields: LogFields, +): string { + const parts: string[] = []; + for (const [k, v] of Object.entries(fields)) { + if (v === undefined) continue; + let serialized: string; + if (typeof v === "string") { + serialized = /\s|"|=/.test(v) ? JSON.stringify(v) : v; + } else if (typeof v === "number" || typeof v === "boolean" || v === null) { + serialized = String(v); + } else { + try { + serialized = JSON.stringify(v); + } catch { + serialized = String(v); + } + } + parts.push(`${k}=${serialized}`); + } + const tail = parts.length > 0 ? " " + parts.join(" ") : ""; + return `${level.toUpperCase()} ${ts} ${msg}${tail}`; +} + +function emit( + level: LogLevel, + msg: string, + fields: LogFields, + bound: LogFields, +): void { + if (LEVELS[level] < LEVELS[resolveLevel()]) return; + + const ts = new Date().toISOString(); + // Merge bound (child) fields under user-provided fields. User wins on + // collision so callers can override correlationId per-call if needed. + const merged: LogFields = { ...bound, ...fields }; + + // Always cache a JSON line in the ring for diag. + const jsonEvent = { level, ts, msg, ...merged }; + let jsonLine: string; + try { + jsonLine = JSON.stringify(jsonEvent); + } catch { + jsonLine = JSON.stringify({ level, ts, msg, _serializeError: true }); + } + pushRing(jsonLine); + + if (resolveMode() === "json") { + writeLine(jsonLine); + } else { + writeLine(formatPretty(level, ts, msg, merged)); + } +} + +function makeLogger(bound: LogFields): Logger { + return { + debug(msg, fields) { + emit("debug", msg, fields ?? {}, bound); + }, + info(msg, fields) { + emit("info", msg, fields ?? {}, bound); + }, + warn(msg, fields) { + emit("warn", msg, fields ?? {}, bound); + }, + error(msg, fields) { + emit("error", msg, fields ?? {}, bound); + }, + child(extra) { + return makeLogger({ ...bound, ...extra }); + }, + }; +} + +export const logger: Logger = makeLogger({}); diff --git a/src/lib/accounts/auto-switch/policy.ts b/src/lib/accounts/auto-switch/policy.ts index e72edc3..b8fcdba 100644 --- a/src/lib/accounts/auto-switch/policy.ts +++ b/src/lib/accounts/auto-switch/policy.ts @@ -4,6 +4,12 @@ // fresh usage for the active account, compares to the configured // thresholds, and if low promotes the candidate with the highest // remaining quota. `runDaemon("watch")` runs the loop with a 30s cycle. +// +// Theme X3: each evaluation cycle emits one `daemon.cycle.start` and one +// `daemon.cycle.end` structured event sharing a correlation id so a log +// reader can pair them. Per the X3 redaction contract we never log auth +// bytes or snapshot file contents — only counts, account names, and +// scalar outcomes. import { AutoSwitchRunResult, RegistryData } from "../types"; import { @@ -17,6 +23,7 @@ import { } from "../_internal/registry-ops"; import { activateSnapshot } from "../write/use"; import { refreshAccountUsage } from "../usage/adapter"; +import { logger, newCorrelationId } from "../../../infra/log/logger"; export function selectBestCandidateFromRegistry( candidates: string[], @@ -40,6 +47,48 @@ export function selectBestCandidateFromRegistry( export async function runAutoSwitchOnce( getCurrentAccountName: () => Promise, +): Promise { + const correlationId = newCorrelationId(); + const cycleLog = logger.child({ correlationId }); + const startedAt = Date.now(); + + cycleLog.info("daemon.cycle.start", {}); + + let result: AutoSwitchRunResult; + try { + result = await runAutoSwitchOnceImpl(getCurrentAccountName, cycleLog); + } catch (err) { + const ms = Date.now() - startedAt; + cycleLog.error("daemon.cycle.end", { + ms, + action: "error", + error: err instanceof Error ? err.message : String(err), + }); + throw err; + } + + const ms = Date.now() - startedAt; + if (result.switched) { + cycleLog.info("daemon.cycle.end", { + ms, + action: "switched", + from: result.fromAccount, + to: result.toAccount, + }); + } else { + cycleLog.info("daemon.cycle.end", { + ms, + action: "noop", + reason: result.reason, + }); + } + + return result; +} + +async function runAutoSwitchOnceImpl( + getCurrentAccountName: () => Promise, + cycleLog: typeof logger, ): Promise { const registry = await loadReconciledRegistry(); if (!registry.autoSwitch.enabled) { @@ -56,6 +105,11 @@ export async function runAutoSwitchOnce( return { switched: false, reason: "no active account" }; } + cycleLog.debug("daemon.cycle.eval", { + accountsCount: accountNames.length, + active, + }); + const nowSeconds = Math.floor(Date.now() / 1000); const activeUsage = await refreshAccountUsage(registry, active, { diff --git a/src/tests/diag-redaction.test.ts b/src/tests/diag-redaction.test.ts new file mode 100644 index 0000000..60d2327 --- /dev/null +++ b/src/tests/diag-redaction.test.ts @@ -0,0 +1,75 @@ +// Theme X3 redaction guard. +// +// The diag command uses an env allowlist. This test pokes a handful of +// "obviously sensitive" var names into an isolated env, runs the +// allowlist collector, and asserts: +// - secret-shaped values never appear in the output +// - approved AUTHMUX_* / CODEX_AUTH_* flags do appear +// - HOME's literal value is never emitted (length-only stand-in) + +import test from "node:test"; +import assert from "node:assert/strict"; + +import { collectEnvAllowlisted } from "../commands/diag"; + +test("env allowlist drops OPENAI_API_KEY and *_TOKEN/*_SECRET names", () => { + const fakeEnv: NodeJS.ProcessEnv = { + OPENAI_API_KEY: "sk-leak-1", + MY_TOKEN: "leak-token", + DB_PASSWORD: "leak-pw", + SOME_SECRET: "leak-secret", + AWS_ACCESS_KEY: "leak-aws", + CODEX_AUTH_DEBUG: "1", + AUTHMUX_LOG: "json", + PATH: "/usr/bin", + HOME: "/home/alice", + NODE_ENV: "test", + }; + + const out = collectEnvAllowlisted(fakeEnv); + const flat = out.map((e) => `${e.name}=${e.value}`).join("\n"); + + // None of the secret-shaped values may appear, by name or by value. + assert.ok(!flat.includes("sk-leak-1"), "OPENAI_API_KEY value leaked"); + assert.ok(!flat.includes("leak-token"), "*_TOKEN value leaked"); + assert.ok(!flat.includes("leak-pw"), "*_PASSWORD value leaked"); + assert.ok(!flat.includes("leak-secret"), "*_SECRET value leaked"); + assert.ok(!flat.includes("leak-aws"), "*_KEY value leaked"); + assert.ok(!flat.includes("OPENAI_API_KEY"), "OPENAI_API_KEY name leaked"); + assert.ok(!flat.includes("MY_TOKEN"), "MY_TOKEN name leaked"); + assert.ok(!flat.includes("DB_PASSWORD"), "DB_PASSWORD name leaked"); + assert.ok(!flat.includes("SOME_SECRET"), "SOME_SECRET name leaked"); + assert.ok(!flat.includes("AWS_ACCESS_KEY"), "AWS_ACCESS_KEY name leaked"); + + // Approved flags do show up. + assert.ok(flat.includes("CODEX_AUTH_DEBUG=1"), "CODEX_AUTH_DEBUG missing"); + assert.ok(flat.includes("AUTHMUX_LOG=json"), "AUTHMUX_LOG missing"); + assert.ok(flat.includes("NODE_ENV=test"), "NODE_ENV missing"); + assert.ok(flat.includes("PATH=/usr/bin"), "PATH missing"); + + // HOME is in the allowlist but its literal value is replaced by a + // length-only stand-in. + const home = out.find((e) => e.name === "HOME"); + assert.ok(home, "HOME should be in output"); + assert.ok( + home!.value.startsWith(" { + // Defense-in-depth: an allowlist prefix must not waive the suffix check. + const fakeEnv: NodeJS.ProcessEnv = { + AUTHMUX_DEBUG_TOKEN: "leak-1", + AUTHMUX_API_KEY: "leak-2", + AUTHMUX_USER_PASSWORD: "leak-3", + AUTHMUX_LOG_LEVEL: "info", + }; + const out = collectEnvAllowlisted(fakeEnv); + const flat = out.map((e) => `${e.name}=${e.value}`).join("\n"); + assert.ok(!flat.includes("leak-1"), "AUTHMUX_DEBUG_TOKEN should be filtered"); + assert.ok(!flat.includes("leak-2"), "AUTHMUX_API_KEY should be filtered"); + assert.ok(!flat.includes("leak-3"), "AUTHMUX_USER_PASSWORD should be filtered"); + assert.ok(flat.includes("AUTHMUX_LOG_LEVEL=info"), "AUTHMUX_LOG_LEVEL missing"); +}); diff --git a/src/tests/logger.test.ts b/src/tests/logger.test.ts new file mode 100644 index 0000000..756b433 --- /dev/null +++ b/src/tests/logger.test.ts @@ -0,0 +1,67 @@ +// Theme X3 logger smoke tests. Focus: ring buffer + correlation IDs + +// JSON-mode line shape. We never assert on the stderr stream because the +// logger writes through `process.stderr.write` directly; the in-memory +// ring buffer is the test-friendly observation point. + +import test from "node:test"; +import assert from "node:assert/strict"; + +import { + clearRecentLogLines, + getRecentLogLines, + logger, + newCorrelationId, +} from "../infra/log/logger"; + +test("logger ring captures the latest events", () => { + clearRecentLogLines(); + logger.info("hello", { a: 1 }); + logger.warn("boom", { b: "two" }); + + const lines = getRecentLogLines(); + assert.equal(lines.length, 2); + const first = JSON.parse(lines[0]); + assert.equal(first.level, "info"); + assert.equal(first.msg, "hello"); + assert.equal(first.a, 1); + const second = JSON.parse(lines[1]); + assert.equal(second.level, "warn"); + assert.equal(second.b, "two"); +}); + +test("child logger injects correlationId into every event", () => { + clearRecentLogLines(); + const cid = newCorrelationId(); + const child = logger.child({ correlationId: cid }); + child.info("daemon.cycle.start", {}); + child.info("daemon.cycle.end", { ms: 12, action: "noop" }); + + const lines = getRecentLogLines().map((l) => JSON.parse(l)); + assert.equal(lines.length, 2); + assert.equal(lines[0].correlationId, cid); + assert.equal(lines[1].correlationId, cid); + assert.equal(lines[1].action, "noop"); + assert.equal(lines[1].ms, 12); +}); + +test("newCorrelationId returns 16 hex chars", () => { + const a = newCorrelationId(); + const b = newCorrelationId(); + assert.match(a, /^[0-9a-f]{16}$/); + assert.match(b, /^[0-9a-f]{16}$/); + assert.notEqual(a, b); +}); + +test("ring buffer caps at 200 entries", () => { + clearRecentLogLines(); + for (let i = 0; i < 250; i++) { + logger.info("event", { i }); + } + const lines = getRecentLogLines(); + assert.equal(lines.length, 200); + // The earliest surviving entry must be i=50 (we dropped 0..49). + const first = JSON.parse(lines[0]); + assert.equal(first.i, 50); + const last = JSON.parse(lines[lines.length - 1]); + assert.equal(last.i, 249); +});