CI flake: experimental-remote-runtime worker-owned-provider stream fails with socket queue stall (1/3446, rerun green)

[code-yeongyu]

Summary

test/experimental-remote-runtime.test.ts > experimental durable server composition > streams prompt events through the worker-owned service provider failed once in CI with an event-sequence assertion while the RPC socket event queue logged stall/overflow warnings. It passed on rerun, on main, and on the branch head — classified as a timing flake, filed for a root-cause fix per the flake policy (fix merged to base, not just reruns).

Actual

CI run 34799956108, job 103840461978 (PR #1673, merged head 01863bd):

• AssertionError: expected [ 'run_start', 'message_start', …(8) ] to deeply equal ArrayContaining{…}
• Logged just before: socket event queue stalled: peer did not drain 57 queued bytes within 50ms (twice) and socket event queue overflow: 0 queued + 2166 incoming > 1024.

Expected

The worker-owned provider event stream is deterministic under CI load; a slow peer drain does not reorder or drop the expected prompt events.

Classification evidence (three-step)

1. No intentional change: the PR diff touched only ask-user multi-select keys/state/render/tests + CHANGELOG.
2. BASE contrast: main CI run 34797565211 (post-fix(coding-agent): cover Alt+Enter echo path and ignore kitty Escape releases in /btw #1675) all shards green; the PR's pre-merge branch head also had this shard green (10m12s pass).
3. Rerun of the failed job: green. Fail 1 / 3446 passed in the failing attempt.

Hypothesis

Timing-sensitive RPC socket event-queue liveness guard: the 50ms peer-drain window can abort/close the queue under CI contention, disturbing the event sequence the test asserts. Related families: credit-timeout quarantine, RPC worker stall retries.

Scope / acceptance

• Reproduce under load or fault injection (slow reader), identify whether the queue-close path can drop/reorder events the test expects.
• Durable fix (backpressure tolerance, drain-window sizing, or test-level event subscription before trigger) merged to main; no test skip, no widened assertion.

[code-yeongyu]

Another occurrence, on a changelog-only PR (#1723, head 82ded54): run 34980419035, job Test (coding-agent 3/3), 1 failed / 3547 passed.

test/experimental-remote-runtime.test.ts:617 streams prompt events through the worker-owned service provider: the received event list ends at entry_added with no run_end, and the same job log carries senpi rpc connection a event queue failed; closing: socket event queue stalled: peer did not drain 57 queued bytes within 50ms at 14:22:53Z, two and a half minutes before the assertion. main CI at 9c1d8bf (the PR's base) passed the same shard. Rerunning the failed job to unblock the PR; the 50 ms drain window under a loaded shard runner is still the shape reported above.

[code-yeongyu]

Second occurrence on the same PR (#1723, now 219b41b after merging main@9432e4e10): run 34983337687, Test (coding-agent 3/3), same assertion at experimental-remote-runtime.test.ts:617, received list ends without run_end. The stall/overflow log lines are the fanout tests' own 50 ms fixtures (DEFAULT_STALL_MS is 4000), so they are noise here.

Root cause is in packages/coding-agent/src/experimental/client.ts runClient(): the transcript subscription that feeds onEvent (and fills completedText) is torn down in the finally right after await agent.prompt(...) resolves. The prompt response and the transcript event stream are independent channels, so when the response lands before the trailing run_end (or message_end) delta is delivered, unsubscribe() drops it. The test then misses run_end; the same race can also return text: "" because completedText.get(response.operationId) is read after the subscription is gone.

Fix shape (production, not test-side): after an accepted prompt response, keep the subscription until a run_end whose runId === response.operationId has been delivered (bounded, e.g. 10 s, then fall through), and only then unsubscribe and await deliveryTail. A regression test can drive a transcript state whose run_end delta is published after the prompt response resolves.

[code-yeongyu]

New occurrence on main itself (not a PR branch): run https://github.com/code-yeongyu/senpi/actions/runs/34999159375 at 4d441c4 (merge of #1727, which touches only scripts/), job Test (coding-agent 3/3):

FAIL  test/experimental-remote-runtime.test.ts > experimental durable server composition > streams prompt events through the worker-owned service provider
AssertionError: expected [ 'run_start', 'message_start', …(8) ] to deeply equal ArrayContaining{…}

The four main runs after it (8fcaf76, 6773273, d872439, 8f4d3e1) were green on the same job, so this stays intermittent. Recording it here so the release pipeline's root npm test gate has a known-flake reference if it trips on this case.

[code-yeongyu]

Recurred again on the changelog-only PR #1756 (run 35061089643, job Test (coding-agent 3/3)): experimental-remote-runtime.test.ts > experimental durable server composition > streams prompt events through the worker-owned service provider — AssertionError: expected [ 'run_start', 'message_start', ... ] to deeply equal ArrayContaining{...}. The PR changes only a CHANGELOG line, so this is purely the tracked socket-queue flake, not the change. Merged via admin (changelog gate itself was green). Flagging the rising hit rate — it blocked a docs PR and is a risk for the release job's root npm test.

[code-yeongyu]

Root-caused and fixed in #1770.

Root cause. A Session worker writes a run's provider updates and that run's operation response to one control channel, in that order. The experimental server forwarded them on two independent paths: service events through an async delivery chain whose entries await the client socket write (SessionWorkerManager.#handleServiceEvent), and operation responses settled the moment they arrived (#handleOperationResponse). When the presentation peer was slow to drain, the still-queued trailing update lost the race: the prompt response frame was written first, runClient unsubscribed from the transcript as soon as agent.prompt() resolved, and the run_end that arrived after that was dropped.

Evidence (runtime, not code reading). Wrapping the server's client-facing ByteConnection.send gives the healthy frame order:

... 20 message_end   21 entry_added   22 usage   23 service_update(run_end)   24 response(accepted, operationId)

Injecting the fault the CI logs describe — the peer stops draining while frame 23 is being written, released only when another frame overtakes it (no wall-clock sleep) — produces exactly this issue's failure, 3/3 runs:

AssertionError: expected [ 'run_start', 'message_start', …(9) ] to deeply equal ArrayContaining{…}
received: ["run_start","message_start","message_end","entry_added","message_start",
           "message_update","message_update","message_update","message_end","entry_added","usage"]

run_end missing, received list ending at entry_added — the same shape as the four reported occurrences.

The socket-queue hypothesis in the issue body is refuted. src/modes/rpc/socket-event-fanout.ts (the source of socket event queue stalled: peer did not drain N queued bytes within 50ms and socket event queue overflow: … > 1024) is never imported by the experimental runtime; those lines are the fanout suite's own 50 ms fixtures running in the same shard (DEFAULT_STALL_MS is 4000 in production). No queue limit or drain window was changed.

Fix. Service events and operation responses for one attachment scope now share a single FIFO, so the client observes the worker's emission order and a slow drain applies backpressure to the response instead of dropping events; buffering stays bounded by the connection's existing pending-byte limit and its explicit disconnect. runClient additionally keeps its transcript subscription until the prompted run's own terminal event is delivered, which also fixes the variant where the returned text came back empty.

Regression coverage. The fault injection is kept as a test (delivered event list + the frame order the peer receives), plus a host-seam unit contract that a response cannot settle ahead of an update that arrived before it. Isolation matrix under the same injection: unfixed → fails with run_end missing; client-side change alone → still fails on frame order; host FIFO → green. 10/10 consecutive runs of the affected files green with CI=1.