Report liveness while a provider call is in flight (Trace ABI v8) - #205
Merged
Conversation
A host's no-progress watchdog cannot distinguish "blocked on the network" from "wedged in WASM" by silence alone, so it was killing healthy runs whose subcall simply took a while. Measured on a real corpus: a run doing genuine work was SIGKILLed at 210s against a 180s no-progress budget, while every turn that ever succeeded finished in under 76s. Batch subcalls are the worst case and explain why raising the number would not have fixed it. They post to `/responses/batch`, which does not match the `/responses` suffix the relay streams on, so they emit no `reasoning_delta` either — nothing at all reaches the host between the subcall's start and its completion, however long that takes. The new transient `heartbeat` event carries `elapsed_ms` and nothing else. No content, so it is not a retention or privacy question, and it can never reach a run record. Emitted from the relay rather than the engine, which is the whole point. Pyodide runs on the relay's thread, so this timer cannot fire while generated code spins in WASM — exactly when a watchdog SHOULD fire. It ticks only while the event loop is free, i.e. only while the process is genuinely healthy waiting on I/O. That is the discrimination the host was missing, and a test pins it directly: ticks land during an await, and none land while the thread is blocked. Raising the timeout was the alternative and was rejected: it trades one guess for another and still kills a batch that runs a minute longer. ABI 7 -> 8. Hosts must accept the new event and move to the trace_v8_* conformance fixtures. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
A streamed response resolves `fetch` as soon as headers arrive and then spends its minutes reading the body in streamResponses, so stopping the heartbeat at the fetch reported nothing for exactly the wait it exists to cover. Caught only by running it: a live query produced 4428 reasoning deltas and zero heartbeats. The unit test passed throughout, because it proved the timer mechanism worked rather than that it spanned the right window — a distinction worth remembering. Now started before the request and stopped in a finally, so it covers headers, body, streaming, and every error path. Verified against a live 75-second subcall: 15003, 30004, 45005, 60006, 75008 ms. The frame that run actually emitted is pinned as a test, including its depth-1 subcall shape. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Merged
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
A no-progress watchdog cannot distinguish "blocked on the network" from "wedged in the interpreter" — both are silence — so hosts were killing healthy runs whose subcall simply took a while.
Measured on a real 314k-message corpus: a run doing genuine work was SIGKILLed at 210s against a 180s no-progress budget, while every turn that ever succeeded finished in under 76s (p50 15.6s, p95 65.4s across 20 answered turns).
The new event
Transient
heartbeat, carryingelapsed_msand nothing else. Fires every 15s while any provider call is outstanding. No content, so it is not a retention or privacy question and can never reach a run record.Why relay-side, not engine-side
This is the whole design and it is the reason the fix works at all.
Pyodide runs on the relay's thread. A timer here cannot fire while generated code spins in WASM — which is exactly when a watchdog should fire. It ticks only while the event loop is free, i.e. only while the process is genuinely healthy waiting on I/O.
So a heartbeat can never mask a real wedge. It only reports the healthy case, which is precisely the discrimination hosts were missing. A test pins it directly: ticks land during an
await, and zero land while the thread is blocked.Why raising the timeout was rejected
It trades one unmeasured number for another, still kills a batch that runs a minute longer, and leaves the watchdog unable to tell apart the two states it exists to distinguish.
Why
reasoning_deltaalone was not enoughIt already streamed and was simply being ignored by hosts, which looked like a free fix. It is not sufficient:
wantsStreamrequires the URL to end with/responses. Batch subcalls do not match, so they stream nothing and go completely silent between start and completion — and a batch is exactly the call most likely to run long. That gap is what made the ABI bump necessary rather than optional.Verified against a live provider call
The second commit exists because the first implementation was wrong and only running it revealed that.
It wrapped
fetchalone. A streamed response resolvesfetchas soon as headers arrive and then spends its minutes reading the body, so the heartbeat stopped before the wait it exists to cover. A live query produced 4428 reasoning deltas and zero heartbeats. The unit test passed throughout — it proved the timer mechanism worked, not that it spanned the right window.Now started before the request and stopped in a
finally, covering headers, body, streaming, and every error path. Re-verified live:That 75-second call previously emitted nothing for its entire duration. Two or three inside one execution is how a healthy run accumulates 180s of apparent silence.
Those frames were
depth: 1— subcalls, the case this exists for. The frame that run actually emitted is pinned verbatim as a test, including an envelope field (parent_run_id) the synthetic test lacked, and confirmed to passisRlmEvent— the same forwarding filter that silently ate every checkpoint in the v7 emoji bug.Testing
1261 passed, 3 skipped, ruff clean,deno test pyodide/65 passed,deno checkclean.Notes for review
trace_v7_*→trace_v8_*, anddroste.testingexports change accordingly. Embedders must update;UPGRADING.mdcovers it in the release PR.🤖 Generated with Claude Code