fix(FN-2371): preserve log severity in dashboard TUI capture

- Add severity control markers to core and engine structured loggers while keeping info logs on stderr transport - Parse and strip internal severity markers in dashboard TUI console capture so logger.log entries render with info icons instead of error icons - Expand dashboard TUI tests to cover captured console severity mapping and structured logger behavior, plus logger unit tests in core/engine - Add a patch changeset for @runfusion/fusion describing the TUI log severity icon fix
2026-04-24 01:11:51 -07:00
parent ea079ef153
commit 31f021a03e
9 changed files with 229 additions and 41 deletions
--- a/.changeset/fix-tui-log-severity-icons.md
+++ b/.changeset/fix-tui-log-severity-icons.md
@@ -0,0 +1,5 @@
+---
+"@runfusion/fusion": patch
+---
+
+Fix dashboard TUI log severity rendering so structured `logger.log(...)` entries routed via `stderr` display with info severity/icon instead of being misclassified as errors.
--- a/packages/cli/src/tests/vitest-workspace-resolution.test.ts
+++ b/packages/cli/src/tests/vitest-workspace-resolution.test.ts
@@ -1,5 +1,5 @@
 import { afterAll, beforeAll, describe, expect, it } from "vitest";
-import { existsSync, renameSync } from "node:fs";
+import { existsSync, renameSync, rmSync } from "node:fs";
 import { join } from "node:path";
 import vitestConfig from "../../vitest.config";

@@ -17,6 +17,9 @@ function hideInternalPackageDistDirs() {
    }

    const hiddenPath = `${distPath}.__fn2360-hidden-${process.pid}`;
+    if (existsSync(hiddenPath)) {
+      rmSync(hiddenPath, { recursive: true, force: true });
+    }
    renameSync(distPath, hiddenPath);
    movedDistDirs.push({ from: distPath, to: hiddenPath });
  }
@@ -26,6 +29,9 @@ function restoreInternalPackageDistDirs() {
  for (let i = movedDistDirs.length - 1; i >= 0; i--) {
    const { from, to } = movedDistDirs[i];
    if (existsSync(to)) {
+      if (existsSync(from)) {
+        rmSync(from, { recursive: true, force: true });
+      }
      renameSync(to, from);
    }
  }
--- a/packages/cli/src/commands/dashboard-tui.test.ts
+++ b/packages/cli/src/commands/dashboard-tui.test.ts
@@ -10,6 +10,7 @@ import {
  type TaskStats,
  type SettingsValues,
 } from "./dashboard-tui.js";
+import { createLogger } from "@fusion/engine";

 // ── LogRingBuffer Tests ────────────────────────────────────────────────────

@@ -197,7 +198,7 @@ describe("DashboardLogSink.captureConsole", () => {
    sink.releaseConsole();
  });

-  it("routes console.error to sink.error", () => {
+  it("keeps raw console.error lines as error", () => {
    const tui = new DashboardTUI();
    const sink = new DashboardLogSink();
    sink.setTUI(tui);
@@ -215,6 +216,46 @@ describe("DashboardLogSink.captureConsole", () => {
    sink.releaseConsole();
  });

+  it("treats structured logger.log routed via console.error as info", () => {
+    const tui = new DashboardTUI();
+    const sink = new DashboardLogSink();
+    sink.setTUI(tui);
+    sink.captureConsole();
+
+    const logger = createLogger("executor");
+    logger.log("task moved to in-progress");
+
+    const entries = (tui as unknown as {
+      logBuffer: LogRingBuffer;
+    }).logBuffer.getAll();
+    expect(entries).toHaveLength(1);
+    expect(entries[0].level).toBe("info");
+    expect(entries[0].prefix).toBe("executor");
+    expect(entries[0].message).toBe("task moved to in-progress");
+
+    sink.releaseConsole();
+  });
+
+  it("keeps structured logger.error as error", () => {
+    const tui = new DashboardTUI();
+    const sink = new DashboardLogSink();
+    sink.setTUI(tui);
+    sink.captureConsole();
+
+    const logger = createLogger("executor");
+    logger.error("task failed");
+
+    const entries = (tui as unknown as {
+      logBuffer: LogRingBuffer;
+    }).logBuffer.getAll();
+    expect(entries).toHaveLength(1);
+    expect(entries[0].level).toBe("error");
+    expect(entries[0].prefix).toBe("executor");
+    expect(entries[0].message).toBe("task failed");
+
+    sink.releaseConsole();
+  });
+
  it("handles untagged messages without a prefix", () => {
    const tui = new DashboardTUI();
    const sink = new DashboardLogSink();
@@ -255,21 +296,59 @@ describe("DashboardLogSink.captureConsole", () => {
  });
 });

+describe("DashboardTUI log icon rendering", () => {
+  it("shows info icon (✓) instead of error icon (✗) for structured logger.log entries", () => {
+    const tui = new DashboardTUI();
+    const sink = new DashboardLogSink();
+    sink.setTUI(tui);
+    sink.captureConsole();
+
+    const stdoutWriteSpy = vi.spyOn(process.stdout, "write").mockImplementation(() => true);
+    (tui as any).activeSection = "logs";
+    (tui as any).isRunning = true;
+
+    try {
+      const logger = createLogger("executor");
+      logger.log("task moved to in-progress");
+
+      stdoutWriteSpy.mockClear();
+      (tui as any).renderLogsSection();
+      const rendered = stdoutWriteSpy.mock.calls.map(([chunk]) => String(chunk)).join("");
+      const stripped = rendered.replace(/\x1b\[[0-9;]*[a-zA-Z]/g, "");
+
+      expect(stripped).toContain("✓ [executor] task moved to in-progress");
+      expect(stripped).not.toContain("✗ [executor] task moved to in-progress");
+    } finally {
+      stdoutWriteSpy.mockRestore();
+      sink.releaseConsole();
+    }
+  });
+});
+
 // ── formatConsoleArgs helper ───────────────────────────────────────────────

 describe("formatConsoleArgs", () => {
  it("joins multiple args with a space", () => {
-    const { message, prefix } = formatConsoleArgs(["hello", "world"]);
+    const { message, prefix, level } = formatConsoleArgs(["hello", "world"]);
    expect(prefix).toBeUndefined();
+    expect(level).toBe("info");
    expect(message).toBe("hello world");
  });

  it("extracts a leading [prefix] tag", () => {
-    const { message, prefix } = formatConsoleArgs(["[executor] starting task FN-123"]);
+    const { message, prefix, level } = formatConsoleArgs(["[executor] starting task FN-123"], "warn");
    expect(prefix).toBe("executor");
+    expect(level).toBe("warn");
    expect(message).toBe("starting task FN-123");
  });

+  it("strips the internal severity marker and returns explicit level", () => {
+    const { message, prefix, level } = formatConsoleArgs(["\u0000fnlvl=error\u0000[executor] task failed"], "info");
+    expect(prefix).toBe("executor");
+    expect(level).toBe("error");
+    expect(message).toBe("task failed");
+  });
+
  it("stringifies objects via JSON", () => {
    const { message } = formatConsoleArgs(["result:", { ok: true, count: 3 }]);
    expect(message).toBe('result: {"ok":true,"count":3}');
--- a/packages/cli/src/commands/dashboard-tui.ts
+++ b/packages/cli/src/commands/dashboard-tui.ts
@@ -1339,9 +1339,11 @@ export class DashboardLogSink {
  /**
   * Monkey-patch `console.log/warn/error` so everything (including the engine's
   * createLogger() output, which writes directly to console.error) surfaces in
-   * the TUI's log ring buffer. Without this, most runtime logs render beneath
-   * the alt-screen TUI and are immediately overwritten on the next render,
-   * leaving the Logs tab nearly empty.
+   * the TUI's log ring buffer. Structured logger calls carry an internal
+   * severity marker so `logger.log(...)` still lands as info even when routed
+   * through console.error transport. Without capture, most runtime logs render
+   * beneath the alt-screen TUI and are immediately overwritten on the next
+   * render, leaving the Logs tab nearly empty.
   *
   * Messages that start with `[prefix] rest` are unpacked so the TUI stores
   * `prefix="prefix"` and `message="rest"`. Idempotent; call `releaseConsole()`
@@ -1358,16 +1360,16 @@ export class DashboardLogSink {
      error: console.error,
    };
    console.log = (...args: unknown[]) => {
-      const { message, prefix } = formatConsoleArgs(args);
-      this.log(message, prefix);
+      const { message, prefix, level } = formatConsoleArgs(args, "info");
+      this.writeCapturedConsoleLog(level, message, prefix);
    };
    console.warn = (...args: unknown[]) => {
-      const { message, prefix } = formatConsoleArgs(args);
-      this.warn(message, prefix);
+      const { message, prefix, level } = formatConsoleArgs(args, "warn");
+      this.writeCapturedConsoleLog(level, message, prefix);
    };
    console.error = (...args: unknown[]) => {
-      const { message, prefix } = formatConsoleArgs(args);
-      this.error(message, prefix);
+      const { message, prefix, level } = formatConsoleArgs(args, "error");
+      this.writeCapturedConsoleLog(level, message, prefix);
    };
  }

@@ -1379,15 +1381,33 @@ export class DashboardLogSink {
    console.error = this.originalConsole.error;
    this.originalConsole = null;
  }
+
+  private writeCapturedConsoleLog(level: LogEntry["level"], message: string, prefix?: string): void {
+    if (level === "error") {
+      this.error(message, prefix);
+      return;
+    }
+    if (level === "warn") {
+      this.warn(message, prefix);
+      return;
+    }
+    this.log(message, prefix);
+  }
 }

+const LOG_LEVEL_MARKER_REGEX = /^\u0000fnlvl=(info|warn|error)\u0000\s*/;
+
 /**
- * Format heterogeneous console args into a single string, and extract a
- * leading `[prefix]` if present. Mirrors `util.format` loosely without
- * the dependency — objects are JSON-stringified (defensively, falling back
- * to String()), everything else is coerced via String().
+ * Format heterogeneous console args into a single string, extracting a
+ * leading internal severity marker and `[prefix]` tag when present.
+ * Mirrors `util.format` loosely without the dependency — objects are
+ * JSON-stringified (defensively, falling back to String()), everything
+ * else is coerced via String().
 */
-export function formatConsoleArgs(args: unknown[]): { message: string; prefix?: string } {
+export function formatConsoleArgs(
+  args: unknown[],
+  fallbackLevel: LogEntry["level"] = "info",
+): { message: string; prefix?: string; level: LogEntry["level"] } {
  const stringified = args.map((arg) => {
    if (typeof arg === "string") return arg;
    if (arg instanceof Error) return arg.stack ?? arg.message;
@@ -1398,11 +1418,15 @@ export function formatConsoleArgs(args: unknown[]): { message: string; prefix?:
    return String(arg);
  }).join(" ");

-  const match = stringified.match(/^\[([^\]]+)\]\s*(.*)$/s);
+  const markerMatch = stringified.match(LOG_LEVEL_MARKER_REGEX);
+  const level = markerMatch?.[1] as LogEntry["level"] | undefined;
+  const withoutMarker = markerMatch ? stringified.replace(LOG_LEVEL_MARKER_REGEX, "") : stringified;
+
+  const match = withoutMarker.match(/^\[([^\]]+)\]\s*(.*)$/s);
  if (match) {
-    return { prefix: match[1], message: match[2] };
+    return { prefix: match[1], message: match[2], level: level ?? fallbackLevel };
  }
-  return { message: stringified };
+  return { message: withoutMarker, level: level ?? fallbackLevel };
 }

 // ── String Helpers ────────────────────────────────────────────────────────────
--- a/packages/core/src/logger.test.ts
+++ b/packages/core/src/logger.test.ts
@@ -0,0 +1,43 @@
+import { describe, it, expect, vi, beforeEach, afterEach } from "vitest";
+import { createLogger } from "./logger.js";
+
+describe("core createLogger", () => {
+  let logSpy: ReturnType<typeof vi.spyOn>;
+  let warnSpy: ReturnType<typeof vi.spyOn>;
+  let errorSpy: ReturnType<typeof vi.spyOn>;
+
+  beforeEach(() => {
+    logSpy = vi.spyOn(console, "log").mockImplementation(() => {});
+    warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
+    errorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
+  });
+
+  afterEach(() => {
+    logSpy.mockRestore();
+    warnSpy.mockRestore();
+    errorSpy.mockRestore();
+  });
+
+  it("emits info logs to stderr with an info severity marker", () => {
+    const logger = createLogger("core-test");
+    logger.log("hello");
+
+    expect(logSpy).not.toHaveBeenCalled();
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[core-test] hello");
+  });
+
+  it("emits warn logs with a warn severity marker", () => {
+    const logger = createLogger("core-test");
+    logger.warn("careful");
+
+    expect(warnSpy).toHaveBeenCalledWith("\u0000fnlvl=warn\u0000[core-test] careful");
+  });
+
+  it("emits error logs with an error severity marker", () => {
+    const logger = createLogger("core-test");
+    const err = new Error("boom");
+    logger.error("broken", err);
+
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=error\u0000[core-test] broken", err);
+  });
+});
--- a/packages/core/src/logger.ts
+++ b/packages/core/src/logger.ts
@@ -20,6 +20,13 @@ export interface Logger {
  error(message: string, ...args: unknown[]): void;
 }

+const LOG_LEVEL_MARKER_PREFIX = "\u0000fnlvl=";
+const LOG_LEVEL_MARKER_SUFFIX = "\u0000";
+
+function withSeverityMarker(level: "info" | "warn" | "error", payload: string): string {
+  return `${LOG_LEVEL_MARKER_PREFIX}${level}${LOG_LEVEL_MARKER_SUFFIX}${payload}`;
+}
+
 /**
 * Create a structured logger that prefixes every message with `[prefix]`.
 *
@@ -27,18 +34,22 @@ export interface Logger {
 * @returns A `Logger` whose output is prefixed and sent to stderr for normal
 *          logs and errors. Keeping logs off stdout prevents command/test
 *          output consumers from receiving Fusion execution chatter.
+ *
+ *          The logger prepends an internal control-character severity marker
+ *          so dashboard TUI console-capture can preserve info/warn/error
+ *          semantics even when `log()` is transported via `console.error`.
 */
 export function createLogger(prefix: string): Logger {
  const tag = `[${prefix}]`;
  return {
    log(message: string, ...args: unknown[]) {
-      console.error(`${tag} ${message}`, ...args);
+      console.error(withSeverityMarker("info", `${tag} ${message}`), ...args);
    },
    warn(message: string, ...args: unknown[]) {
-      console.warn(`${tag} ${message}`, ...args);
+      console.warn(withSeverityMarker("warn", `${tag} ${message}`), ...args);
    },
    error(message: string, ...args: unknown[]) {
-      console.error(`${tag} ${message}`, ...args);
+      console.error(withSeverityMarker("error", `${tag} ${message}`), ...args);
    },
  };
 }
--- a/packages/engine/src/logger.js
+++ b/packages/engine/src/logger.js
@@ -17,6 +17,11 @@
 * of control for filtering, suppressing (e.g. in tests), or redirecting
 * engine log output in the future.
 */
+const LOG_LEVEL_MARKER_PREFIX = "\0fnlvl=";
+const LOG_LEVEL_MARKER_SUFFIX = "\0";
+function withSeverityMarker(level, payload) {
+    return `${LOG_LEVEL_MARKER_PREFIX}${level}${LOG_LEVEL_MARKER_SUFFIX}${payload}`;
+}
 /**
 * Create a structured logger that prefixes every message with `[prefix]`.
 *
@@ -24,18 +29,22 @@
 * @returns A `Logger` whose output is prefixed and sent to stderr. Keeping
 *          engine logs off stdout prevents command/test output consumers from
 *          receiving Fusion execution chatter.
+ *
+ *          The logger prepends an internal control-character severity marker
+ *          so dashboard TUI console-capture can preserve info/warn/error
+ *          semantics even when `log()` is transported via `console.error`.
 */
 export function createLogger(prefix) {
    const tag = `[${prefix}]`;
    return {
        log(message, ...args) {
-            globalThis.console.error(`${tag} ${message}`, ...args);
+            globalThis.console.error(withSeverityMarker("info", `${tag} ${message}`), ...args);
        },
        warn(message, ...args) {
-            globalThis.console.warn(`${tag} ${message}`, ...args);
+            globalThis.console.warn(withSeverityMarker("warn", `${tag} ${message}`), ...args);
        },
        error(message, ...args) {
-            globalThis.console.error(`${tag} ${message}`, ...args);
+            globalThis.console.error(withSeverityMarker("error", `${tag} ${message}`), ...args);
        },
    };
 }
--- a/packages/engine/src/logger.test.ts
+++ b/packages/engine/src/logger.test.ts
@@ -31,26 +31,26 @@ describe("createLogger", () => {
    const logger = createLogger("test");
    logger.log("hello world");
    expect(logSpy).not.toHaveBeenCalled();
-    expect(errorSpy).toHaveBeenCalledWith("[test] hello world");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[test] hello world");
  });

  it("formats warn output as [prefix] message", () => {
    const logger = createLogger("test");
    logger.warn("something happened");
-    expect(warnSpy).toHaveBeenCalledWith("[test] something happened");
+    expect(warnSpy).toHaveBeenCalledWith("\u0000fnlvl=warn\u0000[test] something happened");
  });

  it("formats error output as [prefix] message", () => {
    const logger = createLogger("test");
    logger.error("failure");
-    expect(errorSpy).toHaveBeenCalledWith("[test] failure");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=error\u0000[test] failure");
  });

  it("passes extra arguments through", () => {
    const logger = createLogger("test");
    const err = new Error("boom");
    logger.error("failed:", err);
-    expect(errorSpy).toHaveBeenCalledWith("[test] failed:", err);
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=error\u0000[test] failed:", err);
  });

  it("keeps log output off stdout", () => {
@@ -65,24 +65,24 @@ describe("createLogger", () => {

  it("pre-built instances use correct prefixes", () => {
    schedulerLog.log("tick");
-    expect(errorSpy).toHaveBeenCalledWith("[scheduler] tick");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[scheduler] tick");

    executorLog.log("run");
-    expect(errorSpy).toHaveBeenCalledWith("[executor] run");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[executor] run");

    triageLog.log("spec");
-    expect(errorSpy).toHaveBeenCalledWith("[triage] spec");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[triage] spec");

    mergerLog.log("merge");
-    expect(errorSpy).toHaveBeenCalledWith("[merger] merge");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[merger] merge");

    worktreePoolLog.log("prune");
-    expect(errorSpy).toHaveBeenCalledWith("[worktree-pool] prune");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[worktree-pool] prune");

    reviewerLog.log("review");
-    expect(errorSpy).toHaveBeenCalledWith("[reviewer] review");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[reviewer] review");

    remoteNodeLog.log("stream");
-    expect(errorSpy).toHaveBeenCalledWith("[remote-node] stream");
+    expect(errorSpy).toHaveBeenCalledWith("\u0000fnlvl=info\u0000[remote-node] stream");
  });
 });
--- a/packages/engine/src/logger.ts
+++ b/packages/engine/src/logger.ts
@@ -22,6 +22,13 @@ export interface Logger {
  error(message: string, ...args: unknown[]): void;
 }

+const LOG_LEVEL_MARKER_PREFIX = "\u0000fnlvl=";
+const LOG_LEVEL_MARKER_SUFFIX = "\u0000";
+
+function withSeverityMarker(level: "info" | "warn" | "error", payload: string): string {
+  return `${LOG_LEVEL_MARKER_PREFIX}${level}${LOG_LEVEL_MARKER_SUFFIX}${payload}`;
+}
+
 /**
 * Create a structured logger that prefixes every message with `[prefix]`.
 *
@@ -29,18 +36,22 @@ export interface Logger {
 * @returns A `Logger` whose output is prefixed and sent to stderr. Keeping
 *          engine logs off stdout prevents command/test output consumers from
 *          receiving Fusion execution chatter.
+ *
+ *          The logger prepends an internal control-character severity marker
+ *          so dashboard TUI console-capture can preserve info/warn/error
+ *          semantics even when `log()` is transported via `console.error`.
 */
 export function createLogger(prefix: string): Logger {
  const tag = `[${prefix}]`;
  return {
    log(message: string, ...args: unknown[]) {
-      console.error(`${tag} ${message}`, ...args);
+      console.error(withSeverityMarker("info", `${tag} ${message}`), ...args);
    },
    warn(message: string, ...args: unknown[]) {
-      console.warn(`${tag} ${message}`, ...args);
+      console.warn(withSeverityMarker("warn", `${tag} ${message}`), ...args);
    },
    error(message: string, ...args: unknown[]) {
-      console.error(`${tag} ${message}`, ...args);
+      console.error(withSeverityMarker("error", `${tag} ${message}`), ...args);
    },
  };
 }