`cancel interrupts loop queued behind shell` fails about one run in four, on Linux

[Edo771977]

Found by accident, and it is not a Windows-runner story: it reproduces on a four-core Linux box in this container, with an unmodified checkout.

The measurement

packages/opencode/test/session/prompt.test.ts:2011, run on its own (bun test test/session/prompt.test.ts -t "cancel interrupts loop queued behind shell" --timeout 30000), on dev at 37a3827c51 with no local changes:

run 1:  ^ this test timed out after 30000ms.   0 pass  1 fail
run 2:  1 pass
run 3:  1 pass
run 4:  1 pass

One failure in four, and it is the test's own 30s ceiling rather than an assertion. Two neighbouring variants of an unrelated log line gave 0 failures in 4 and 2 in 3 — all small samples of the same flake, which is how it was noticed: I attributed a 30s hang to a line I had just moved, and the control run without that line hangs too. That attribution is retracted on #40.

What it is waiting for

const sh = yield* prompt.shell({ sessionID: chat.id, agent: "build", command: "sleep 30" }).pipe(Effect.forkChild)
yield* waitForBusy(chat.id)
const loop = yield* prompt.loop({ sessionID: chat.id }).pipe(Effect.forkChild)
yield* Effect.sleep(50)
yield* prompt.cancel(chat.id)

const exit = yield* Fiber.await(loop)          // asserts "User aborted the command"
…
yield* Fiber.await(sh)                          // unbounded

The command is sleep 30 and the ceiling is 30s, so a cancel that does not actually end the shell is indistinguishable from the child simply running to completion. Since a failing assertion on the loop would report as an assertion, the timeout means one of the two Fiber.awaits never returned — and the test cannot say which, because the last one is unbounded. #28 gave the two sibling tests in this file named, bounded waits for exactly this reason; this one did not get the same treatment. Doing that is the cheap first step and would make the next occurrence say something.

The spawner is not where it is stuck

Worth recording so nobody repeats it. I probed the layer under shellImpl directly: spawn the resolved preferred shell running sleep 30 through CrossSpawnSpawner with the same options the shell tool uses (stdin: "ignore", forceKillAfter: "3 seconds"), start draining the merged output, then interrupt the fiber and let the scope release — ten iterations, 10/10 clean in 2–7ms. So interrupting a drain and killing the child does not hang at that level on Linux, and the close-versus-exit deviation recorded on #40 is not the mechanism here.

That leaves the cancel path above the spawner: prompt.cancel, shellImpl's abort handling, or the loop/queue coordination.

Why it matters beyond the test

If the cancel genuinely fails to end the shell about a quarter of the time, that is the product behaviour behind the test, not a test artifact: a user who aborts a long-running shell command gets a session that stays busy. The alternative — the cancel works and one of the fibers is not resolved — is a coordination bug in the same area. Both are worth more than a flaky test, and the current shape of the test cannot tell them apart.

Related but distinct: #40 is the Windows the shell never exited failure, whose own waits are bounded and named. Same family of question — a shell that ends and a wait that does not — on different platforms and, so far, with no shared mechanism established.

[Edo771977]

It says which step stops now, and it is the cancel itself

c136003bdc bounds and names every step of the test, with the ceiling raised above their sum — the first attempt kept the 30s ceiling and the ceiling won the race, which left the failure exactly as nameless as before. On the ninth run it spoke:

error: the cancel itself never returned
(fail) cancel interrupts loop queued behind shell [60000.02ms]

Not the loop, not the shell's exit: prompt.cancel(chat.id) does not return. And with the shell logging that went in for #40, the captured console gives the order:

15:58:55.012  INFO  cancel          { "session.id": "ses_f17426890ffe…" }
15:58:55.140  INFO  running shell   { shell: "/bin/bash", command: "sleep 30", cwd: "/tmp/opencode-test-gnxtcy1uc8v" }
15:59:00.016  INFO  disposing all instances

The cancel is issued 128ms before the shell has started. waitForBusy returned because the runner marks the session busy when the shell is admitted, not when it is running, so the cancel lands in the window between the two.

The spawn happens anyway

A temporary probe inside shellImpl, one log on entering the interruptible block and one after the spawn, on a failing run:

cancel
running shell
PROBE entering restore, about to spawn
PROBE spawned
error: the cancel itself never returned

So the pending interrupt does not stop the child being started, and after that the cancel waits — long enough to reach a 60-second ceiling, which is consistent with waiting out the sleep 30.

Where the cancel waits is Runner.stopShell (packages/opencode/src/effect/runner.ts:108-113):

const stopShell = (shell: ShellHandle<A, E>) =>
  Effect.gen(function* () {
    if (shell.ready) yield* shell.ready.await.pipe(Effect.exit, Effect.asVoid)
    yield* Deferred.succeed(shell.cancelled, undefined).pipe(Effect.asVoid)
    yield* Fiber.interrupt(shell.fiber)
  })

It waits for the shell's ready latch before interrupting — deliberate, so the abort has a part to mark — and Fiber.interrupt then waits for the fiber to terminate. shellImpl runs inside Effect.uninterruptibleMask with only the spawn/drain/exit block restored, and it also captures that block with Effect.exit, so there are two places an interrupt can fail to end the fiber promptly. Which of them it is, is the next step.

Two mechanisms measured and ruled out

Recorded so nobody pays for them twice. Both were probed at the CrossSpawnSpawner level with the resolved preferred shell running sleep 30 and the same options the shell tool uses:

• Interrupting a drain, then releasing the scope: 10/10 clean, 2–7ms.
• Interrupting a spawn whose output nobody has read yet — the exact window this failure lands in: 6/6 clean, 2–11ms.

So the close-versus-exit deviation recorded on #40 is not this, however well it fits the shape. That is worth knowing in both directions: it was my leading hypothesis twice.

And the rate was wrong

"About one run in four" came from a four-run sample. Across roughly forty runs today it is nearer one in ten — 1 of 4 unbounded, 1 of 8, 0 of 10, 1 of 10, 1 of 14. Still frequent enough to catch on demand, which is what makes this one worth finishing.

What it means if it is the product and not the test

The test is doing something a user does: abort a shell command right after starting it. If a cancel issued in that window does not end the shell and does not return, then a user who hits escape in the first tenth of a second waits out their own command with the session stuck busy. That is the thing to fix; the named waits only made it visible.

---

Generated by Claude Code

[Edo771977]

Found and fixed in 723a6bd2b3.

Where the fiber was held

Not at either of the two places I named last time. The probe walk, in order:

1. The shell fiber is interruptible when the cancel lands, the interrupt is delivered, and the fiber starts unwinding — the trail of interruptible transitions shows interruptUnsafe followed by the finalizer machinery entering an uninterruptible region.
2. PROBE inner exit { tag: "Failure" } fires, PROBE scope closed never does. So the hang is the scope finalizer, i.e. the spawner's acquireRelease release in packages/core/src/cross-spawn-spawner.ts.
3. That release signals the child and then awaits the deferred resolved by the child's close event. A snapshot of the stuck child:

pid: 4491, sig: "SIGTERM", group: []
stdio: [ "0:null",
         "1:d=true,  e=true,  f=false, lis=0, cl=0",
         "2:d=false, e=false, f=false, lis=0, cl=1" ]

The process is gone and its whole process group is empty. stdout ended and closed. stderr never did — never read, never destroyed, still open. Node emits close only once every stdio pipe it opened has closed as well, and a pipe nobody ever read never sees the EOF. So close never comes, Deferred.await(signal) never returns, and because the release runs uninterruptibly the fiber is held there for good.

That is why the timing is so tight: the cancel has to land in the window between the spawn returning and the drain having attached to both pipes. Earlier: PROBE spawned at 46.288, PROBE stopShell interrupting at 46.291 — 3 ms.

The fix

Close the pipes in the release instead of waiting on them. Nothing can read that output any more — the scope carrying the handle is being torn down — and a child that exited normally has already ended them, so the destroy is a no-op there.

What it costs the user without the fix

Cancelling a shell command in its first tenth of a second leaves the session busy until the command would have finished on its own. With sleep 30, thirty seconds of a session that ignores you.

Verification

cancel interrupts loop queued behind shell, which reproduces this by racing the cancel against the spawn: 10 failures in 62 runs before, 0 in 60 after. Both package suites re-run: the 5 remaining failures (flock/effect-flock unwritable roots, tool.write OS-denied write, the HttpApi log test, the tui legacy-config test) all fail identically without this change — most of them because these tests run as root.

What I did not add

No isolated spawner test. I tried three shapes — a pipe left completely untouched, a drain abandoned after it had started, and only one of the two pipes read — and all three tear down cleanly on their own in under 550 ms. What the race leaves behind is narrower than any of them, and a test that cannot fail when the fix is removed is not coverage. The loop test is the regression test, and it now names its failing step.

---

Generated by Claude Code