Files
fusion/docs/diagnostics.md
gsxdsm cca13737b6 FN-8603: reduce steady-state diagnostic log noise
Route routine core, engine, and dashboard diagnostics through debug-gated shared loggers.

- Demote steady-state diagnostic sites while preserving warnings and errors for actionable failures.
- Add cross-package severity contracts and manifest coverage for demoted log sites.
- Document logging severity guidance and add a patch changeset.

Files changed:
 .changeset/fn-8603-log-severity.md                 |  7 ++
 docs/diagnostics.md                                | 20 ++++--
 .../__tests__/log-severity-spam-contract.test.ts   | 71 ++++++++++++++++++
 packages/core/src/activity-analytics.ts            |  5 +-
 packages/core/src/ai-summarize.ts                  | 61 +++++++---------
 packages/core/src/async-mission-store.ts           |  5 +-
 packages/core/src/async-secrets-store.ts           |  7 +-
 packages/core/src/central-core.ts                  | 17 ++---
 packages/core/src/docker-provisioning.ts           | 13 ++--
 packages/core/src/index.ts                         |  1 +
 packages/core/src/master-key.ts                    |  9 ++-
 packages/core/src/memory-compaction.ts             | 29 ++++----
 packages/core/src/memory-insights.ts               |  7 +-
 packages/core/src/migration-orchestrator.ts        |  7 +-
 packages/core/src/mission-store.ts                 |  5 +-
 packages/core/src/node-discovery.ts                |  7 +-
 packages/core/src/notification/dispatcher.ts       |  9 ++-
 .../core/src/plugins/bundled-plugin-install.ts     | 11 +--
 packages/core/src/reflection-store.ts              |  5 +-
 packages/core/src/secrets-store.ts                 |  7 +-
 packages/core/src/task-store/agent-logs.ts         | 21 +++---
 packages/core/src/task-store/async-events.ts       |  5 +-
 packages/core/src/task-store/async-maintenance.ts  |  7 +-
 packages/core/src/task-store/comments-ops.ts       |  7 +-
 packages/core/src/task-store/task-mutation-ops.ts  | 11 +--
 packages/core/src/task-store/workflow-integrity.ts |  9 ++-
 packages/core/src/types/merge-policy.ts            |  5 +-
 packages/core/src/usage-events.ts                  |  5 +-
 .../__tests__/log-severity-spam-contract.test.ts   | 48 +++++++++++++
 packages/dashboard/src/ai-refine.ts                |  5 +-
 packages/dashboard/src/ai-session-diagnostics.ts   | 10 +--
 packages/dashboard/src/chat.ts                     |  8 ++-
 packages/dashboard/src/devserver-manager.ts        |  9 ++-
 packages/dashboard/src/file-service.ts             |  5 +-
 packages/dashboard/src/github-tracking-comments.ts |  7 +-
 .../dashboard/src/github-tracking-reconciler.ts    |  5 +-
 packages/dashboard/src/github-tracking-state.ts    |  5 +-
 packages/dashboard/src/gitlab-lifecycle.ts         |  5 +-
 packages/dashboard/src/insights-routes.ts          |  9 ++-
 packages/dashboard/src/issue-image-attachments.ts  |  5 +-
 packages/dashboard/src/knowledge-index.ts          |  5 +-
 packages/dashboard/src/plugin-routes.ts            |  7 +-
 packages/dashboard/src/routes/board-workflows.ts   |  5 +-
 packages/dashboard/src/routes/context.ts           |  5 +-
 .../dashboard/src/routes/register-auth-routes.ts   | 13 ++--
 .../routes/register-docker-provisioning-routes.ts  |  7 +-
 .../dashboard/src/routes/register-git-github.ts    | 21 +++---
 packages/dashboard/src/routes/register-gitlab.ts   |  7 +-
 .../src/routes/register-session-diff-routes.ts     |  9 ++-
 .../src/routes/register-settings-memory-routes.ts  |  7 +-
 .../src/routes/register-setup-activity-routes.ts   |  7 +-
 .../dashboard/src/routes/register-signal-routes.ts |  5 +-
 .../src/routes/register-task-workflow-routes.ts    | 11 +--
 packages/dashboard/src/runtime-logger.ts           | 11 +--
 packages/dashboard/src/server.ts                   |  7 +-
 packages/dashboard/src/sse.ts                      |  8 ++-
 packages/dashboard/src/terminal-service.ts         | 34 ++++-----
 packages/dashboard/src/view-chunk-manifest.ts      |  5 +-
 .../engine/src/__tests__/log-severity-manifest.ts  | 83 ++++++++++++++++++++++
 .../__tests__/log-severity-spam-contract.test.ts   | 40 ++++++++++-
 .../src/__tests__/logger-debug-gating.test.ts      |  7 +-
 packages/engine/src/goal-anchoring-audit.ts        |  5 +-
 packages/engine/src/plugin-runner.ts               | 44 ++++++------
 packages/engine/src/pty-native.ts                  |  9 ++-
 .../engine/src/runtimes/child-process-worker.ts    |  4 +-
 packages/engine/src/self-healing.ts                | 12 ++--
 packages/engine/src/worktree-hooks.ts              | 10 ++-
 67 files changed, 632 insertions(+), 250 deletions(-)

Fusion-Task-Id: FN-8603

Fusion-Task-Lineage: 53901db6-1af2-4bd7-b5ea-49507e048ef2

Co-authored-by: Fusion (runfusion.ai) <noreply@runfusion.ai>
2026-07-26 12:01:19 -07:00

18 KiB
Raw Blame History

Diagnostics

Debug-level diagnostics (FUSION_DEBUG)

Engine and core subsystem loggers (createLogger) expose a debug() level for routine diagnostics. It is off by default so the TUI log pane and engine stderr show state changes rather than repeated resting-state chatter.

Severity Use it for
debug() Repeated poll/sweep lines with unchanged state, expected skips and no-ops, per-item progress, expected-and-handled failures (fallback/retry/optional dependency), and diagnostics already recorded as run-audit events.
log() A state transition or operator-visible event.
warn() Handled degradation that needs eventual operator attention.
error() An unrecovered failure requiring operator action; do not use it when code recovered or scheduled a retry.

Most new diagnostic sites should therefore start at debug() and only be promoted when they meet a higher-severity rule. debug() output is enabled per subsystem with the logger prefix:

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 classes include local/default routing, capacity and re-entrancy skips, poll/sweep no-actions, per-step success/progress, optional integration probes, and successful verification bookkeeping. State-changing recovery and dispatch outcomes remain visible.

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.

packages/engine/src/__tests__/log-severity-manifest.ts and package contract tests pin individual demotions and the no-bare-console rule. This makes an accidental severity reversion a CI failure instead of an operator-visible log flood.

Goal injection diagnostics ([goal-injection])

Executor, heartbeat, and planning runs emit one goal-injection diagnostic with outcome applied, no-goals, or disabled-or-failed.

  • Run-audit event: prompt:goal-injection (database domain, target lane) with metadata { lane, outcome, goalCount, goalIds, provenanceGoalIds, truncated, reason?, errorClass?, runId?, agentId?, taskId? }.
  • Goal anchoring events also persist metadata.goalIds (alongside existing count/tool fields):
    • goal:injection-applied / goal:injection-skipped → { lane, count, goalIds, truncated?, reason? }
    • goal:retrieval-invoked → { toolName, count, goalIds, notFound }
  • Run cited-goals read path: GET /api/agents/:id/runs/:runId/cited-goals returns { runId, taskId?, injectedGoalIds, retrievedGoalIds, citedGoalIds } aggregated from goal:* + prompt:goal-injection run-audit events.
  • Task log (executor lane with taskId): [goal-injection] <outcome> count=<n> ids=<json-array> provenance=<json-array> truncated=<bool> ....
  • goalIds / goalCount describe the active goals injected into the prompt; provenanceGoalIds additively records mission-derived task provenance and does not affect prompt selection.
  • Guardrail: diagnostics persist goal IDs/counts only; never prompt text, goal titles, or goal descriptions.

Agent performance reflection telemetry

Agent reflection generation emits one run-audit event for every AgentReflectionService.generateReflection attempt, covering manual dashboard requests, executor/post-task tools, heartbeat tools, and self-improve callers from the shared service seam.

  • Run-audit events (database domain, target agentId):
    • reflection:generated metadata: { agentId, trigger, taskId?, reflectionId, tasksCompleted?, tasksFailed?, avgDurationMs?, commonErrorCount, insightCount, suggestedImprovementCount }.
    • reflection:skipped metadata: { agentId, trigger, taskId?, reason: "no-history" | "not-completed" }.
    • reflection:failed metadata: { agentId, trigger, taskId?, errorClass }.
  • Trigger taxonomy is preserved from ReflectionTrigger: manual, periodic, post-task, and user-requested.
  • The events use synthetic run context with phase reflection and source equal to the trigger so they correlate in the run-audit stream without requiring caller-specific wiring.
  • Guardrail: reflection diagnostics persist IDs, counts, reasons, and error classes only; never prompt text, reflection summaries, insight strings, suggested-improvement text, or free-form trigger details.

Post-task performance capture (reflection:captured, FN-7528)

AgentReflectionService.captureTaskPerformance is a deterministic, non-LLM counterpart to generateReflection: it runs once per completed task at the executor completion seam (TaskExecutor.signalTaskComplete), guarded by reflectionService presence, settings.reflectionEnabled, and an assigned agent id. It never calls the model provider and persists a compact structured post-task ReflectionMetrics record — duration, packages/files touched, verification command(s) + file-scoped-vs-broader classification, and retry/rework count — sourced only from the completed Task record. Fields whose source is unavailable are omitted, never fabricated.

  • Run-audit event (database domain, target agentId):
    • reflection:captured metadata: { agentId, trigger: "post-task", taskId?, reflectionId, retryReworkCount?, filesTouchedCount?, packagesTouchedCount?, verificationFileScoped?, durationMs? }.
    • Skipped/failed captures reuse the existing reflection:skipped (reason: "no-history" | "not-completed") and reflection:failed (errorClass) event types above.
  • Guardrail: capture telemetry stays ids/counts/outcomes-only — verificationScopeReason free-text, the deterministic one-line summary, and any prompt/reflection prose never reach run-audit metadata (they are stored only in the ReflectionMetrics/AgentReflection record itself).
  • Capture is best-effort and fire-and-forget: a capture failure never blocks or fails task completion, and an in-memory per-taskId guard prevents duplicate captures across the executor's several completion call sites (fresh completion, duplicate in-review re-entry, auto-recovery, paused-after-completion finalize, retry-completed).

Insight run sweeper ([insight-sweeper])

The dashboard insight router runs stale-run recovery sweeps for project_insight_runs rows stuck in pending/running without a live controller owner.

  • Recovery writes terminalCause: "orphaned_active_run_recovered" and lifecycle failure metadata (failureClass: "non_retryable", retryable: false).
  • Recovery appends both warning and status_changed events on project_insight_run_events with metadata.recovery = "orphaned_active_run".
  • metadata.recoverySource indicates where recovery occurred: startup, periodic, drive_by, or manual.

Dependency-blocked Todo backlog health ([dependency-blocked-todo])

Self-healing now runs surface-dependency-blocked-todos during both startup recovery and periodic maintenance.

  • Normal path emits a workflow insight titled Backlog health: dependency-blocked todos YYYY-MM-DD.
  • Fallback path (insight store unavailable) writes a per-task log entry prefixed with [dependency-blocked-todo] against the top blocker task.
  • Reporter summary warnings include group count, total blocked Todo count, and top blocker IDs.

Operator interpretation:

  • ageBucket: "fresh" → expected dependency queueing.
  • ageBucket: "aging" → review blocker progress.
  • ageBucket: "stale" → emerging stall; escalate/unblock blocker.

Windows embedded PostgreSQL recovery ([postgres-embedded], FN-8522)

When a Fusion-owned Windows embedded cluster reports the exact 0xC0000142 backend DLL-initialization failure followed by PostgreSQL's shutdown chain, the existing startup/System diagnostic sink records:

  • detected Windows DLL initialization shutdown; attempting one owned-cluster recovery
  • Windows owned-cluster recovery completed; existing pools may reconnect, or
  • Windows DLL initialization recovery failed after one retry; restart Fusion and inspect the System log

The recovery budget is one per lifecycle and applies only to a post-readiness cluster Fusion started. It never restarts a joined cluster. On the terminal message, restart Fusion; if it repeats, retain the System log and bundled-runtime version for support rather than deleting the data directory.

Process supervisor ([process-supervisor])

The process supervisor logs when it registers a supervised child, starts teardown, expires the grace window, escalates to SIGKILL, or observes a natural child exit.

  • spawned pid=<pid> pgid=<pgid|n/a> command=<cmd> — child registered for parent-death supervision.
  • terminating pid=<pid> pgid=<pgid|n/a> reason=<reason> — teardown cascade started.
  • grace expired for pid=<pid>; escalating to SIGKILL — child ignored the grace window.
  • sent SIGKILL to pid=<pid> pgid=<pgid|n/a> — hard-kill escalation sent.
  • maxLifetime exceeded for pid=<pid> after <ms>ms — lifetime watchdog fired.
  • child pid=<pid> exited naturally code=<n|null> signal=<n|null> — child deregistered after exit.

Self-healing surfacing passes ([self-healing])

  • surface-in-review-stalls
    • Log prefix: In-review stall surfaced [
    • Purpose: reason-driven in-review stall detector (merge-blocker, retry exhaustion, no-worktree, transient merge-status orphaning).
  • surface-in-review-stalled
    • Log prefix: In-review stalled surfaced [in-review-stalled]: quiet ...
    • Purpose: time-quiet detector for unpaused in-review tasks beyond inReviewStalledThresholdMs.
    • Non-overlap: skipped when reason-driven In-review stall surfaced [ is fresh, and skipped for paused tasks (owned by stale-paused-review).
  • surface-stale-paused-reviews
    • Log prefix: Stale paused review surfaced [stale-paused-review]: paused ...
    • Purpose: paused in-review backlog-health detector gated by stalePausedReviewThresholdMs.
  • FN-5335 backward-move annotations
    • Log prefix shape: [<stage-name>] <taskId>: triple-proof not satisfied — no action (operator-decides)
    • Representative stage names: no-progress-no-task-done, partial-progress-no-task-done, stale-incomplete-review, ghost-review, missing-worktree-review, stuck-merge-deadlock, finalize-no-op-review, reclaim-pr-conflict, reclaim-self-owned-branch-conflict, auto-rebound-paused-scope-decay.

No-progress churn stuck-task escalation ([executor], [stuck-detector], [self-healing])

Time-based stuck/stalled/stale surfaces now floor activity timestamps using settings.engineActiveSinceMs plus settings.engineActivationGraceMs (default 300000). The runtime stamps engineActiveSinceMs on startup and each unpause transition so engine pause/downtime does not count as quiet time.

  • Trigger shape: one loop classification/compact-and-resume has already fired for the current execute() lifecycle, then ignored fn_task_update rebuffs accumulate to ignoredStepUpdateCount >= 25 without intervening progress.
  • Executor diagnostic: [executor] <taskId>: no-progress churn detected (ignoredStepUpdates=N, stuckKillStreak=M) — escalating to STUCK_NO_PROGRESS_CHURN.
  • Self-healing diagnostic: <taskId> no-progress churn detected (ignoredStepUpdates=N, stuckKillStreak=M) — marking failed.
  • Audit event: task:stuck-no-progress-churn-terminalized with { taskId, ignoredStepUpdateCount, stuckKillStreak, lastReason: "no-progress-churn" }.
  • Outcome: task is marked status: "failed", moved to in-review, and not requeued; operators should decompose/rescope the task instead of waiting for more automatic stuck-kill retries.

Dispatch oscillation breaker ([scheduler], [self-healing])

FN-5941 adds a convergence backstop for repeated todo↔in-progress churn.

  • Suppressed false-positive backward recoveries emit task:reclaim-self-owned-branch-conflict-no-action, task:auto-recover-in-progress-limbo-no-action, or task:stuck-loop-exhausted-no-action with liveness metadata (taskId, branch, worktree, checkedOutBy, executionStartedAt, executionAgeMs, graceMs, liveWorktreeBoundBranch, reason).
  • Scheduler settle-window diagnostic: Task <id> was engine-requeued <age>ms ago — waiting <settleMs>ms settle window before redispatch.
  • Terminal audit event: task:dispatch-oscillation-terminalized with { taskId, cycleCount, windowMs, lastMoveSource }.
  • Outcome: task stays in todo, is auto-paused with pausedReason: "dispatch-oscillation", and requires operator unpause/forward progress to reset the counter.

Stale self-owned active-session cleanup diagnostics ([executor])

FN-5346 adds a same-task stale-binding reconcile marker before worktree removal:

  • [FN-5346] <taskId>: dropped stale self-owned activeSessionRegistry entry before removeWorktree at <worktreePath>
  • Follow-up task log entry: Cleared stale self-owned active-session entry before remove

Runtime stop diagnostics ([runtime-stop], [executor])

Engine stop now aborts in-flight executor AI sessions before the runtime drain wait.

  • Executor summary log: [executor] abortAllInFlight: aborted N task surface(s) — engine stop
  • Runtime warning when in-flight work still exists after configured post-abort drain: [runtime-stop] post-abort drain timeout reached with N tasks still in-flight

Use these together to distinguish expected immediate session teardown from genuinely stuck cleanup surfaces that outlive the configured runtimeStopDrainMs window.

Reports health stale-classifier diagnostics ([reports-health])

Direct-report stale decisions in HeartbeatMonitor.buildReportsHealthSection() now emit a structured log when an agent is marked **stale**.

  • Log shape: [reports-health] stale report <agentId> intervalSource=<source> staleThresholdMs=<n> heartbeatAgeMs=<n>
  • intervalSource values:
    • runtimeConfig — interval came from cached per-agent runtime config
    • persisted-agent — cache was missing/sparse; interval came from persisted getAgent() row
    • monitor-default — no per-agent interval available; monitor default interval used
  • staleThresholdMs is the computed stale threshold (max(1.5 × interval, 5m floor))
  • heartbeatAgeMs is the report's current heartbeat age at classification time
  • Healthy reports do not emit this diagnostic; only stale decisions do

Resume instrumentation (FN-5389, Phase 1)

Dashboard Phase 1 resume instrumentation adds observation-only client/server traces for refetch/reconnect attribution. It does not change visibility/pageshow/SSE behavior; FN-5392 consumes this data for fixes.

  • Client event shape (ResumeEvent): { ts, view, trigger, projectId?, gapMs?, replayAttempted, replayFromEventId?, lastEventId?, sseChannel?, reason?, detail? }.
  • Trigger taxonomy: visibility, pageshow, sse-error, sse-reconnect, sse-open, remount, route-active, route-inactive, project-context-change.
  • Sources:
    • sse-bus (pageshow, visible visibilitychange, openChannel, forceReconnect, EventSource error)
    • Hooks: useTasks (visibility, sse-reconnect), useChatRooms (sse-reconnect), useChat (sse-open, project-context-change)
    • Components: Board and ChatView mount/unmount route markers (remount / route-active / route-inactive)
  • Access paths:
    • Client ring (500): window.__fusionDebug.resumeInstrumentation.get() / .clear()
    • Server ring (5000, in-memory): GET /api/diagnostics/resume-events?limit=&since=&view= returns { events, droppedSinceLastRead }
  • Client batching: POST /api/diagnostics/resume-events in idle batches (<=25 per POST).
  • Disable knob: window.__fusionDebug.resumeInstrumentation.setEnabled(false).

FN-5415 extends this coverage across remaining board/data visibility hooks: useNodes, useMeshState, useProjects, and useManagedDockerNodes. Each now emits trigger: "visibility" with reason: "debounced-refresh" when refresh is taken and reason: "debounce-skipped" (including detail.timeSinceLastRefreshMs) when suppressed by debounce. This completes board/data-hook resume-correlation coverage needed for FN-5392 Phase 2 remediation analysis.

Phase 3 coverage (FN-5416)

FN-5416 extends resume-correlation coverage to stream-focused hooks and their primary route shells:

  • Hooks
    • usePrChecksStream: remount, visibility
    • useDevServerLogs: project-context-change, sse-open, sse-reconnect
    • useResearch: sse-open, sse-reconnect
    • useBackgroundSessions: sse-open, sse-reconnect
    • useAgentLogs: project-context-change, sse-open, sse-reconnect on /api/tasks/:id/logs/stream (live tail via SSE; historical reads are backed by .fusion/tasks/{ID}/agent-log.jsonl)
  • Route shells
    • DevServerView: remount / route-active / route-inactive
    • ResearchView: remount / route-active / route-inactive

Merge temp worktree cleanup classification ([merger])

Fusion merge cleanup treats a narrow class of temporary merge/post-merge worktree removal failures as non-fatal only after Git admin state proves there is no registered worktree leak.

  • Applies to Fusion-created temp merge paths such as fusion-ai-merge-* and post-merge paths such as post-merge-* during merger-cleanup / merger-post-merge removal.
  • Trigger shape: git worktree remove --force <path> fails with validation text such as fatal: validation failed, cannot remove working tree: '<path>/.git' is not a .git file.
  • Recovery proof: Fusion runs git worktree prune, then inspects git worktree list --porcelain.
  • Harmless classification: if the target path is absent from porcelain after prune, the merger logs that cleanup remove failed but no registered worktree remains. If a directory still exists, Fusion reports it as residue for operator inspection; it does not delete arbitrary /var/folders content.
  • Leak classification: if the target path is still present in porcelain after prune, the cleanup failure remains visible as a real registered-worktree leak.

Operator verification command:

git worktree list --porcelain | grep -F "<temp-worktree-path>"

No output means Git no longer registers that temp path; matching worktree <temp-worktree-path> output means the leak is still registered and needs operator cleanup.