fix: quiet per-poll scheduler hold-release and routing log spam

Both lines fired on every scheduler poll while nothing changed: a held
card re-attempts release each sweep, and every dispatch candidate logged
its resolved node. On a busy board that filled the operator log pane with
"Hold release for FN-XXXX deferred" and "routed to node=local" within
seconds, burying real scheduler events.

Add a Logger.debug() level, off by default and opted into per subsystem
via FUSION_DEBUG, and demote both lines to it. Routing to a remote node
stays at info since it explains where work actually went; only the local
default is demoted. Lines reporting a real transition (capacity
rejection, racing sweep, release failure) are untouched.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

.changeset/quiet-scheduler-steady-state-logs.md

@@ -0,0 +1,7 @@
+---
+"@runfusion/fusion": patch
+---
+
+summary: Quiet repetitive scheduler hold-release and task-routing lines that flooded the engine log pane.
+category: fix
+dev: Adds `Logger.debug()` in `packages/engine/src/logger.ts`, gated per subsystem by `FUSION_DEBUG` (`1`/`true`/`all`/`*`, or a comma-separated prefix list). Demotes `Hold release for <id> deferred — no reservable slot` and local-only `Task <id> routed to node=local` to debug; remote routing stays at info. See `docs/diagnostics.md`.

docs/diagnostics.md

@@ -1,5 +1,26 @@
 # Diagnostics
 
+## Debug-level engine logs (`FUSION_DEBUG`)
+
+Engine subsystem loggers (`createLogger` in `packages/engine/src/logger.ts`) expose a `debug()` level for steady-state per-poll chatter. It is **off by default** so the TUI log pane and engine stderr show state *changes* rather than the scheduler reprinting its resting state every poll.
+
+Opt in per subsystem with the logger prefix:
+
+```bash
+FUSION_DEBUG=scheduler        # one subsystem
+FUSION_DEBUG=scheduler,merger # several
+FUSION_DEBUG=1                # everything (also: true, all, *)
+```
+
+The variable is re-read per call, so it can be toggled on a long-lived process without recreating loggers. Debug lines emit under the `info` severity marker and render like any other info line.
+
+Currently debug-gated:
+
+- `Task <id> routed to node=local (source=local)` — routing to a **remote** node stays at info; only the local default is demoted.
+- `Hold release for <id> deferred — no reservable slot for <column>` — being at capacity is the expected steady state, not an event.
+
+Guidance for new log sites: if a line repeats on every scheduler poll while nothing changed, it belongs at `debug()`. Anything reporting a transition, a rejection, or something needing operator action stays at `log()`/`warn()`/`error()`.
+
 ## Goal injection diagnostics (`[goal-injection]`)
 
 Executor, heartbeat, and planning runs emit one goal-injection diagnostic with outcome `applied`, `no-goals`, or `disabled-or-failed`.

packages/engine/src/__tests__/logger-debug-gating.test.ts

@@ -0,0 +1,63 @@
+import { describe, it, expect, vi, afterEach } from "vitest";
+import { createLogger } from "../logger.js";
+
+/*
+FNXC:EngineDiagnostics 2026-07-15-12:55:
+Guards the contract that keeps steady-state scheduler chatter out of the operator log pane: `debug()` is silent unless the subsystem opted in via `FUSION_DEBUG`, and `log()` is never gated.
+A regression either way is invisible in normal use — it either re-floods the TUI or silently swallows real events — so it is asserted rather than eyeballed.
+*/
+describe("createLogger debug gating", () => {
+  afterEach(() => {
+    delete process.env.FUSION_DEBUG;
+    vi.restoreAllMocks();
+  });
+
+  it("suppresses debug output when FUSION_DEBUG is unset", () => {
+    const spy = vi.spyOn(console, "error").mockImplementation(() => {});
+    createLogger("scheduler").debug("steady-state chatter");
+    expect(spy).not.toHaveBeenCalled();
+  });
+
+  it("emits debug output for a subsystem named in the FUSION_DEBUG list", () => {
+    process.env.FUSION_DEBUG = "scheduler,merger";
+    const spy = vi.spyOn(console, "error").mockImplementation(() => {});
+    createLogger("scheduler").debug("steady-state chatter");
+    expect(spy).toHaveBeenCalledOnce();
+    expect(spy.mock.calls[0]?.[0]).toContain("[scheduler] steady-state chatter");
+  });
+
+  it("suppresses debug output for a subsystem absent from the FUSION_DEBUG list", () => {
+    process.env.FUSION_DEBUG = "merger";
+    const spy = vi.spyOn(console, "error").mockImplementation(() => {});
+    createLogger("scheduler").debug("steady-state chatter");
+    expect(spy).not.toHaveBeenCalled();
+  });
+
+  it.each(["1", "true", "all", "*"])("emits debug output for every subsystem when FUSION_DEBUG=%s", (value) => {
+    process.env.FUSION_DEBUG = value;
+    const spy = vi.spyOn(console, "error").mockImplementation(() => {});
+    createLogger("scheduler").debug("steady-state chatter");
+    expect(spy).toHaveBeenCalledOnce();
+  });
+
+  it("re-reads FUSION_DEBUG per call so toggling does not require a new logger", () => {
+    const log = createLogger("scheduler");
+    const spy = vi.spyOn(console, "error").mockImplementation(() => {});
+    log.debug("first");
+    expect(spy).not.toHaveBeenCalled();
+    process.env.FUSION_DEBUG = "scheduler";
+    log.debug("second");
+    expect(spy).toHaveBeenCalledOnce();
+  });
+
+  it("never gates log/warn/error on FUSION_DEBUG", () => {
+    const errorSpy = vi.spyOn(console, "error").mockImplementation(() => {});
+    const warnSpy = vi.spyOn(console, "warn").mockImplementation(() => {});
+    const log = createLogger("scheduler");
+    log.log("real event");
+    log.warn("real warning");
+    log.error("real failure");
+    expect(errorSpy).toHaveBeenCalledTimes(2);
+    expect(warnSpy).toHaveBeenCalledOnce();
+  });
+});

packages/engine/src/hold-release.ts

@@ -486,8 +486,13 @@ async function issueRelease(
   if (targetIsProcessing && deps.reserveSlot) {
     reservation = await deps.reserveSlot(task, target);
     if (!reservation) {
-      // Semaphore/worktree exhausted — reservation-first means no move at all.
-      schedulerLog.log(`Hold release for ${task.id} deferred — no reservable slot for ${target}`);
+      /*
+      Semaphore/worktree exhausted — reservation-first means no move at all.
+
+      FNXC:WorkflowScheduling 2026-07-15-12:55:
+      A held card re-attempts release on every sweep, so a full board reprinted this line per task per poll and buried real scheduler events. Being at capacity is the expected steady state, not an event: debug-only (`FUSION_DEBUG=scheduler`).
+      */
+      schedulerLog.debug(`Hold release for ${task.id} deferred — no reservable slot for ${target}`);
       return false;
     }
   }

packages/engine/src/logger.ts

@@ -18,6 +18,11 @@
 
 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;
 }
@@ -29,6 +34,22 @@ function withSeverityMarker(level: "info" | "warn" | "error", payload: 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]`.
  *
@@ -40,6 +61,11 @@ function withSeverityMarker(level: "info" | "warn" | "error", payload: string):
  *          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}]`;
@@ -47,6 +73,10 @@ export function createLogger(prefix: string): Logger {
     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);
     },

packages/engine/src/scheduler.ts

@@ -32,7 +32,7 @@ import { schedulerLog } from "./logger.js";
 import { type PrMonitor, type PrComment } from "./pr-monitor.js";
 import { reconcileMissionFeatureState } from "./mission-feature-sync.js";
 import { evaluateSpecStaleness, getPromptPath } from "./spec-staleness.js";
-import { resolveEffectiveNode } from "./effective-node.js";
+import { resolveEffectiveNode, type EffectiveNode } from "./effective-node.js";
 import { applyUnavailableNodePolicy, decideOwningNodeHandoff } from "./node-routing-policy.js";
 import type { NodeDispatchValidationResult } from "./node-dispatch-validation.js";
 import type { MeshLeaseManager } from "./mesh-lease-manager.js";
@@ -47,6 +47,20 @@ import { runHoldReleaseSweep, isUnplannedForExecution, type SlotReservation } fr
 import { moveTaskToReplanColumn } from "./replan-target.js";
 import { evaluateParkedAgentTaskLink } from "./task-agent-sync.js";
 
+/*
+FNXC:WorkflowScheduling 2026-07-15-12:55:
+Every dispatch pass resolves a routing node, so logging each resolution at info level reprinted `routed to node=local (source=local)` for every task on every poll and buried real scheduler events in the TUI log pane.
+Local routing is the default nobody needs told about: it is debug-only (`FUSION_DEBUG=scheduler`). Remote routing stays at info because it explains where work actually went and is what an operator reaches for when a task runs on the wrong host.
+*/
+function logTaskRouting(taskId: string, node: EffectiveNode): void {
+  const message = `Task ${taskId} routed to node=${node.nodeId ?? "local"} (source=${node.source})`;
+  if (node.nodeId === undefined) {
+    schedulerLog.debug(message);
+    return;
+  }
+  schedulerLog.log(message);
+}
+
 function shouldRunWorkflowColumnScheduler(_settings: Settings): boolean {
   /*
   FNXC:WorkflowScheduling 2026-06-22-00:00:
@@ -1902,7 +1916,7 @@ export class Scheduler {
 
         // Resolve effective node for routing
         let effectiveNode = resolveEffectiveNode(freshTask, settings);
-        schedulerLog.log(`Task ${task.id} routed to node=${effectiveNode.nodeId ?? "local"} (source=${effectiveNode.source})`);
+        logTaskRouting(task.id, effectiveNode);
 
         // Enforce dispatch configuration validation before node-health fallback logic.
         if (effectiveNode.nodeId !== undefined && this.options.validateNodeDispatch) {
@@ -2426,7 +2440,7 @@ export class Scheduler {
           }
 
           let effectiveNode = resolveEffectiveNode(freshTask, settings);
-          schedulerLog.log(`Task ${task.id} routed to node=${effectiveNode.nodeId ?? "local"} (source=${effectiveNode.source})`);
+          logTaskRouting(task.id, effectiveNode);
 
           if (effectiveNode.nodeId !== undefined && this.options.validateNodeDispatch) {
             const nodeValidation = await this.options.validateNodeDispatch(effectiveNode.nodeId);