Merge file-backed log sink

Author: TheGreatAxios

src/index.ts

@@ -3,6 +3,7 @@ import { LOG_NAMESPACE_ROOT } from "./branding.js";
 import { primeCrashReporting, writeCrashReport, type CrashKind } from "./crash/report.js";
 import { loadConfig } from "./config/index.js";
 import { ensureTelemetrySettings, globalSettingsPath } from "./config/settings.js";
+import { installFileLogSink } from "./logging/sink.js";
 import { flushPerfToOtel } from "./perf/index.js";
 import { createTelemetry, telemetryDisabledByEnv } from "./telemetry/index.js";
 import { getTelemetry, setTelemetry } from "./telemetry/singleton.js";
@@ -20,6 +21,12 @@ export async function mainWithRunners(
   argv: readonly string[],
   runners: Runners,
 ): Promise<number> {
+  // Must run before any other line: @intx/log installs a console sink as a
+  // side effect of import, and loadConfig itself can log (e.g. healed
+  // settings). Once installed, this replaces that default so nothing —
+  // including a vendored dependency's logger — reaches the terminal the
+  // TUI is about to own.
+  installFileLogSink();
   const config = await loadConfig(argv, { allowUnconfigured: true });
   // Resolve the crash-report directory once, up front, while the process is
   // healthy. This is the only place project-key resolution (which shells

src/logging/sink.test.ts

@@ -0,0 +1,41 @@
+import { describe, expect, spyOn, test } from "bun:test";
+import { mkdtempSync, readFileSync, rmSync } from "node:fs";
+import { tmpdir } from "node:os";
+import { join } from "node:path";
+import { getLogger } from "@intx/log";
+
+import { corbitsLogFilePath, installFileLogSink } from "./sink.js";
+
+describe("corbitsLogFilePath", () => {
+  test("nests under the settings dir, not directly in home", () => {
+    expect(corbitsLogFilePath("/home/dev")).toBe("/home/dev/.corbits/logs/corbits.log");
+  });
+});
+
+describe("installFileLogSink", () => {
+  test("routes a logger's output to the file, never to stdout/stderr", () => {
+    const dir = mkdtempSync(join(tmpdir(), "corbits-sink-test-"));
+    const file = join(dir, "corbits.log");
+    try {
+      installFileLogSink(file);
+
+      const stdoutWrite = spyOn(process.stdout, "write");
+      const stderrWrite = spyOn(process.stderr, "write");
+      try {
+        getLogger(["some", "vendored", "logger"]).error("boom {detail}", { detail: "bad" });
+      } finally {
+        stdoutWrite.mockRestore();
+        stderrWrite.mockRestore();
+      }
+
+      expect(stdoutWrite).not.toHaveBeenCalled();
+      expect(stderrWrite).not.toHaveBeenCalled();
+
+      const logged = readFileSync(file, "utf8");
+      expect(logged).toContain("boom bad");
+      expect(logged).toContain("some.vendored.logger");
+    } finally {
+      rmSync(dir, { recursive: true, force: true });
+    }
+  });
+});

src/logging/sink.ts

@@ -0,0 +1,69 @@
+import { appendFileSync, mkdirSync } from "node:fs";
+import { homedir } from "node:os";
+import { dirname, join } from "node:path";
+
+import { configureSync } from "@intx/log";
+
+import { SETTINGS_DIR_NAME } from "../branding.js";
+
+// Matches LogTape's Sink shape structurally (see @logtape/logtape's
+// sink.d.ts); not imported directly since only @intx/log is a declared
+// dependency here. The real type is strictly wider than this — if LogTape
+// ever renames or narrows one of these fields, nothing here will catch the
+// drift, so keep this in sync by hand if @intx/log's pinned version moves.
+type LogRecord = {
+  readonly category: readonly string[];
+  readonly level: string;
+  readonly message: readonly unknown[];
+  readonly timestamp: number;
+  readonly properties: Record<string, unknown>;
+};
+
+export function corbitsLogFilePath(home: string = homedir()): string {
+  return join(home, SETTINGS_DIR_NAME, "logs", "corbits.log");
+}
+
+function formatRecord(record: LogRecord): string {
+  return (
+    JSON.stringify({
+      timestamp: new Date(record.timestamp).toISOString(),
+      level: record.level,
+      category: record.category.join("."),
+      message: record.message.join(""),
+      properties: record.properties,
+    }) + "\n"
+  );
+}
+
+/**
+ * Routes every logger — including ones inside vendored dependencies, which
+ * Corbits cannot edit — to a file instead of the console.
+ *
+ * `@intx/log` installs a console sink as a side effect of its first import
+ * (see its `default-sink` module), so a bare `getLogger` import is enough
+ * for a log call to reach stdout/stderr before Corbits does anything. This
+ * must run before any other Corbits code executes — first statement in
+ * `mainWithRunners` — so that race is never live: the TUI holds the
+ * alternate screen for the rest of the process, and anything landing on
+ * the real terminal mid-frame corrupts it.
+ */
+export function installFileLogSink(path: string = corbitsLogFilePath()): void {
+  mkdirSync(dirname(path), { recursive: true });
+  configureSync({
+    reset: true,
+    sinks: {
+      file: (record: LogRecord) => {
+        appendFileSync(path, formatRecord(record));
+      },
+    },
+    // "debug" (not "warning"): a file has no screen to corrupt, and several
+    // teardown-race diagnostics (e.g. src/tui/runner.ts, src/exec/runner.ts)
+    // are logger.debug calls that exist specifically to be readable here
+    // after the fact. Filtering them out at the sink would silently disable
+    // the diagnostics the file exists to capture.
+    loggers: [
+      { category: ["logtape", "meta"], lowestLevel: "warning", sinks: ["file"] },
+      { category: [], lowestLevel: "debug", sinks: ["file"] },
+    ],
+  });
+}

src/tui-opentui/log-sink.test.ts

@@ -0,0 +1,69 @@
+/**
+ * CL-5593: a raw structured log line from a vendored logger
+ * (`interchange.inference.default-director`) painted itself over the prompt
+ * box mid-frame, because nothing had ever pointed LogTape away from its
+ * default console sink. This drives the real shell in a live session and
+ * fires that exact logger the way the vendored code does, then asserts the
+ * rendered frame is untouched and nothing reached stdout/stderr.
+ */
+import { afterEach, beforeEach, describe, expect, spyOn, test } from "bun:test"
+import { mkdtempSync, rmSync, readFileSync } from "node:fs"
+import { tmpdir } from "node:os"
+import { join } from "node:path"
+import { getLogger } from "@intx/log"
+
+import { installFileLogSink } from "../logging/sink.js"
+import { createAppShell } from "./shell.js"
+import { withTestRenderer } from "./harness.js"
+
+describe("log sink during a live TUI session", () => {
+  let logDir: string
+  let logFile: string
+
+  beforeEach(() => {
+    logDir = mkdtempSync(join(tmpdir(), "corbits-log-sink-test-"))
+    logFile = join(logDir, "corbits.log")
+  })
+
+  afterEach(() => {
+    rmSync(logDir, { recursive: true, force: true })
+  })
+
+  test("a vendored logger's error never reaches stdout, stderr, or the frame", async () => {
+    installFileLogSink(logFile)
+
+    const stdoutWrite = spyOn(process.stdout, "write")
+    const stderrWrite = spyOn(process.stderr, "write")
+
+    try {
+      await withTestRenderer(async (h) => {
+        const shell = createAppShell(h.renderer, { cwd: "/workspace/corbits-code" })
+        await h.renderOnce()
+
+        const before = h.captureCharFrame()
+        expect(before).toContain("/workspace/corbits-code")
+
+        // Same category and tagged-template call shape as
+        // vendor/intx-inference's default-director.
+        const vendoredLogger = getLogger(["interchange", "inference", "default-director"])
+        vendoredLogger.error`Inference error in default director: ${"could not be verified"} [HTTP 400] (category: ${"fatal"})`
+
+        await h.renderOnce()
+        const after = h.captureCharFrame()
+
+        expect(after).toContain("/workspace/corbits-code")
+        expect(after).not.toContain("@timestamp")
+        expect(after).not.toContain("interchange.inference.default-director")
+      })
+    } finally {
+      stdoutWrite.mockRestore()
+      stderrWrite.mockRestore()
+    }
+
+    expect(stdoutWrite).not.toHaveBeenCalled()
+    expect(stderrWrite).not.toHaveBeenCalled()
+
+    const logged = readFileSync(logFile, "utf8")
+    expect(logged).toContain("interchange.inference.default-director")
+  })
+})