bug: watchdog fails a completed synchronous execution after a backend restart instead of recovering its result #2944

Summary

When the backend is recreated while a synchronously dispatched execution (triggered_by = mcp / manual) is in flight, the agent keeps running and finishes normally, but its result is returned on the held-open HTTP connection whose backend worker no longer exists. The next cleanup cycle after the agent's 5-minute "recently completed" marker expires then writes status=failed, cost=NULL, response=NULL with the orphan message below — for a run that succeeded. The full terminal is sitting on the agent's disk (session JSONL) and the agent still answers recently_completed_ids for 5 minutes, yet the watchdog never asks for a result — only for a last-error — before failing the row. Observed on a 40-minute, $32 planning run; the operator lost the response and Trinity lost the cost attribution.

Component

Backend / services/cleanup_service.py (watchdog + boot recovery) · Agent Runtime / agent_server/services/process_registry.py

Priority

P2

Error

Execution not tracked by agent '[AGENT]' (not running, not pending, not recently completed) and no live backend dispatcher (not parked in this worker, no cross-worker marker) — recovered by watchdog

Backend log sequence (times relative):

T+0:00   [Recovery] Task execution recovery complete: recovered=0, still_running=1 ...   # new backend boots; the row is correctly left alone
T+29:00  agent: [Headless Task] Task <session> completed: cost=$32.00, duration=..., tools=240, raw_messages=1820
         agent: [ProcessRegistry] Unregistered execution <id>
         agent: [Task] Task <session> completed successfully                                # returned to a dead socket
T+30:10  [Cleanup] Cycle complete: {'orphaned_executions': 0, ...}                         # marker still fresh (70 s old) → skipped
T+35:10  agent: GET /api/executions/running  200
         agent: GET /api/executions/<id>/last-error  404
         [Slots] Agent released slot for execution <id>
         [Watchdog] orphan_recovered: execution <id>                                       # marker 370 s old → failed

Location

• File: src/backend/services/cleanup_service.py
  • _orphan_error_message (~line 92) and the orphan branch in the periodic watchdog (~lines 2195–2215): the only agent-side probe before _recover_execution(..., "orphan_recovered") is GET /api/executions/{id}/last-error (~line 2331); nothing asks the agent for a completed result.
  • Boot recovery (~lines 2755–2780): a row whose id is in the agent's registry is counted still_running and left alone — correct — but no consumer is re-attached, so its eventual result has nowhere to go.
  • CLEANUP_INTERVAL_SECONDS = 300 (line 109).
• File: src/backend/services/task_execution_service.py ~line 1307: async_dispatch = dispatch_async_eligible(triggered_by) — fire-and-forget (refactor: fire-and-forget dispatch — a hung turn holds zero backend resource #1083) is DISPATCH_ASYNC-gated and limited to ASYNC_DISPATCH_ELIGIBLE_TRIGGERS = {"schedule", "webhook"} (config.py ~line 254), so mcp/manual dispatches always ride the held-open connection.
• File: src/agent_server/services/process_registry.py line 32: RECENTLY_COMPLETED_TTL_SECONDS = 300 — identical to the cleanup interval, so one cycle is guaranteed to land just past the marker.

Root Cause

Two independent gaps compound:

1. No result-recovery path for synchronous dispatch. The result of a push-dispatched turn exists only as the HTTP response to the backend coroutine that made the call. A backend restart destroys that consumer. The refactor: fire-and-forget dispatch — a hung turn holds zero backend resource #1083 result-callback path that would survive this is opt-in and excluded for mcp/manual triggers by design (their callers consume result.response synchronously). Boot recovery correctly recognises "agent still running it, no dispatcher here", but its only two outcomes are wait and orphan → failed.
2. The orphan verdict asks the wrong question. _orphan_error_message says what was observed — "not running, not pending, not recently completed" — and that is accurate, but the verdict is written as failed with no attempt to fetch the terminal. The agent already has the machinery to reconstruct a completed turn from its session JSONL (bug: completed turn discarded on error_during_execution — jsonl_recovery never consulted, response lost despite end_turn in the JSONL #1870 recovered_terminal), and bug: watchdog fails admitted-but-undispatched executions as "completed on agent but status not reported", releasing their slots and masking the real terminal #2433 already established that the watchdog must not assert an outcome it did not observe. Here it asserts failure for a run whose success is on disk.

The TTL/interval equality makes the race deterministic rather than occasional: the first cycle after completion always sees a fresh marker and skips; the second always sees an expired one and fails the row.

Reproduction Steps

1. From an MCP client, chat_with_agent (or POST /api/agents/{name}/chat) with a task that runs for more than ~10 minutes on an agent with DISPATCH_ASYNC unset (the default).
2. While it is running, recreate the backend: docker compose -f docker-compose.prod.yml up -d backend (image rebuild or any config change that forces a recreate).
3. Boot log: [Recovery] ... still_running=1 — the row is left running.
4. Wait for the agent to finish ([Headless Task] Task ... completed in the agent log, [Task] Task ... completed successfully).
5. Wait two cleanup cycles (≤ 10 min). The row flips to failed with the orphan message, cost and response NULL.
6. Confirm the run actually succeeded: the session JSONL under ~/.claude/projects/ in the agent container carries the final assistant text; GET /api/executions/{id} shows nothing.

Suggested Fix

In order of value:

1. Try to recover the terminal before failing an orphan. In the watchdog's orphan branch, before _recover_execution(..., "orphan_recovered"), ask the agent for a completed result (new agent-server route, e.g. GET /api/executions/{id}/result, backed by the process registry's completion record and, failing that, the bug: completed turn discarded on error_during_execution — jsonl_recovery never consulted, response lost despite end_turn in the JSONL #1870 session-JSONL reconstruction). If the agent returns a terminal, write it as success with its cost/response/session id and record an activity noting it was recovered post-restart. Only fall through to failed when the agent genuinely has nothing.
2. Keep the completion record long enough to be found. RECENTLY_COMPLETED_TTL_SECONDS should comfortably exceed CLEANUP_INTERVAL_SECONDS (e.g. 2× + margin), and the completion entry should retain the terminal payload (or at least the session id) rather than just a timestamp, so (1) has something to fetch from.
3. Boot recovery: re-attach instead of only waiting. For rows counted still_running at boot with no local dispatcher, schedule a poll of the agent's completion record so the result is claimed as soon as it lands, rather than leaving it to the watchdog's orphan path.
4. Longer term this is what the pull spine (feat: pull / work-stealing coordination (push→pull dispatch) #1081) removes structurally — a pull-claimed turn reports its terminal via callback regardless of which backend process is alive — but until pull is default-on for every trigger, mcp/manual turns remain exposed.

Environment

• Trinity version: c9a71e7f (dev, 0.9.5 post-release), DISPATCH_ASYNC=false, TRINITY_PULL_MODE unset
• Database: PostgreSQL
• Docker version: 28.3.3
• OS: Debian 12 (host), agents on the current base image (RECENTLY_COMPLETED_TTL_SECONDS = 300)

Related

• refactor: fire-and-forget dispatch — a hung turn holds zero backend resource #1083 fire-and-forget dispatch + result callback (the path that would survive this; not eligible for mcp/manual)
• bug: watchdog fails admitted-but-undispatched executions as "completed on agent but status not reported", releasing their slots and masking the real terminal #2433 watchdog must not assert an outcome it did not observe (this is the mirror case: asserting failure for an observed-on-disk success)
• bug: completed turn discarded on error_during_execution — jsonl_recovery never consulted, response lost despite end_turn in the JSONL #1870 recovered_terminal — session-JSONL reconstruction of a completed turn, currently only reachable from inside the agent's own execution
• bug: circuit breaker dormant state silently blocks scheduled tasks for hours with no auto-recovery or notification #921 recently-completed window (origin of the 300 s TTL)
• bug: long-running backend→agent task calls dropped when uvicorn worker recycles #408 long-running backend→agent calls dropped on uvicorn worker recycle (fixed the recycle trigger, not the lost-result consequence)
• feat: pull / work-stealing coordination (push→pull dispatch) #1081 / Production soak-test of pull/work-stealing coordination (#1081) before default-on #1766 pull / work-stealing dispatch (structural fix)