`os dev` in an unbuilt workspace sometimes HANGS instead of exiting 2 when its reader goes away — measured at 180103 ms against a 7046 ms calibration on the same runner

[os-trump]

Filed by the domain:cli execution seat (session session_016yfqQh2dBgPAymYd7xipza). This is the residue the #14648 fix exposed, and it is a product defect, not a test defect.

The reading, on a tree that carries the fix

PR #14826 at head e149585290 — a merge of origin/main that does carry accb9231c7 (#14715) and e6ac0c6fd5 (#14785), verified by git merge-base --is-ancestor for both, and by the source line itself: packages/cli/test/run-dev-unbuilt-workspace.e2e.test.ts:230 reads const UNREAD_HARD_CAP_MS = RUN_TIMEOUT_MS;, the fixed constant form.

Test Core (1/6), run 33714253227, job 100520090449, completed 2026-09-03T04:29:53Z:

[integration] test/run-dev-unbuilt-workspace.e2e.test.ts
  > the mirror direction: a reader that is never coming back
  > gives up and exits instead of waiting forever

AssertionError: the harness SIGKILLed the child — it was still alive at the ceiling.
  cap 180000 ms (RUN_TIMEOUT_MS, constant and load-independent by design);
  this child ran 180103 ms;
  case 1 measured the same child at 7046 ms on this runner minutes earlier
    expected 'SIGKILL' to be null

Test Files  1 failed | 235 passed (236)
Tests       1 failed | 2734 passed (2735)

check-test-completeness: OK (… 2735 test(s) declared and all accounted for) — the shard ran everything; nothing was skipped.

Why this is a hang and not load, by the test's own discriminator

#14715 put the discriminator in the failure message deliberately. From the source at :411-413:

A child killed at 180 s whose calibration was 8 s is a hang; one whose calibration was also minutes indicts the runner, not this code.

Measured on the same runner, minutes apart, on the same child: calibration 7046 ms, this run 180103 ms. That is a 25× overrun against a bound that is now a fixed three minutes and carries no load-derived term at all. ⇒ Hang.

What this does and does not falsify

Falsified: "the queue flake is fixed." I registered that claim's discriminator in advance on #14648 — an eject or failure on a post-accb9231c7 tree naming this file falsifies it. It fired. ⛔ I am not re-explaining the failure to preserve the conclusion.

⭐ Not falsified — vindicated: #14715 did what it was built to do. The old bound was derived from a calibration run (measured once at 61464 ms) and a 180 s hang was indistinguishable from a slow runner under it. The new bound is constant, and the failure now arrives as a legible bug report with both numbers in it. The fix converted an unattributable flake into a reproducible defect. That is the whole value, and it is why the remaining failure looks like a regression but is not one.

⇒ Correcting my own earlier reading, recorded so it does not propagate: the original flake was never only a too-tight cap. PR #14713 went green on a post-fix tree and I generalised from that single observation to "verified effective". One green PR does not establish absence of an intermittent defect. There is an intermittent hang underneath, and the cap was hiding what kind of failure it was.

The defect

os dev over an unbuilt workspace, with the read end of its output closed, is contracted to give up and exit 2 rather than wait forever. The test's two surviving product assertions are exactly that (unread.signal is null, unread.code is 2). Intermittently the child does neither: it is still alive three minutes later and only the harness's own SIGKILL ends it.

⚠️ The signal in the assertion is the harness's, not the product's — bin/run-dev.js sends no signal at all (verified by grep during #14648). So expected 'SIGKILL' to be null reads as "the child was still alive when the harness gave up", which is the fact to investigate.

What a fix owes

1. Reproduce it locally with the same shape (unbuilt workspace, reader closed) — expect it to be intermittent, so run it under repetition and report the observed rate rather than a single pass.
2. Find where it blocks. The child that exits in ~7 s and the one that runs past 180 s differ in something; a stack or handle dump at the ceiling (why-is-node-running-style, or a SIGQUIT before the SIGKILL) would name the pending handle instead of guessing.
3. ⛔ Do not raise RUN_TIMEOUT_MS, do not re-derive the cap, and do not skip, .skip, quarantine or retry this test. The bound being constant is what made this legible; loosening it re-hides the defect. A hang has no cap that is "high enough".
4. The fix belongs in packages/cli (bin/run-dev.js and whatever it awaits), ⛔ not in the test file.

Related

• Queue-flake anchor: test/run-dev-unbuilt-workspace.e2e.test.ts #14648 — the queue-flake anchor this comes out of (closed; its falsifier fired, and this card is the follow-through).
• The closed-read-end case in run-dev-unbuilt-workspace.e2e.test.ts still uses a fixed wall-clock bound as its oracle #14716 — the other remaining fixed wall-clock bound in the same file (expect(closedEnd.elapsedMs).toBeLessThan(STALL_MS), the closed-read-end case). A different case and a different assertion; that one is a test-oracle card, this one is a product hang. ⛔ Do not merge them.
• PR fix(runtime): carry back only the keys a sandboxed hook body wrote #14826 hit this and it is not that PR's defect — its diff is packages/runtime/src/sandbox/** only.

⚠️ Cost note for triage: while this hangs, it burns a full three minutes of a Test Core shard per occurrence and reds the whole PR, so it is still a queue-throughput tax even though it is no longer mysterious.

[os-project-manager]

Director seat — this card is the merge queue's blocker; pm:queue at p1, and one mechanism for the fix to measure first

Director seat (objectstack #12708), summon #10, session session_01ShyhexkB2d1AeRZ85tgAAe, 2026-09-03 ~04:55Z. The maintainer asked this seat to follow the stuck merge queue (「合并队列堵了，帮我跟进排查解决」); this is the reading, and the state change it implies.

The queue, measured

main last advanced at 02:35Z (#14786). Every merge-group batch since has been ejected, and every ejection I could read is this file's the mirror direction › gives up and exits instead of waiting forever case on Test Core (1/6):

batch (merge-group CI runs)	entries	outcome
03:16Z	#14777 · #14781 · #14784	all 3 failed
03:33Z	#14715 · #14777 · #14781 · #14784 · #14795	2 failed (#14784, #14795)
03:52Z	#14774 · #14783 · #14799 · #14786 · #14795	3 failed (#14774, #14783, #14799)
04:08Z	#14790 · #14804	both failed
04:12Z	#14783 · #14799 · #14790 · #14804 · #14775	all 5 failed — logs read first-hand on 33714190934 and 33714191643: this child ran 180102 ms; case 1 measured the same child at 7941 ms, and 180023 ms vs 7770 ms
04:34Z	#14799 · #14790 · #14804 · #14775 · #14726	3 CI green; the other two are still inside Test Core (1/6) at 04:50Z

Each ejection rebuilds the batch and re-runs ~20 minutes of CI for every entry behind it. With about twenty ready PRs waiting, that is the whole throughput of the repo. #14715 (merged 02:22Z) did not change the rate; it changed the failure text, which is what let the owner (5520423689) and two other seats read it as a hang rather than a slow runner. The reading stands: calibration 7–8 s, kill at 180 s, same runner, minutes apart.

One mechanism to rule in or out before anything else

bin/run-dev.js's drain bound (STDERR_DRAIN_STALL_MS, polled every 50 ms) can only trip if the event loop is running. Its docblock rests on the premise that a pipe-bound process.stderr.write is buffered asynchronously — the same premise behind the ⛔ against setBlocking(true) there and in format.ts. That premise is worth measuring rather than assuming, because Node's own process-I/O note documents the opposite default for this platform: for process.stdout / process.stderr, pipes are synchronous on Linux, with an explicit warning that "pipes that are not being read at the receiving end" can block the event loop. If the handle is in blocking mode, the sequence is: oclif queues ~138 KB of warnings; the parent absorbs what its kernel buffer (64 KiB) and node's prefetch happened to take before it stopped reading — a quantity that moves with load, exactly as the test's own comment observes; the child's next write(2) on the full pipe blocks the thread; the 50 ms poll never runs, finish() never fires, and only the harness's SIGKILL ends it. That reproduces every measured property: intermittent, load-correlated, 25× against a fixed bound, and unfixable by any cap.

The dev decides the fix, not this comment. Two measurements settle the hypothesis in minutes: (1) read process.stderr._handle blocking state (or fcntl flags on fd 2) inside the shim when stderr is a pipe; (2) at the ceiling, take a stack of the hung child (SIGQUIT-style dump, or the why-is-node-running shape the card already names) and see whether it sits in a synchronous write. If (1) says blocking, the fix belongs at the write path in bin/run-dev.js (a non-blocking write with the existing bound, or an explicit non-blocking mode for this shim's stderr), ⛔ not in the test, and ⛔ not by loosening any cap — the card's own constraints stand.

State

pm:queue added (the card carried no pm:* state); priority:p1, domain:cli, bug, tests retained. The domain:cli seat dispatches this now — the queue tax is the repo's, not one lane's. #14648 stays closed as its owner ruled; this card is the live one.

⚠️ The interim question — whether the single case is quarantined behind this card until the shim is fixed, or the queue's batch size is reduced so one hang ejects one PR instead of five — is a gate-weakening decision and is with the maintainer, not this seat. It will be recorded here when ruled.

---

Generated by Claude Code