Fix orchestrator wait_for_events parked forever on message hydration failure (QUALITY-1904) - #15585
Conversation
…failure (QUALITY-1904) A new_message SSE event whose body fetch failed (hydrate_event_for_recipient returning None) was still counted toward the batch's max sequence, so persist_event_cursor advanced the cursor past it regardless. Once the cursor passed that sequence, no later reconnect would ever ask the server for it again, silently and permanently dropping the message. An orchestrator blocked in wait_for_events on exactly that message had no other way to wake up until a human noticed and manually prompted it, or the 30-60 minute watchdog fired. Fix: track whether a forwarded SSE item's hydration attempt failed (SseStreamItem::hydration_failed). Route failed-hydration new_message events into a per-conversation stalled_messages retry queue instead of the normal event/message batch, and cap persist_event_cursor so it never advances past the earliest still-stalled sequence. Retry hydration for the oldest stalled entry on every SSE drain tick (~500ms) until it succeeds or a ~20s retry budget is exhausted, at which point it is dropped so a truly unrecoverable message cannot stall the cursor forever. Covered by two new regression tests in orchestration_event_streamer_tests.rs exercising the cursor cap and the give-up path.
|
This PR was generated with Warp. Comment |
…t_cursor The stalled-message cursor cap only lived in persist_event_cursor, but apply_task_children (reached from register_parent_on_wait, the exact wait_for_events-time path this bug hit) and the on-server-token harness fetch both wrote ConversationStreamState::event_cursor directly, bypassing the cap entirely. Fix by routing every writer through two new helpers, capped_owner_event_cursor and set_owner_event_cursor. Also: - retry_stalled_message no longer charges a failed attempt against the retry budget when self_run_id can't be resolved yet (previously hydrate_event_for_recipient would reject the empty recipient_run_id outright, burning the budget for an unrelated reason). - retry_stalled_message now retries the lowest-sequence stalled entry (min_by_key) instead of relying on insertion order. - Giving up after MAX_STALLED_MESSAGE_RETRY_ATTEMPTS now explicitly advances the cursor past the abandoned sequence via set_owner_event_cursor, matching the log message instead of silently leaving the cursor pinned (which previously caused an endless re-stall/re-give-up loop on reconnect). - Corrected the MAX_STALLED_MESSAGE_RETRY_ATTEMPTS doc comment: retries are serialized and each attempt can take up to the 5s message-fetch timeout, so the real worst-case budget is on the order of minutes per event, not ~20s. New/updated tests: - wait_time_parent_registration_does_not_skip_past_a_stalled_message drives finish_register_parent_on_wait directly to prove the cap holds on that path. - retry_stalled_message_does_not_charge_an_attempt_when_self_run_id_is_unavailable. - hydration_failure_retry_gives_up_after_max_attempts now asserts the cursor actually advances on give-up.
There was a problem hiding this comment.
Overview
Fixes silent permanent loss of an inbox new_message whose hydration failed: the cursor no longer advances past an unresolved sequence, and the event is retried instead of dropped. The revision closed the critical hole from the first pass — every writer of event_cursor now goes through capped_owner_event_cursor, including the register_parent_on_wait path the incident actually hit — so the remaining items are for your judgment, not blockers.
Concerns
- CI has not validated this change. Every substantive job (tests, clippy/fmt, release compilation) is
SKIPPEDon the draft, andCheck CI resultsis red purely because its required jobs were skipped. The author's local presubmit was reported clean but nothing independent has run; marking the PR ready is what actually exercises it. - The give-up path advances only the in-memory cursor.
finish_stalled_message_retrycallsset_owner_event_cursorbut notpersist_event_cursor, so SQLite keeps the pinned value and a process restart re-reads it, redelivers the abandoned message and re-queues it with a fresh 40-attempt budget. That is the safe direction, but it is broader than what the log line claims, so either persist the advance or say the release is process-local.
Verdict
Checks: build not independently verified, tests reported passing locally (847/847), CI red due to draft-skipped required jobs, visual proof n/a
Found: 0 critical, 0 important, 2 suggestions, 0 nits
Responding as wilson: Open session · View in factory
- Remove transformation comments ("Routed through set_owner_event_cursor...")
at three call sites; the routing is evident from the call itself.
- State the cursor-cap rationale once, on capped_owner_event_cursor, instead
of repeating it at every writer.
- Stop enumerating callers in doc comments (capped_owner_event_cursor,
retry_stalled_message, enqueue_stalled_messages).
- Trim internal narration in MAX_STALLED_MESSAGE_RETRY_ATTEMPTS and
finish_stalled_message_retry docs to the non-obvious rationale only.
- Drop the (QUALITY-1904) issue tags; the link belongs in the PR description.
- Reflow comments to 100 columns via ./script/format.
No behavior changes.
…sage is stalled A stalled new_message event pins event_cursor behind it so the server keeps replaying from a safe point. But the owner drain's dedupe compared incoming events against that same pinned cursor, so a reconnect's replay of everything since the pin re-delivered events the drain had already fully processed while the stall was outstanding -- duplicate lifecycle events happen to be collapsed by the existing supersession rule, but a duplicate message injection is not. Add ConversationStreamState::handled_sequence, a local-only high-water mark of what the drain has actually delivered or given up on (never persisted, never sent to the server as the resume cursor). The owner drain's dedupe now compares against max(event_cursor, handled_sequence) instead of event_cursor alone, while a still-outstanding stalled sequence is always let back through the dedupe check regardless of handled_sequence, so its replay keeps reaching the stalled-message queue. Considered also deduping incoming events by event_id in enqueue_event_batch as a backstop. Decided against it: with the drain's own dedupe fixed at the source, a second mechanism doing the same job would only invite drift. Added a regression test that stalls one message, fully delivers a later one, simulates a reconnect replay of both, and asserts the already-delivered one is not redelivered while the stalled one remains resolvable via retry.
The dedupe bypass added in the previous commit lets a still-outstanding stalled sequence back through the drain filter on every replay so it keeps reaching enqueue_stalled_messages. But if that replay's own hydration attempt succeeds, the event was delivered through the normal batch path while its stalled_messages entry was left in place. The independent retry timer would later hydrate the same sequence again and deliver it a second time via finish_stalled_message_retry. Collect sequences resolved this way during the drain loop (mirroring newly_stalled) and remove the matching stalled_messages entries before the batch is handed off. This also makes advance_handled_sequence's input honest again (a sequence it counts as handled is no longer still queued) and lets capped_owner_event_cursor's cap clear immediately instead of waiting on the independent retry. Added a regression test that stalls a sequence, replays it with hydration succeeding, and asserts both a single delivery and an empty stalled queue afterward -- verified to fail against the prior commit.



Description
While investigating QUALITY-1904 — an orchestrator parked in
wait_for_eventsthat sat for ~50 minutes without waking on a child's message, only delivered after a human manually prompted it and a later execution restarted — I found a real bug in how the client handles a child agent's message: if fetching the message's body failed even once (e.g. a transient timeout), the message was silently dropped and could never be redelivered, because the client had already advanced past it and the server only resends events "since" the last position it saw.This PR fixes that defect. It does not change how streams are opened or reconnect, so it may not be the actual cause of the QUALITY-1904 incident; a separate, unrelated fix addresses that.
Root cause
SseForwardingConsumer::on_eventhydrates anew_messageevent's body over the network. When that fetch failed, the event was still counted as processed and the cursor still advanced past it, so the message could never come back.Fix
Linked Issue
Testing
orchestration_event_streamer_tests.rs:wait_for_events-time cursor write also respects the cap.self_run_iddoesn't count against the retry budget.cargo clippy -p warp --all-targets --tests -- -D warnings— clean.cargo fmt --check— clean.cargo test -p warp --lib ai::blocklist::— all 849 tests pass, including the 6 new/updatedorchestration_event_streamerones. (One unrelated pre-existing test,secret_redaction::test_detect_secrets_no_regexes_configured, is flaky under full-suite parallel execution and passes in isolation/reruns; unrelated to this change.)./script/run— not applicable; this only exercises under cloud/agent_sdk orchestration with a live server SSE connection, which isn't reproducible via the local desktop app. Verified via the unit tests above instead.Agent Mode
CHANGELOG-BUG-FIX: Fixed a bug where a cloud orchestrator agent waiting on
wait_for_eventscould get permanently stuck and never receive a child agent's message if the message's body failed to fetch once.