From 73fe461db5c2e0dc41f85cfe015ed260655430ca Mon Sep 17 00:00:00 2001 From: gsxdsm Date: Sun, 2 Aug 2026 23:18:07 -0700 Subject: [PATCH] fix: demote routine engine log noise to debug Keep the default TUI for lifecycle transitions (Starting/Specifying/Worktree created/merge/move). Demote expected skips, schedule-trigger echoes, session setup bookkeeping, warm worktree reuse, and fn_run_verification command-fail detail. Pin via severity manifest and contract tests. --- docs/diagnostics.md | 2 +- .../core/src/postgres/embedded-lifecycle.ts | 5 +- .../src/__tests__/log-severity-manifest.ts | 25 ++++++++++ .../log-severity-spam-contract.test.ts | 48 +++++++++++++++++++ packages/engine/src/agent-heartbeat.ts | 11 +++-- packages/engine/src/auto-claim-snapshot.ts | 7 ++- .../engine/src/ephemeral-worker-manager.ts | 11 ++++- packages/engine/src/executor.ts | 28 ++++++----- packages/engine/src/run-verification-tool.ts | 11 +++-- .../engine/src/runtimes/in-process-runtime.ts | 13 ++++- packages/engine/src/scheduler.ts | 20 ++++++-- packages/engine/src/worktree-acquisition.ts | 8 ++-- 12 files changed, 158 insertions(+), 31 deletions(-) diff --git a/docs/diagnostics.md b/docs/diagnostics.md index 1a0601ba6f..207cf3d1cd 100644 --- a/docs/diagnostics.md +++ b/docs/diagnostics.md @@ -21,7 +21,7 @@ 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 classes include local/default routing, capacity and re-entrancy skips, poll/sweep no-actions, per-step success/progress, optional integration probes, successful verification bookkeeping, per-session agent setup (`agent-session` runtime/fallback resolution, planning mode, stuck-detector track bookkeeping), intentional skill-exclusion notices (`[skills] info: … disabled by project execution settings`), expected-missing PROMPT.md seed reads (ENOENT), token-cache metrics JSON, duplicate runtime `Specifying …` echoes, and zero-count recovery summaries. State-changing recovery and dispatch outcomes remain visible. +Currently debug-gated classes include local/default routing, capacity and re-entrancy skips, poll/sweep no-actions, per-step success/progress, optional integration probes, successful verification bookkeeping, per-session agent setup (`agent-session` runtime/fallback resolution, planning mode, stuck-detector track bookkeeping), intentional skill-exclusion notices (`[skills] info: … disabled by project execution settings`), expected-missing PROMPT.md seed reads (ENOENT), token-cache metrics JSON, duplicate runtime `Specifying …` echoes, zero-count recovery summaries, mission "no linked feature" skips, event-driven "triggering scheduling" echoes, auto-claim snapshot invalidation, assignment-trigger skip guards (ephemeral/disabled/active-run), runtime `Scheduled`/`Started executing` echoes of executor `Starting`, worktree warm-reuse, runtime-env injection counts, baseCommitSha capture, parse-steps reconcile diagnostics, graph node worktree re-acquire, ephemeral already-owned worker skip, embedded-postgres rejoin "already running", and `fn_run_verification` non-timeout command-fail detail (failed `done` lines stay at info). State-changing recovery and dispatch outcomes remain visible (`Starting`/`Specifying`/`Worktree created`/`Auto-merge merged`/column moves/slow hold-release). Dashboard server code uses the core logger only: `import { createLogger } from "@fusion/core";`. Do not import an engine logger, use a relative cross-package logger path, or add a dashboard-local logger implementation. diff --git a/packages/core/src/postgres/embedded-lifecycle.ts b/packages/core/src/postgres/embedded-lifecycle.ts index 68ec53a6dc..06bdf12633 100644 --- a/packages/core/src/postgres/embedded-lifecycle.ts +++ b/packages/core/src/postgres/embedded-lifecycle.ts @@ -1421,9 +1421,8 @@ export class EmbeddedPostgresLifecycle { // Check if PG is already running for this data dir. If so, reuse it. const existing = await isAlreadyRunning(this.options.dataDir, this.options.onLog); if (existing) { - this.options.onLog( - `embedded postgres: already running on port ${existing.port} (data dir ${this.options.dataDir}), connecting without starting a new instance`, - ); + // FNXC:EngineDiagnostics 2026-08-03-05:54: multi-process rejoin is expected; keep "starting embedded PostgreSQL" as the boot-visible line. + log.debug(`embedded postgres: already running on port ${existing.port} (data dir ${this.options.dataDir}), connecting without starting a new instance`); this.resolvedPort = existing.port; this.running = false; // We didn't start it, so we won't stop it this.ownsProcess = false; diff --git a/packages/engine/src/__tests__/log-severity-manifest.ts b/packages/engine/src/__tests__/log-severity-manifest.ts index 8422da0418..472ac50289 100644 --- a/packages/engine/src/__tests__/log-severity-manifest.ts +++ b/packages/engine/src/__tests__/log-severity-manifest.ts @@ -97,4 +97,29 @@ export const logSeverityManifest: SeverityManifestEntry[] = [ { pkg: "engine", file: "executor.ts", anchor: "tokenCacheMetricsLog.debug(JSON.stringify({", priorSeverity: "log", severity: "debug" }, { pkg: "engine", file: "runtimes/in-process-runtime.ts", anchor: "runtimeLog.debug(`Specifying ${t.id}...`)", priorSeverity: "log", severity: "debug" }, { pkg: "engine", file: "triage.ts", anchor: "planLog.debug(`${taskId}: failed to read PROMPT.md during ${context} (${promptPath}): ${msg}`)", priorSeverity: "warn", severity: "debug" }, + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Operator TUI audit of a busy board: demote expected skips, schedule-trigger echoes, + session/setup bookkeeping, and routine verification command-fail detail so default + severity stays lifecycle transitions (Starting/Specifying/Worktree created/merge/move). + */ + { pkg: "engine", file: "scheduler.ts", anchor: "No linked feature found for task ${taskId}", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "scheduler.ts", anchor: "Task created — triggering scheduling", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "scheduler.ts", anchor: "Task moved to ${to} — triggering scheduling", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "auto-claim-snapshot.ts", anchor: "invalidate reason=${reason}", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "agent-heartbeat.ts", anchor: "Assignment trigger skipped for ${agent.id} (ephemeral/internal)", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "agent-heartbeat.ts", anchor: "Assignment trigger skipped for ${agent.id} (disabled)", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "agent-heartbeat.ts", anchor: "Assignment trigger skipped for ${agent.id} (active run)", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "runtimes/in-process-runtime.ts", anchor: "Scheduled task ${task.id}", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "runtimes/in-process-runtime.ts", anchor: "Started executing task ${task.id} in ${worktreePath}", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "executor.ts", anchor: "executorLog.debug(`${task.id}: executor runtime env injected", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "executor.ts", anchor: "executorLog.debug(`${live.id}: graph node '${node.id}' runtime env injected", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "executor.ts", anchor: "executorLog.debug(`${task.id}: workflow node '${nodeId}' acquired worktree", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "executor.ts", anchor: "executorLog.debug(`${task.id}: captured baseCommitSha ${baseCommitSha.slice(0, 7)}`)", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "executor.ts", anchor: "executorLog.debug(`${taskId}: reconcile step source governed by parse-steps", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "run-verification-tool.ts", anchor: "executorLog.debug(`[fn_run_verification] command failed (exit=", priorSeverity: "warn", severity: "debug" }, + { pkg: "engine", file: "worktree-acquisition.ts", anchor: "logger.debug(`Reusing existing worktree: ${path}`)", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "worktree-acquisition.ts", anchor: "logger.debug(`Reusing existing worktree: ${worktreePath}`)", priorSeverity: "log", severity: "debug" }, + { pkg: "engine", file: "ephemeral-worker-manager.ts", anchor: "this.log.debug(`Skipping task-worker creation for ${task.id}: task already has execution owner`)", priorSeverity: "warn", severity: "debug" }, + { pkg: "core", file: "postgres/embedded-lifecycle.ts", anchor: "log.debug(`embedded postgres: already running on port", priorSeverity: "log", severity: "debug" }, ]; diff --git a/packages/engine/src/__tests__/log-severity-spam-contract.test.ts b/packages/engine/src/__tests__/log-severity-spam-contract.test.ts index ef22b6eadb..0ccdf32448 100644 --- a/packages/engine/src/__tests__/log-severity-spam-contract.test.ts +++ b/packages/engine/src/__tests__/log-severity-spam-contract.test.ts @@ -264,6 +264,9 @@ describe("log severity spam contract (source)", () => { expect(tool).toMatch(/executorLog\.debug\(\s*`\[fn_run_verification\] command quiet for/); expect(tool).toMatch(/\(log\.debug \?\? log\.info\)\(/); expect(tool).toMatch(/if \(result\.success\) \{\s*\(log\.debug \?\? log\.info\)\(/); + // Non-timeout command failures are routine agent loops; keep one done-line at info, detail at debug. + expect(tool).toMatch(/executorLog\.debug\(`\[fn_run_verification\] command failed \(exit=/); + expect(tool).not.toMatch(/executorLog\.warn\(`\[fn_run_verification\] command failed \(exit=/); expect(utils).toMatch(/debugLog\(`\$\{taskId\}: running \$\{type\} command:/); expect(utils).toMatch(/debugLog\(`\$\{taskId\}: \$\{type\} command succeeded in/); expect(utils).toMatch(/logger\.error\(`\$\{taskId\}: \$\{type\} command failed/); @@ -273,6 +276,51 @@ describe("log severity spam contract (source)", () => { expect(exec).toMatch(/executorLog\.debug\(`\$\{task\.id\}: \[verification\] passed`\)/); expect(exec).toMatch(/executorLog\.log\(`\$\{task\.id\}: \[verification\] test failed/); }); + + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Screenshot audit: keep default TUI for lifecycle transitions; demote expected skips, + schedule-trigger echoes, and session/setup bookkeeping. + */ + it("busy-board lifecycle noise stays debug-gated; starts and creates stay log", () => { + const scheduler = readSrc("scheduler.ts"); + const runtime = readSrc("runtimes/in-process-runtime.ts"); + const exec = readSrc("executor.ts"); + const heartbeat = readSrc("agent-heartbeat.ts"); + const autoClaim = readSrc("auto-claim-snapshot.ts"); + const ephemeral = readSrc("ephemeral-worker-manager.ts"); + const worktree = readSrc("worktree-acquisition.ts"); + + expect(scheduler).toMatch(/schedulerLog\.debug\(`No linked feature found for task/); + expect(scheduler).toMatch(/schedulerLog\.debug\("Task created — triggering scheduling"\)/); + expect(scheduler).toMatch(/schedulerLog\.debug\(`Task moved to \$\{to\} — triggering scheduling`\)/); + expect(scheduler).toMatch(/schedulerLog\.log\(`Starting \$\{taskId\}:/); + expect(scheduler).not.toMatch(/schedulerLog\.log\(`No linked feature found for task/); + + expect(runtime).toMatch(/runtimeLog\.debug\(`Scheduled task \$\{task\.id\}`\)/); + expect(runtime).toMatch(/runtimeLog\.debug\(`Started executing task \$\{task\.id\} in \$\{worktreePath\}`\)/); + expect(runtime).not.toMatch(/runtimeLog\.log\(`Scheduled task \$\{task\.id\}`\)/); + + expect(exec).toMatch(/executorLog\.log\(`Starting \$\{task\.id\}:/); + expect(exec).toMatch(/executorLog\.log\(`Worktree created:/); + expect(exec).toMatch(/executorLog\.debug\(`\$\{task\.id\}: executor runtime env injected/); + expect(exec).toMatch(/executorLog\.debug\(`\$\{task\.id\}: captured baseCommitSha/); + expect(exec).toMatch(/executorLog\.debug\(`\$\{task\.id\}: workflow node '\$\{nodeId\}' acquired worktree/); + expect(exec).not.toMatch(/executorLog\.log\(`\$\{task\.id\}: executor runtime env injected/); + + expect(heartbeat).toMatch(/heartbeatLog\.debug\(`Assignment trigger skipped for \$\{agent\.id\} \(ephemeral\/internal\)`\)/); + expect(heartbeat).not.toMatch(/heartbeatLog\.log\(`Assignment trigger skipped for \$\{agent\.id\} \(ephemeral\/internal\)`\)/); + + expect(autoClaim).toMatch(/this\.logger\.debug\(`invalidate reason=\$\{reason\}`\)/); + expect(autoClaim).not.toMatch(/this\.logger\.log\(`invalidate reason=\$\{reason\}`\)/); + + expect(ephemeral).toMatch(/this\.log\.debug\(`Skipping task-worker creation for \$\{task\.id\}: task already has execution owner`\)/); + expect(ephemeral).not.toMatch(/this\.log\.warn\(`Skipping task-worker creation for \$\{task\.id\}: task already has execution owner`\)/); + + expect(worktree).toMatch(/logger\.debug\(`Reusing existing worktree: \$\{path\}`\)/); + expect(worktree).toMatch(/logger\.debug\(`Reusing existing worktree: \$\{worktreePath\}`\)/); + expect(worktree).not.toMatch(/logger\?\.log\(`Reusing existing worktree:/); + }); }); describe("log severity spam contract (runtime gating)", () => { diff --git a/packages/engine/src/agent-heartbeat.ts b/packages/engine/src/agent-heartbeat.ts index 9d31a8ea52..d08808e9ee 100644 --- a/packages/engine/src/agent-heartbeat.ts +++ b/packages/engine/src/agent-heartbeat.ts @@ -4964,13 +4964,18 @@ export class HeartbeatTriggerScheduler { try { if (!isHeartbeatManaged(agent)) { - heartbeatLog.log(`Assignment trigger skipped for ${agent.id} (ephemeral/internal)`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Ephemeral/internal, disabled, and active-run skips are expected guard outcomes on + assignment events — not operator-actionable. Mirror timer-tick skip gates (debug). + */ + heartbeatLog.debug(`Assignment trigger skipped for ${agent.id} (ephemeral/internal)`); return; } const runtimeConfig = (agent.runtimeConfig ?? {}) as { enabled?: boolean; allowParallelExecution?: boolean }; if (runtimeConfig.enabled === false) { - heartbeatLog.log(`Assignment trigger skipped for ${agent.id} (disabled)`); + heartbeatLog.debug(`Assignment trigger skipped for ${agent.id} (disabled)`); return; } @@ -4980,7 +4985,7 @@ export class HeartbeatTriggerScheduler { const activeRun = await this.store.getActiveHeartbeatRun(agent.id); if (activeRun) { this.pendingAssignments.set(agent.id, { taskId }); - heartbeatLog.log(`Assignment trigger skipped for ${agent.id} (active run)`); + heartbeatLog.debug(`Assignment trigger skipped for ${agent.id} (active run)`); return; } diff --git a/packages/engine/src/auto-claim-snapshot.ts b/packages/engine/src/auto-claim-snapshot.ts index 6f50857142..cbf8b4f9cc 100644 --- a/packages/engine/src/auto-claim-snapshot.ts +++ b/packages/engine/src/auto-claim-snapshot.ts @@ -189,7 +189,12 @@ export class AutoClaimSnapshotManager { this.cache = null; this.staleReason = "invalidate"; this.invalidatedAt = this.now(); - this.logger.log(`invalidate reason=${reason}`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Snapshot invalidation runs on every task create/update that changes the auto-claim + fingerprint. Cache bookkeeping only — default TUI should not reprint it. + */ + this.logger.debug(`invalidate reason=${reason}`); } async getSnapshot(): Promise { diff --git a/packages/engine/src/ephemeral-worker-manager.ts b/packages/engine/src/ephemeral-worker-manager.ts index 1e83d6a322..73597289ee 100644 --- a/packages/engine/src/ephemeral-worker-manager.ts +++ b/packages/engine/src/ephemeral-worker-manager.ts @@ -42,6 +42,8 @@ export interface TaskOwner { export interface EphemeralWorkerLogger { log: (msg: string, ...rest: unknown[]) => void; warn: (msg: string, ...rest: unknown[]) => void; + /** Optional; demoted steady-state skips use debug when present (FUSION_DEBUG). */ + debug?: (msg: string, ...rest: unknown[]) => void; } export interface EphemeralWorkerManagerOptions { @@ -114,7 +116,14 @@ export class EphemeralWorkerManager { // Already-tracked in this session: leave alone. const cached = this.taskAgentMap.get(task.id); if (cached) { - this.log.warn(`Skipping task-worker creation for ${task.id}: task already has execution owner`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Already-owned tasks (assigned permanent agent or prior onTaskStart) hit this on every + start — expected re-entrance, not degradation. Was warn and yellow-flagged the TUI. + */ + if (this.log.debug) { + this.log.debug(`Skipping task-worker creation for ${task.id}: task already has execution owner`); + } return cached; } diff --git a/packages/engine/src/executor.ts b/packages/engine/src/executor.ts index 4f31ee972a..b4adfe5134 100644 --- a/packages/engine/src/executor.ts +++ b/packages/engine/src/executor.ts @@ -9292,7 +9292,12 @@ export class TaskExecutor { await this.captureBaseCommitSha(task, acquisition.worktreePath, audit, { isResume: false }); } this.options.onStart?.(task, acquisition.worktreePath); - executorLog.log(`${task.id}: workflow node '${nodeId}' acquired worktree at ${acquisition.worktreePath}`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Per-node worktree acquisition is expected graph plumbing once the task has a worktree; + Worktree created / Starting lines remain the operator-visible lifecycle events. + */ + executorLog.debug(`${task.id}: workflow node '${nodeId}' acquired worktree at ${acquisition.worktreePath}`); return await this.store.getTask(task.id); } catch (error) { const message = error instanceof Error ? error.message : String(error); @@ -9871,9 +9876,8 @@ export class TaskExecutor { } else if (mode === "prompt") { const injected = await this.buildInjectedRuntimeEnv(live.id, worktreePath, executionTarget.branch ?? undefined); nodeEnv = injected.env; - executorLog.log( - `${live.id}: graph node '${node.id}' runtime env injected (${injected.pathEntryCount} PATH entries, ${injected.injectedKeyCount} env keys)`, - ); + // FNXC:EngineDiagnostics 2026-08-03-05:54: per-node PATH/key injection is plumbing, not a lifecycle event. + executorLog.debug(`${live.id}: graph node '${node.id}' runtime env injected (${injected.pathEntryCount} PATH entries, ${injected.injectedKeyCount} env keys)`); } // (U3) Genuinely-unattended signal. `unattended` is an explicit opt-in @@ -13367,9 +13371,8 @@ export class TaskExecutor { const injected = await this.buildInjectedRuntimeEnv(task.id, worktreePath, acquisition.branch ?? undefined); taskEnv = injected.env; - executorLog.log( - `${task.id}: executor runtime env injected (${injected.pathEntryCount} PATH entries, ${injected.injectedKeyCount} env keys)`, - ); + // FNXC:EngineDiagnostics 2026-08-03-05:54: env injection counts are session setup, not operator state changes. + executorLog.debug(`${task.id}: executor runtime env injected (${injected.pathEntryCount} PATH entries, ${injected.injectedKeyCount} env keys)`); this.options.onStart?.(task, worktreePath); @@ -18383,7 +18386,11 @@ ${scopeGuard} } await this.store.updateTask(task.id, { baseCommitSha }); - executorLog.log(`${task.id}: captured baseCommitSha ${baseCommitSha.slice(0, 7)}`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Base-SHA capture is per-task setup bookkeeping (also in run-audit). Worktree created stays info. + */ + executorLog.debug(`${task.id}: captured baseCommitSha ${baseCommitSha.slice(0, 7)}`); await audit.git({ type: "commit:create", target: baseCommitSha, metadata: { purpose: "base", preserved: false } }); } catch (err: unknown) { const errorMessage = err instanceof Error ? err.message : String(err); @@ -21608,9 +21615,8 @@ You have access to the file system to review changes.${inlineFixBlock}${verdictB const ir = await resolveWorkflowIrForTask(this.store, taskId); const stepSource = this.resolveTaskStepSource(ir); if (stepSource) { - executorLog.log( - `${taskId}: reconcile step source governed by parse-steps(artifact=${stepSource.artifact}, parser=${stepSource.parser})`, - ); + // FNXC:EngineDiagnostics 2026-08-03-05:54: parse-steps source read-through is diagnostic only. + executorLog.debug(`${taskId}: reconcile step source governed by parse-steps(artifact=${stepSource.artifact}, parser=${stepSource.parser})`); } } catch { // Read-through is diagnostic only; never block reconcile on it. diff --git a/packages/engine/src/run-verification-tool.ts b/packages/engine/src/run-verification-tool.ts index 8cdc183817..f321625973 100644 --- a/packages/engine/src/run-verification-tool.ts +++ b/packages/engine/src/run-verification-tool.ts @@ -769,9 +769,14 @@ async function runVerificationCommandUnlocked( const success = expectFailure ? true : zeroExit; if (!success && !timedOut) { - executorLog.warn( - `[fn_run_verification] command failed (exit=${exitCode}, signal=${signal ?? "none"}): ${command}`, - ); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Agent verification fails routinely during implement/fix loops; the tool result already + returns exit code + summarized output to the agent. A warn here doubled every red run + (command failed + done success=false) and yellow-flagged normal work. Keep one failure + line at info on the done path; demote this detail to debug. + */ + executorLog.debug(`[fn_run_verification] command failed (exit=${exitCode}, signal=${signal ?? "none"}): ${command}`); } if (!timedOut) { reapVerificationProcessGroup(supervised); diff --git a/packages/engine/src/runtimes/in-process-runtime.ts b/packages/engine/src/runtimes/in-process-runtime.ts index 1215ef8f50..64764bddac 100644 --- a/packages/engine/src/runtimes/in-process-runtime.ts +++ b/packages/engine/src/runtimes/in-process-runtime.ts @@ -1165,7 +1165,11 @@ export class InProcessRuntime }, onSchedule: (task) => { this.recordActivity(); - runtimeLog.log(`Scheduled task ${task.id}`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Redundant with scheduler `Starting ${id}` — keep the dispatch side-effect silent by default. + */ + runtimeLog.debug(`Scheduled task ${task.id}`); }, onBlocked: () => {}, validateNodeDispatch: async (nodeId) => { @@ -1306,7 +1310,12 @@ export class InProcessRuntime }, onStart: (task, worktreePath) => { this.recordActivity(); - runtimeLog.log(`Started executing task ${task.id} in ${worktreePath}`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Executor already emits `Starting ${id}` at dispatch; worktree path is also on + worktree-created / node-acquired lines. Demote this echo to debug. + */ + runtimeLog.debug(`Started executing task ${task.id} in ${worktreePath}`); // Legacy invariant (implemented in EphemeralWorkerManager): // if (this.taskAgentMap.has(task.id)) { ... "Skipping task-worker creation for" ... } void this.workerManager?.onTaskStart(task); diff --git a/packages/engine/src/scheduler.ts b/packages/engine/src/scheduler.ts index bdf1c21ea4..52e812f36d 100644 --- a/packages/engine/src/scheduler.ts +++ b/packages/engine/src/scheduler.ts @@ -1000,7 +1000,12 @@ export class Scheduler { this.store.on("task:created", (task) => { this.lastAutoClaimFingerprint.set(task.id, computeAutoClaimFingerprint(task)); this.options.snapshotManager?.invalidate("task:created"); - schedulerLog.log("Task created — triggering scheduling"); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Event-driven schedule triggers fire on every create/done; the card transition is already + visible on the board and via task:moved logs. Keep the trigger line debug-only. + */ + schedulerLog.debug("Task created — triggering scheduling"); this.schedule(); }); @@ -1221,7 +1226,11 @@ export class Scheduler { // trigger scheduling immediately so waiting tasks can start without waiting // for the next poll interval (up to 15 seconds). if (resolvedParked.terminal.has(to) || to === resolvedParked.hold) { - schedulerLog.log(`Task moved to ${to} — triggering scheduling`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Duplicate of the column-move lifecycle line; schedule side-effect is not operator-facing. + */ + schedulerLog.debug(`Task moved to ${to} — triggering scheduling`); this.schedule(); } }); @@ -3092,7 +3101,12 @@ export class Scheduler { const feature = await this.resolveMissionFeatureForTask(missionStore, task); if (!feature) { - schedulerLog.log(`No linked feature found for task ${taskId} (sliceId=${task.sliceId ?? "none"}) — skipping mission status update`); + /* + FNXC:EngineDiagnostics 2026-08-03-05:54: + Most tasks are not mission-linked. Skipping mission status is the expected steady-state path, + not an operator-visible event — keep it off the default TUI unless FUSION_DEBUG=scheduler. + */ + schedulerLog.debug(`No linked feature found for task ${taskId} (sliceId=${task.sliceId ?? "none"}) — skipping mission status update`); return; } diff --git a/packages/engine/src/worktree-acquisition.ts b/packages/engine/src/worktree-acquisition.ts index f167311451..b2e96d4ca7 100644 --- a/packages/engine/src/worktree-acquisition.ts +++ b/packages/engine/src/worktree-acquisition.ts @@ -59,7 +59,7 @@ export interface AcquireTaskWorktreeOptions { store: TaskStore; settings: Partial; pool?: WorktreePool; - logger?: { log: (m: string) => void; warn: (m: string) => void; error?: (m: string) => void }; + logger?: { log: (m: string) => void; warn: (m: string) => void; debug?: (m: string) => void; error?: (m: string) => void }; audit?: Pick; runContext?: RunMutationContext; runInitCommand?: boolean; @@ -556,7 +556,8 @@ export async function acquireTaskWorktree(opts: AcquireTaskWorktreeOptions): Pro /** Warm-reuse an existing, usable, branch-matched worktree (mirrors the resume path). */ const reuseWarmWorktree = async (path: string, resumedBranch: string, source: "existing"): Promise => { - logger?.log(`Reusing existing worktree: ${path}`); + // FNXC:EngineDiagnostics 2026-08-03-05:54: warm reuse is the common healthy path; Worktree created stays info. + if (logger?.debug) logger.debug(`Reusing existing worktree: ${path}`); const cleanup = await removeDesktopBuildArtifacts(path, logger); if (cleanup.removed.length > 0) { await store.logEntry(task.id, `Removed desktop build artifacts from worktree: ${cleanup.removed.join(", ")}`, undefined, runContext); @@ -679,7 +680,8 @@ export async function acquireTaskWorktree(opts: AcquireTaskWorktreeOptions): Pro } if (task.worktree && isResume) { - logger?.log(`Reusing existing worktree: ${worktreePath}`); + // FNXC:EngineDiagnostics 2026-08-03-05:54: resume reuses the pinned path — expected, not a default-visible event. + if (logger?.debug) logger.debug(`Reusing existing worktree: ${worktreePath}`); const cleanup = await removeDesktopBuildArtifacts(worktreePath, logger); if (cleanup.removed.length > 0) { await store.logEntry(task.id, `Removed desktop build artifacts from worktree: ${cleanup.removed.join(", ")}`, undefined, runContext);