Files
fusion/packages/engine/src/logger.ts
gsxdsm 2499803c73 fix: guard CE sessions against concurrent-turn displacement and harden JSON-protocol parsing
Port the planning turn-admission invariant (FNXC:PlanningTurnAdmission,
2026-07-22) into the Compound Engineering orchestrator: at most one turn
(opening/answer/resume-rehydration) is admitted per CE session, reserved
synchronously and held until the turn settles — a re-entered mobile view
re-submitting a turn now gets CeTurnInProgressError (HTTP 409) instead of
displacing the in-flight turn's live agent, which surfaced as "Failed to
parse agent response: AI returned no valid JSON". cancel()/discard()
force-clear the reservation; releases are token-scoped so a stale release
can't drop a newer turn's slot.

In the engine interactive-ai-session seam: bump the reformat retry from
one to two attempts (non-Anthropic default models comply less reliably
with the JSON-only protocol), and log every failed parse with a bounded
raw-response snippet plus resolved provider/model — including a distinct
empty-assistant-message marker — so support can diagnose these reports
without a repro.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
2026-07-23 10:31:22 -07:00

178 lines
6.9 KiB
TypeScript

/**
* Lightweight structured logger for the `@fusion/engine` package.
*
* Usage:
* ```ts
* import { createLogger } from "./logger.js";
* const log = createLogger("my-module");
* log.log("hello"); // → console.error("[my-module] hello")
* log.warn("oops"); // → console.warn("[my-module] oops")
* log.error("fail"); // → console.error("[my-module] fail")
* ```
*
* All engine subsystems should use the pre-built instances exported below
* rather than calling `console.*` directly. This gives us a single point
* of control for filtering, suppressing (e.g. in tests), or redirecting
* engine log output in the future.
*/
export interface Logger {
log(message: string, ...args: unknown[]): void;
/**
* Steady-state per-poll chatter. Suppressed unless the subsystem is opted in
* via `FUSION_DEBUG` (see `isDebugEnabled`).
*/
debug(message: string, ...args: unknown[]): void;
warn(message: string, ...args: unknown[]): void;
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}`;
}
/*
FNXC:EngineDiagnostics 2026-07-15-12:55:
Operators read the TUI log pane to see what the engine is *doing*; per-poll steady-state chatter (routine node routing, capacity-deferred hold releases) drowned real events out — a 1000-line buffer held only a few seconds of scheduler polls.
Such lines move to `debug()`, off by default and opted in per subsystem via `FUSION_DEBUG` (`FUSION_DEBUG=1`/`all` for everything, or a comma-separated prefix list like `FUSION_DEBUG=scheduler,merger`).
Anything that reports a state *change* or needs operator action stays on `log()`/`warn()`/`error()`.
*/
function isDebugEnabled(prefix: string): boolean {
const raw = process.env.FUSION_DEBUG?.trim();
if (!raw) return false;
if (raw === "1" || raw === "true" || raw === "all" || raw === "*") return true;
return raw
.split(",")
.map((entry) => entry.trim())
.includes(prefix);
}
/**
* Create a structured logger that prefixes every message with `[prefix]`.
*
* @param prefix - Short subsystem name, e.g. `"scheduler"` or `"executor"`.
* @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`.
*
* `debug()` is gated on `FUSION_DEBUG` and re-reads the env var per
* call so tests and long-lived processes can toggle it without
* re-creating loggers. When enabled it emits under the `info` marker,
* so TUI console-capture needs no new severity to render it.
*/
export function createLogger(prefix: string): Logger {
const tag = `[${prefix}]`;
return {
log(message: string, ...args: unknown[]) {
console.error(withSeverityMarker("info", `${tag} ${message}`), ...args);
},
debug(message: string, ...args: unknown[]) {
if (!isDebugEnabled(prefix)) return;
console.error(withSeverityMarker("info", `${tag} ${message}`), ...args);
},
warn(message: string, ...args: unknown[]) {
console.warn(withSeverityMarker("warn", `${tag} ${message}`), ...args);
},
error(message: string, ...args: unknown[]) {
console.error(withSeverityMarker("error", `${tag} ${message}`), ...args);
},
};
}
/** Logger for the scheduler subsystem. */
export const schedulerLog = createLogger("scheduler");
/** Logger for the task executor subsystem. */
export const executorLog = createLogger("executor");
/** Logger for the plan processor subsystem. */
export const planLog = createLogger("plan");
/** Logger for the pi agent session subsystem. */
export const piLog = createLogger("pi");
/** Logger for extension discovery/provider registration. */
export const extensionsLog = createLogger("extensions");
/** Logger for the merge/auto-merge subsystem. */
export const mergerLog = createLogger("merger");
/** Logger for the worktree pool subsystem. */
export const worktreePoolLog = createLogger("worktree-pool");
/** Logger for the review subsystem. */
export const reviewerLog = createLogger("reviewer");
/** Logger for the PR monitor subsystem. */
export const prMonitorLog = createLogger("pr-monitor");
export const prReconcileLog = createLogger("pr-reconcile");
/** Logger for the project runtime subsystem. */
export const runtimeLog = createLogger("runtime");
/** Logger for the IPC subsystem. */
export const ipcLog = createLogger("ipc");
/** Logger for the project manager subsystem. */
export const projectManagerLog = createLogger("project-manager");
/** Logger for the hybrid executor subsystem. */
export const hybridExecutorLog = createLogger("hybrid-executor");
/** Logger for the mission autopilot subsystem. */
export const autopilotLog = createLogger("autopilot");
/** Logger for the heartbeat execution subsystem. */
export const heartbeatLog = createLogger("heartbeat");
/** Logger for the interactive AI session seam (planning / CE stage sessions). */
export const interactiveSessionLog = createLogger("interactive-session");
/** Logger for remote node runtime/client subsystems. */
export const remoteNodeLog = createLogger("remote-node");
/** Logger for remote tunnel process orchestration subsystem. */
export const remoteTunnelLog = createLogger("remote-tunnel");
/** Logger for periodic node health monitor subsystem. */
export const nodeHealthMonitorLog = createLogger("node-health-monitor");
/** Logger for the peer exchange (gossip) subsystem. */
export const peerExchangeLog = createLogger("peer-exchange");
/**
* Extract both a short message and a full stack trace from an unknown caught
* value. Use this at catch sites instead of the
* `err instanceof Error ? err.message : String(err)` idiom so that the stack
* is preserved for logs, task `activityLog` entries, and surfaced diagnostics.
*
* `detail` is `message` when no stack is available and `message + "\n" + stack`
* otherwise — suitable for `store.logEntry(taskId, action, detail)`.
*/
export function formatError(err: unknown): { message: string; stack?: string; detail: string } {
if (err instanceof Error) {
const message = err.message || err.name || "Error";
const stack = err.stack;
const detail = stack && stack.includes(message) ? stack : stack ? `${message}\n${stack}` : message;
return { message, stack, detail };
}
let message: string;
if (typeof err === "string") {
message = err;
} else {
try {
message = JSON.stringify(err);
} catch {
message = String(err);
}
}
return { message, detail: message };
}