Repository navigation
fix(cli): stop the TUI worker RPC from hanging on a dropped request - #14860
Conversation
The release-only `validate-cli-*` gate has failed three runs in a row with an opaque `TUI timed out during screen ... screen="" output=<5222 chars>`. The captured payload is byte-identical across runs, OS families and architectures (5222 chars on Unix, 4735 on Windows) and always starts at the first byte, so the stream genuinely stops at the end of the first blank frame rather than being truncated. Which targets fail shuffles per run; how they fail never does. The harness could not tell us why, because `render()` threw only the VT stream and its `finally` deleted the temp home first -- discarding the one artifact that identifies the hung step, the CLI log the child writes under `$XDG_DATA_HOME/kilo/log`. Attach that log tail to the failure, along with child liveness and stream-idle age, so a red run names the startup step that hangs instead of requiring a local repro that has never reproduced. - read the log directory rather than guessing filenames (dev.log, opencode.log, and a timestamped .log all occur) and skip nested directories - record chunks/bytes/idle and probe the child with `kill(pid, 0)`, mirroring the existing pattern in kilocode/pty/termination.ts, so a failure says whether the child was alive and whether the stream had gone quiet - fail fast after 25s of silence during the screen phase only; input/edit are driven by the 1s probe, so a global idle check there would risk new flakes - convert the rejection into a value instead of adding a try/catch, which lets the child terminate before the log is read and keeps the original failure ahead of any termination error - add KILO_PTY_SMOKE_KEEP=1 to retain the harness home for inspection Also add a dispatch-only validate-cli-smoke workflow. publish.yml owns the compiled `__pty-smoke` gate but is workflow_dispatch-only and goes on to publish, so that gate never runs on a branch; test.yml covers only the unit tests against synthetic renderers, not the standalone binary. The new workflow builds for the host platform and runs the same smoke step on the four targets that failed, with no signing, release or publish.
The first instrumented run (37491326744) reproduced the stall on darwin-x64 and windows-x64 and showed `alive=true idle=25s bytes=5222/4753`: the child is healthy but silent. The attached log tail ends at the last global-config line and never reaches `creating instance`, which `InstanceStore.load` emits from the TUI *worker* thread. Raising the child's log level alone does not localise it -- a healthy startup has a ~1.2s window between the last config line and `creating instance` with no log statements in either file. So add checkpoints at the two worker boundaries. With no --port, `external` is false and the TUI proxies every HTTP call through `createWorkerFetch`, so a worker that never answers leaves the TUI painted but dataless -- matching the observed single blank frame. `Rpc.client().call()` builds `new Promise((resolve) => ...)` with no reject path and no timeout, and the worker handler posts `rpc.result` only on success, so a dropped message or a worker-side throw hangs the caller forever with no error. The captured output carries no worker error text, which rules out a worker throw and leaves "never booted" vs "booted but RPC stuck" -- exactly what these checkpoints separate. - log `worker booted` after the worker's own KiloLog.init, and `worker listening` after Rpc.listen, so the log tail says which side stalled - raise the harness child to DEBUG (KiloLog.init and Logging.minimumLogLevel both already read KILO_LOG_LEVEL, so no shared logging change is needed), overridable via KILO_PTY_SMOKE_LOG_LEVEL - widen DIAGNOSTIC to the spellings worker.ts actually prints (`worker unhandledRejection` / `worker uncaughtException`), which the old `unhandled exception` alternation missed This is diagnostic only; the missing RPC timeout is a real product bug (a hiccuping worker gives users a permanently blank TUI with no error) and is left for a separate change.
Run 37493845893 pinned the release PTY smoke stall: both failing targets logged `worker booted` and `worker listening`, so the worker started and registered `onmessage`, yet `creating instance` never followed and the TUI sat on one blank frame with `alive=true`. The parent was waiting on a reply that never came. Two gaps in the worker transport combined: - `Rpc.listen` is the last statement in cli/tui/worker.ts, so `onmessage` was only assigned after the worker's top-level await and the evaluation of Server/InstanceRuntime/etc. Anything the parent posted in that window -- ~2s in CI -- was dropped. - `call` resolved from `new Promise((resolve) => ...)` with no reject path and no timeout, and the worker replied only on success. A dropped message or a throwing handler stranded the caller forever. With no --port the TUI proxies every HTTP call through the worker, so a single lost message left it painted but dataless: blank screen, process alive, no error. Users hit the same thing; the smoke gate was reporting a real defect. Fixes, with the logic in src/kilocode/util/rpc.ts and the shared file delegating behind kilocode_change markers: - `arm()` queues parent messages from the first line of the worker and `listen` replays them, closing the race - worker handlers answer failures as `rpc.error` (including unknown methods) and the client rejects with that message, so nothing is silently swallowed - bound only the pre-handshake window: the first reply from the worker clears the timers on in-flight calls, so a long proxied request is never cut short, while a worker that never answers now fails with a clear error Verified the regression test fails against the upstream implementation: the same "post before listen" scenario hangs indefinitely there and passes here. Locally 12/12 stress runs of the compiled binary render in ~2.2s with no stalls.
Run 37496124379 still failed on darwin-x64 with the unchanged signature (bytes=5222, alive=true, worker booted + listening, no `creating instance`) and no rpc error -- because the harness silence watchdog fires at 25s while the rpc handshake timeout was 30s, so the timeout never got to report. Make the handshake bound overridable and have the harness set it to 8s, well inside the watchdog, and log both ends of the exchange: - the worker logs every inbound request, which separates a lost request from a lost reply when the parent reports a timeout - the client logs the timeout before rejecting, so it lands in the attached log tail rather than depending on the TUI surfacing the rejection A healthy run logs `checkUpgrade` first and then `creating instance`, so the next failure distinguishes three cases: the request never arrived, it arrived and the handler hung, or the reply was lost.
Run 37497461267 showed the previous attempt did not close the race. Three targets failed and the worker logged only `tuiGone id=11` and `shutdown id=12` -- ids 0..10 never reached it. Two reasons: - `arm()` cannot run early enough. Static imports evaluate before the module body, so arming waits for Server/InstanceRuntime/etc to load, which is where most of the window goes (main banner 16:42:12 -> worker booted 16:42:14). - the handshake bound was keyed off any inbound message, and the worker emits global events before it can serve requests, so those events cleared the timers for the already-lost calls and the guard never fired. Gate on the parent instead, which removes the window rather than racing it: - `listen` announces `rpc.ready`, and the client holds every request in an outbox until it arrives, so nothing is posted while the worker is still evaluating imports - the client probes with `rpc.hello` and the worker answers with a fresh `rpc.ready`, covering the reverse order where the worker announced itself before the parent attached its handler and that announcement was lost - the only bound is "never became ready", so once the worker is serving, requests run unbounded and a long proxied request is not cut short - `arm` stays as a second line of defence and replays anything that still lands early, including the probe Tests cover both orders, the never-ready rejection, handler throws, async rejections and unknown methods. Verified the upstream implementation hangs indefinitely on the "post before listen" scenario. 10/10 local stress runs of the compiled binary render in ~2.2s.
The branch push trigger existed only because workflow_dispatch is unavailable until the file is on the default branch. It has served its purpose, and leaving it in would spend two macOS runners on every push to that branch. Once this is on main: gh workflow run validate-cli-smoke.yml --ref <branch>
Code Review SummaryStatus: No Issues Found | Recommendation: Merge The only incremental change since the previous review is the removal of the temporary branch-scoped Files Reviewed (1 file)
Previous Review Summaries (4 snapshots, latest commit 6eed952)Current summary above is authoritative. Previous snapshots are kept for context only. Previous review (commit 6eed952)Status: 1 Issue Found | Recommendation: Address before merge Overview
Issue Details (click to expand)SUGGESTION
Files Reviewed (7 files)
The transport hardening itself looks correct. Fix these issues in Kilo Cloud Previous review (commit f96c169)Status: No Issues Found | Recommendation: Merge The incremental change converts the single-line Files Reviewed (1 file)
Previous review (commit 43d88ef)Status: No Issues Found | Recommendation: Merge The two findings from the previous review are both resolved in this revision:
Files Reviewed (2 files)
Previous review (commit 114a87c)Status: 2 Issues Found | Recommendation: Address before merge Overview
Issue Details (click to expand)WARNING
SUGGESTION
NotesThe core fix is well designed. The Fix these issues in Kilo Cloud Files Reviewed (8 files)
Reviewed by deepseek-v4.1-flash · Input: 34.7K · Output: 3.9K · Cached: 265.2K Review guidance: REVIEW.md from base branch |
Two gaps in the ready-gating, both reachable in the TUI since tui.ts keeps
issuing proxied fetch and checkUpgrade calls long after startup.
- A call made after the never-ready bound elapsed queued forever: the timer had
cleared itself while `ready` stayed false, so the request joined `outbox` with
nothing left to settle it, reintroducing the silent hang in a narrower window.
The bound now records the error and `call` rejects with it immediately, and
`rpc.ready` clears that state so a worker which announces itself late is still
usable rather than permanently poisoned.
- A malformed KILO_RPC_HANDSHAKE_TIMEOUT failed every call at startup, because
`Number("")` is 0 and `Number("x")` is NaN and setTimeout treats both as the
next tick. The override now falls back to the 30s default unless it parses to
a finite positive number, which also covers 0 and negatives.
Confirmed the post-bound test catches the regression by removing the new guard
and re-running it: the test hangs indefinitely without it and passes once
restored.
The annotation guard failed on packages/opencode/src/cli/tui/worker.ts:21. A `kilocode_change` note on the preceding comment line does not cover the next line, so the added `Rpc.arm()` statement counted as an unannotated change to a shared upstream file. Wrap it in a start/end block instead. Comment-only change. The earlier local run used --worktree, which diffs HEAD..worktree and so saw nothing once the change was committed; CI runs --base <sha>, which reads the committed revision. Reproduced and verified with the same invocation CI uses.
…timeouts Adopts three ideas from #14849, which diagnosed the same startup race independently, and leaves util/rpc.ts byte-identical to upstream. Real-worker coverage. The in-process channel tests cannot reproduce the actual failure, because the bug is Bun discarding messages rather than anything in our own code. A fixture now holds a real Worker in the window that breaks, and measurement decided its shape: a message is lost only while the worker's event loop is alive with no `onmessage` installed, which is what a top-level await during module evaluation produces. A thread parked in `Atomics.wait` queues the message instead, so a blocking gate reproduces nothing -- the fixture polls a shared gate to keep the loop running, and the gate keeps it deterministic. Confirmed by deleting the outbox gating: the startup test then fails with "request lost during worker startup", and passes once restored. User-facing timeout. `client.ready` resolves false when the bound elapses, so tui.ts reports "TUI worker did not start within 30s" and leaves through the normal shutdown path instead of sitting on a blank screen. Transport-level gating stays as the guard for any call issued before that check. No upstream footprint. worker.ts and tui.ts now call KiloRpc directly, so util/rpc.ts is restored to upstream exactly and can never conflict on a fork merge. `Rpc.emit` still comes from upstream; the now-dead `Rpc` import in tui.ts is removed. Also tolerate non-envelope traffic on the channel. The fixture posts a SharedArrayBuffer and callers may postMessage anything, and a JSON.parse throw inside onmessage would take down the handler. Restores the temporary push trigger so the compiled smoke runs on this branch; it must come out before merge.
The branch push trigger existed only because workflow_dispatch is unavailable until the file is on the default branch. The compiled smoke has since passed on all four targets (run 37516104234), so drop it rather than spend two macOS runners on every push to the branch. Once this is on main: gh workflow run validate-cli-smoke.yml --ref <branch>
Problem
CLI/VS Code releases were blocked from v7.8.3 (2026-10-01). The release-only
validate-cli-*gate failed four dispatches with an opaque error:
The captured payload was byte-identical across runs, OS families and architectures —
5222 chars on every Unix target, 4735 on Windows — and always started at the first byte,
so nothing was truncated: the stream genuinely stopped at the end of the TUI's first blank
frame. Which targets failed shuffled every run; how they failed never did.
The gate was right. There is a real bug, and users hit it: a worker hiccup left the TUI on a
permanently blank screen with no error and no timeout.
Root cause
With no
--port, the TUI proxies every HTTP call through its worker thread viacreateWorkerFetch. Two defects in the worker RPC transport combined:Rpc.listenis the last statement incli/tui/worker.ts,reached only after the worker's top-level
awaitand the evaluation ofServer/InstanceRuntime/AppRuntime. Anything the parent posted in that window wasdiscarded. Measured at ~2s in CI (main banner
16:42:12→worker booted16:42:14).call()resolved fromnew Promise((resolve) => ...)with no rejectpath and no timeout, and the worker replied only on success. A dropped request or a throwing
handler stranded the caller permanently.
So one lost message meant a TUI painted but dataless: a single blank frame, process alive, no
error, forever.
I verified the runtime behaviour directly rather than assuming it. A message is lost only when
the worker's event loop is alive but no
onmessageexists yet, which is exactly what atop-level
awaitduring module evaluation produces. A thread parked inAtomics.waitqueuesthe message instead. That distinction matters for the test design below.
Fix
Gate on the parent, which removes the window rather than racing it. All logic lives in
src/kilocode/util/rpc.ts.listenannouncesrpc.ready; the client holds requests in an outbox until it arrives, sonothing is posted while the worker is still evaluating imports.
rpc.helloand the worker answers with a freshrpc.ready, coveringthe reverse order where the worker announced itself before the parent attached.
rpc.error(including unknown methods) and the clientrejects with that message, so nothing is silently swallowed.
so a long proxied request is never cut short.
client.readyresolvesfalseon timeout, andtui.tsreportsTUI worker did not start within 30sand leaves through the normalshutdownAndExitpath instead of hanging.arm()remains a second line of defence for anything that still lands early.postMessagecannot kill the handlerwith a
JSON.parsethrow.packages/opencode/src/util/rpc.tsis byte-identical to upstream — it does not appear inthis diff at all.
worker.tsandtui.tscallKiloRpcdirectly, so the shared transport cannever conflict on a fork merge.
Rpc.emitstill comes from upstream.Testing
test/kilocode/util/rpc.test.ts— 15 in-process tests: both handshake orders, thenever-ready rejection, rejection of calls made after the bound elapsed, recovery when the
worker is ready late, handler throws, async rejections, unknown methods, event delivery, and
malformed
KILO_RPC_HANDSHAKE_TIMEOUTvalues.test/kilocode/util/rpc-worker.test.ts— 4 tests against a realWorkerheld in thewindow that actually breaks. The fixture polls a shared gate so the event loop stays alive
with no handler installed; a blocking
Atomics.waitgate queues the message and reproducesnothing, which I confirmed before settling on this shape.
post-before-listen hangs indefinitely against the upstream implementation; deleting the
post-bound guard hangs
rejects calls made after the ready bound already elapsed; anddeleting the outbox gating fails the real-worker test with
request lost during worker startup.bun test ./test/kilocode/pty-smoke.test.ts16/16,bun run typecheckclean,check-opencode-annotations(default and--basemodes),check-workflows,check-md-table-padding, prettier clean on touched files.cli-darwin-arm64: 10/10 stress runs render in ~2.8–3.3s, no stalls.(
37516104234), and green twice at the earlier fix commit (37499273809, attempts 1 and 2)to sample the intermittency — against 8 failures in the 16 target-attempts before the fix.
Why
validate-cli-smoke.ymlis hereNothing in CI ever compiled the CLI on a PR or a push. That is the gap that let this reach
four release attempts:
publish.ymlworkflow_dispatchonly — and it goes on to publishcontainers.ymlmain, path-filtered topackages/containers/**, Linux Docker onlytest.ymlpty-smoke.test.tsfrom source against synthetic renderersSo the compiled
__pty-smokegate only ever ran during a release dispatch.test.ymlstayedgreen throughout, because the bug needs the compiled binary and a real worker thread.
This workflow builds for the host platform (
--single) and runs the identical smoke step onthe four targets that failed, with no signing, release or publish. It is what made this
diagnosable: five runs drove the investigation, and it disproved two of my own wrong fixes
(
37496124379,37497461267) instead of letting them ship.It is dispatch-only, which makes it investigation tooling rather than a guard — it will not
catch the next regression unless someone runs it. A path filter on
cli/tui/**,util/rpc.ts,pty-smoke.tsandscript/build.tswould have caught this bug on this PR.Happy to add that, or to drop the workflow, if you would rather. The repo is public, so runner
minutes are free; a full run is ~8–10 min.
One maintenance caveat: the smoke invocation is now duplicated between
publish.ymland thisworkflow and can drift. The cleaner shape is a reusable
workflow_callworkflow bothreference, which is more shared-CI refactoring than belongs here.
Also included
The diagnosis was impossible without these, and they make the next failure self-explanatory:
pty-smoke.tsattaches theopencode.log/dev.logtail plus child liveness(
alive=/idle=/chunks=/bytes=), and fails fast after 25s of silence in thescreenphase. Previously
render()threw only the VT stream and itsfinallydeleted the temp home,discarding the one artifact that identified the hung step.
KILO_PTY_SMOKE_KEEP=1retains it.DIAGNOSTICwidened to the spellingsworker.tsactually prints(
worker unhandledRejection/worker uncaughtException), which the oldunhandled exceptionalternation missed.Notes for the reviewer
readiness handshake, and I borrowed three things from it: the real-
Workertest, theuser-facing timeout message with a clean exit, and keeping
util/rpc.tsuntouched. The twoPRs conflict — both add a line right after
Rpc.listen(rpc)— so they should not both mergeas-is. Worth noting for
@lambertjosh: that PR's fixture parks the worker withAtomics.wait, which queues messages rather than dropping them, so its test would passwithout its fix.
reload(
SIGUSR2) andshutdownduring startup are covered too, and it adds therpc.errorrejectpath for throwing handlers — a separate latent hang.
precisely: Bun 1.4.2 is the trigger, the missing handshake is the defect. 1.3.14 queued
messages posted during worker startup and 1.4.2 drops them, which is why the race only became
visible after that bump.
simple-git3→4major bump. Unrelated to this work; the full
test.ymlrun has since passed on every shard,so it is covered.
v7.8.4draft release (26 assets) should be cleaned up before the next publishdispatch, or
versionmay collide on the same tag.