Skip to content

Commit a8a674a

Browse files
os-trumpclaude
andauthored
fix(cli): stop run-dev.js freezing in write(2) when its stderr reader stops reading (#14875)
* fix(cli): keep run-dev's stderr off the blocking write path Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza * test(cli): pin the stderr write path against a manufactured blocking pipe Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza * chore(changeset): record the run-dev stderr blocking-write hang fix Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza * test(cli): lift the never-read-reader quarantine now that the shim hang is fixed Reverses 392f410 exactly: the `'never-read'` spawn in `beforeAll` and the case it feeds are live again, and the definite-assignment assertion the quarantine needed is gone with it. The file is byte-for-byte its pre-quarantine shape (blob 131331e) — nothing else has touched it since. Per the maintainer's ruling A (2026-09-03): the quarantine is not a resting state, and the PR that fixes the hang re-enables the case in the same change. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_016yfqQh2dBgPAymYd7xipza --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent 85f3f55 commit a8a674a

6 files changed

Lines changed: 541 additions & 36 deletions

File tree

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,37 @@
1+
---
2+
"@objectstack/cli": patch
3+
---
4+
5+
fix(cli): `run-dev.js` can no longer freeze in the kernel when its stderr reader stops reading
6+
7+
Over an unbuilt workspace with the read end of its output alive but not being
8+
drained, the dev entry point is contracted to give up and exit 2 rather than
9+
wait. Intermittently it did neither: it stayed alive past every ceiling and
10+
ended only when something killed it — 27 of 30 runs on a cold `tsx` transform
11+
cache, against 1 of 90 on a warm one.
12+
13+
The bound that was supposed to stop it (`STDERR_DRAIN_STALL_MS`, polled by a
14+
50 ms `setInterval`) was not late; it was unreachable. Sampled from outside the
15+
process, the main thread was parked inside `write(2)` on fd 2 with `O_NONBLOCK`
16+
clear on that file description, so the event loop was not running and no timer,
17+
callback or promise in the file could fire. No ceiling of any size separates
18+
that from a wait, which is why raising and re-deriving one never helped.
19+
20+
The flag is not stable and nothing in this repo clears it: node sets
21+
`O_NONBLOCK` when it opens the pipe, and libuv clears it again in the pre-exec
22+
of any child spawned with inherited stdio — and because inheriting is `dup2`,
23+
the flag lives on an open file description the spawner shares, so the spawner
24+
loses it too. Under `tsx` that child is the esbuild service, started when a
25+
module has to be transformed, which is why a fresh CI checkout hits this and a
26+
warm developer box almost never does. Measured on one run: `O_NONBLOCK` true at
27+
102 ms, false at 1132 ms in the same sample the esbuild service appears in, main
28+
thread in `write(2)` from 2730 ms and never out of it.
29+
30+
`bin/run-dev.js` now re-asserts non-blocking mode on the write path before each
31+
stderr write, which cannot be outrun by a later spawn the way a one-shot at
32+
startup can. This is the inverse of the `setBlocking(true)` both this file and
33+
`src/utils/format.ts` refuse: it is what keeps their shared premise — that a
34+
write to a pipe gets buffered rather than parking the thread — true.
35+
36+
`bin/` is not named in this package's `files`, so only `bin/run.js` (the `bin`
37+
target) is packed: no published byte changes here.

packages/cli/bin/run-dev.js

Lines changed: 26 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,8 @@
1313
// exactly as it did.
1414
import { flush, handle, run, settings } from '@oclif/core';
1515

16+
import { keepStderrNonBlocking } from './stderr-nonblocking.mjs';
17+
1618
/**
1719
* How long stderr may make NO PROGRESS before this shim stops waiting for it.
1820
*
@@ -74,6 +76,15 @@ const STDERR_DRAIN_POLL_MS = 50;
7476
* ⛔ Deliberately NOT `process.stderr._handle.setBlocking(true)`: `format.ts`
7577
* records why — the same binary runs `os serve` / `os dev`, and a blocking
7678
* write to a pipe with a slow reader stalls the event loop.
79+
*
80+
* ⚠️ That last sentence is also this function's own PREMISE, not just a reason
81+
* to avoid a call: a bound enforced by a `setInterval` is worth nothing if a
82+
* write can park the thread. The premise is not free — libuv clears
83+
* `O_NONBLOCK` on fd 2's shared description in the pre-exec of any child
84+
* spawned with inherited stdio, and this shim runs under `tsx`, which spawns
85+
* the esbuild service on a cold transform cache. `keepStderrNonBlocking()`,
86+
* installed above `run()`, is what holds the premise true; without it this
87+
* bound is unreachable rather than late, which is a HANG and not a long wait.
7788
*/
7889
function writeStderr(text) {
7990
return new Promise((resolve) => {
@@ -169,6 +180,21 @@ async function announceUnbuiltWorkspace(error) {
169180
process.env.NODE_ENV = 'development';
170181
settings.debug = true;
171182

183+
// ⚠️ BEFORE `run()`, and that order is the whole point rather than tidiness.
184+
// The bound in `writeStderr` is a `setInterval`, so it can only fire while this
185+
// process's event loop is running — and every byte oclif is about to put on
186+
// stderr is written by `Config.load()`, long before this file gets control
187+
// back. If one of those writes parks the main thread inside `write(2)`, no
188+
// bound in this file has run yet or ever will: the process is frozen in the
189+
// kernel with the diagnostic still unwritten, and only a reader or a kill ends
190+
// it. Measured that way on an unbuilt workspace with the reader gone — 27 of 30
191+
// cold-cache runs, main thread in `write(2)` on fd 2 at `sock_alloc_send_pskb`,
192+
// still alive at a 90 s ceiling. `stderr-nonblocking.mjs` carries the whole
193+
// derivation, including who clears the flag (a child spawned with inherited
194+
// stdio — libuv clears `O_NONBLOCK` on the SHARED open file description) and
195+
// why the re-assert has to sit on the write path rather than run once here.
196+
keepStderrNonBlocking();
197+
172198
const running = run(process.argv.slice(2), import.meta.url);
173199

174200
// ⚠️ ATTACHED AFTER `run()`, and that order is load-bearing rather than style.
Lines changed: 109 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,109 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
3+
/**
4+
* Keep this process's stderr writes off the BLOCKING path for the whole run.
5+
*
6+
* `bin/run-dev.js` bounds how long it waits for stderr to drain, and the bound
7+
* is enforced by a 50 ms `setInterval`. That instrument — and every other
8+
* timer, callback and promise in the process — only exists while the event loop
9+
* is running, so the bound is worth exactly as much as the premise underneath
10+
* it: that a write to a pipe nobody is reading gets BUFFERED rather than
11+
* parking the thread inside `write(2)`.
12+
*
13+
* ## The premise is not free, and it was measured false
14+
*
15+
* Node makes that premise true when it opens the pipe: `uv_pipe_open()` sets
16+
* `O_NONBLOCK` on fd 2 the moment `process.stderr` is first touched. What is
17+
* easy to miss is that libuv CLEARS it again in the pre-exec of every child
18+
* spawned with inherited stdio (`uv__process_child_init` does exactly that for
19+
* fds 0-2, deliberately, because a child expects blocking stdio) — and since
20+
* inheriting is `dup2`, the child shares the parent's OPEN FILE DESCRIPTION.
21+
* The flag lives on the description, not on the fd number, so clearing it for
22+
* the child clears it for the SPAWNER TOO.
23+
*
24+
* Measured on one `os dev`-shaped run over an unbuilt workspace, sampling
25+
* `/proc/PID/fdinfo/2` from outside the process every 50 ms:
26+
*
27+
* ```
28+
* 102ms pid=19236 O_NONBLOCK=true (process.stderr materialised)
29+
* 1132ms pid=19236 O_NONBLOCK=false (esbuild service spawned; same sample)
30+
* 1132ms pid=19248 …/@esbuild/linux-x64/bin/esbuild --service=…
31+
* 2730ms pid=19236 O_NONBLOCK=false inWrite=true
32+
* ```
33+
*
34+
* and from there the main thread never left `write(2)`:
35+
*
36+
* ```
37+
* pid=19236 state=S syscall=1(write) args=0x2,…,0x244 wchan=sock_alloc_send_pskb
38+
* tid=19236 (node) syscall=1(write) ← the MAIN thread
39+
* ```
40+
*
41+
* With the loop parked in the kernel there is no late timer to catch up: the
42+
* no-progress bound is not slow, it is UNREACHABLE, and no ceiling of any size
43+
* distinguishes that from a wait. The process ends only when someone reads the
44+
* pipe or kills it. That is the hang.
45+
*
46+
* ⚠️ Nothing in the spawn is ours. The service is esbuild's, spawned by `tsx`
47+
* when it has to transform a module, which is why this reproduces on a COLD
48+
* transform cache (a fresh CI checkout) and almost never on a warm developer
49+
* box: measured 27 of 30 cold against 1 of 90 warm.
50+
*
51+
* ## Why the re-assert is on the WRITE path and not done once at startup
52+
*
53+
* Because the clearing happens at 1132 ms and is caused by a spawn this process
54+
* does not control or even know about. A one-shot at module top is undone by
55+
* the next `spawn(…, { stdio: 'inherit' })` anywhere in the process — including
56+
* from a module-hooks worker thread, which shares the same descriptions — and
57+
* it fails SILENTLY, back into the hang it was meant to prevent. Re-asserting
58+
* immediately before each write costs one `fcntl` and cannot be outrun by a
59+
* later spawn, whoever makes it.
60+
*
61+
* ## ⛔ This is not the prohibited call, it is its inverse
62+
*
63+
* `run-dev.js` and `src/utils/format.ts` both refuse
64+
* `_handle.setBlocking(TRUE)`, and that refusal stands: forcing blocking writes
65+
* process-wide is what stalls `os serve` / `os dev` on its own logs. This
66+
* function forces the other direction — it is the thing that KEEPS those two
67+
* docblocks true when something else has quietly flipped the flag.
68+
*
69+
* ⛔ It does not touch a TTY. A terminal is written synchronously on POSIX by
70+
* design, has no unread-reader failure mode (the reader is a human's terminal),
71+
* and prompt-adjacent output would change behaviour for no benefit.
72+
*/
73+
74+
/** Marks the stream so a second install cannot stack wrappers. */
75+
const INSTALLED = Symbol.for('objectstack.stderr-nonblocking');
76+
77+
/**
78+
* @param {NodeJS.WriteStream} [stream] The stream to guard; defaults to
79+
* `process.stderr`. Parameterised for the pin, which drives the guard against
80+
* a manufactured blocking pipe rather than waiting for a cold cache.
81+
* @returns {boolean} `true` when this process's writes are now guarded,
82+
* `false` when there was nothing to guard (a TTY, a file, a stream with no
83+
* libuv handle). The boolean is returned rather than logged: a reporter that
84+
* announces itself on the very stream it is repairing is the one thing this
85+
* file must not do.
86+
*/
87+
export function keepStderrNonBlocking(stream = process.stderr) {
88+
if (!stream || stream.isTTY === true) return false;
89+
const handle = stream._handle;
90+
if (!handle || typeof handle.setBlocking !== 'function') return false;
91+
if (stream[INSTALLED]) return true;
92+
93+
const write = stream.write;
94+
if (typeof write !== 'function') return false;
95+
96+
stream[INSTALLED] = true;
97+
stream.write = function guardedWrite(...args) {
98+
// One `fcntl`, immediately ahead of the syscall that would otherwise park
99+
// this thread. Wrapped because a stream that lost its handle mid-run must
100+
// still take the write — a repair that throws is worse than the defect.
101+
try {
102+
handle.setBlocking(false);
103+
} catch {
104+
// Nothing to say and nowhere safe to say it.
105+
}
106+
return write.apply(this, args);
107+
};
108+
return true;
109+
}
Lines changed: 107 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,107 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
3+
/**
4+
* The hazard `bin/stderr-nonblocking.mjs` exists for, MANUFACTURED rather than
5+
* waited for — driven by `run-dev-stderr-nonblocking.e2e.test.ts`.
6+
*
7+
* ⚠️ The reason this fixture exists at all is that the real occurrence is
8+
* INTERMITTENT: over the real CLI it reproduced 27 of 30 runs on a cold `tsx`
9+
* transform cache and 1 of 90 on a warm one. A pin that drove the real child
10+
* would therefore be green most of the time on a developer box while the defect
11+
* was fully present — a test that only fails intermittently is not a pin. So
12+
* this fixture reproduces the CONDITION deterministically and in ~200 ms:
13+
*
14+
* 1. materialise `process.stderr`, which is when node opens the pipe and sets
15+
* `O_NONBLOCK` on it — the state every healthy run starts in;
16+
* 2. spawn a trivial child with INHERITED stdio. libuv clears `O_NONBLOCK` on
17+
* fds 0-2 in the child's pre-exec, and inheriting is `dup2`, so the flag —
18+
* which lives on the shared open file description — is cleared for THIS
19+
* process too. In the real defect this spawn is the esbuild service that
20+
* `tsx` starts when it has to transform a module; nothing about the
21+
* mechanism needs it to be esbuild;
22+
* 3. write far past every buffer on the path (2 MiB, against ~128 KiB of
23+
* kernel pipe plus the parent's own readable buffer) to a reader that is
24+
* never coming back.
25+
*
26+
* With the flag cleared, step 3 parks the MAIN THREAD inside `write(2)` and the
27+
* event loop stops: no timer, no callback, no bound of any kind can run, and the
28+
* process ends only when someone reads the pipe or kills it. With the guard
29+
* installed, the same writes queue in userland and the process exits on its own.
30+
*
31+
* Every step announces itself into a MARKER FILE rather than onto stderr —
32+
* stderr is the thing under test and, in the failing arm, the thing that is
33+
* blocked. The markers are what let the harness tell "froze at the write" from
34+
* "was still booting", so its verdict never rests on wall clock alone.
35+
*
36+
* argv: `<marker file> guarded|unguarded`
37+
*/
38+
39+
import { spawnSync } from 'node:child_process';
40+
import { appendFileSync, readFileSync } from 'node:fs';
41+
42+
import { keepStderrNonBlocking } from '../../bin/stderr-nonblocking.mjs';
43+
44+
const [, , MARKS, ARM] = process.argv;
45+
const mark = (line) => appendFileSync(MARKS, `${line}\n`);
46+
47+
/**
48+
* The flag itself, read from the kernel rather than inferred.
49+
*
50+
* Linux-only. `unreadable` elsewhere, and the harness treats that as "cannot
51+
* confirm" instead of quietly assuming the hazard was armed — the one reading
52+
* that would make the control vacuous is `true`, and only that one is refused.
53+
*/
54+
function nonBlocking() {
55+
try {
56+
const flags = /flags:\s*(\d+)/.exec(readFileSync('/proc/self/fdinfo/2', 'utf8'))?.[1];
57+
return flags === undefined ? 'unreadable' : String((parseInt(flags, 8) & 0o4000) !== 0);
58+
} catch {
59+
return 'unreadable';
60+
}
61+
}
62+
63+
// Touching the stream is what materialises it; `writableLength` is the cheapest
64+
// touch that cannot itself write anything.
65+
void process.stderr.writableLength;
66+
mark(`START O_NONBLOCK=${nonBlocking()}`);
67+
68+
spawnSync(process.execPath, ['-e', '0'], { stdio: 'inherit' });
69+
mark(`HAZARD O_NONBLOCK=${nonBlocking()}`);
70+
71+
if (ARM === 'guarded') mark(`GUARD ${keepStderrNonBlocking()}`);
72+
73+
mark('WRITING');
74+
const chunk = 'x'.repeat(8 * 1024);
75+
// ⚠️ 2 MiB, and the size is a MEASUREMENT rather than a round number. A reader
76+
// that is merely paused is not the only absorber: the kernel pipe holds 64 KiB
77+
// and node's own readable buffer in the parent holds about another 64 KiB, so
78+
// ~128 KiB can disappear before the writer ever meets backpressure. 192 KiB was
79+
// tried first and the unguarded arm reached the end of its loop unblocked on
80+
// one run in two — a control that green-lights the very hazard it exists to
81+
// prove. 2 MiB is 16x that headroom, so no absorber on this path can swallow it.
82+
let backpressured = 0;
83+
for (let i = 0; i < 256; i++) {
84+
if (process.stderr.write(chunk) === false) backpressured += 1;
85+
// Progress, so a frozen arm shows WHERE it stopped rather than only that it
86+
// never finished — the difference between evidence and an empty timeout.
87+
//
88+
// ⚠️ Every 4 chunks (32 KiB), not every 32. The block lands around chunk 16 —
89+
// one kernel pipe plus one reader-side buffer in — so a coarser interval puts
90+
// the FIRST marker after the freeze, and the control then reads "froze before
91+
// any write landed" on a perfectly good reproduction. Measured that way.
92+
if ((i + 1) % 4 === 0) mark(`WROTE ${(i + 1) * 8} KiB`);
93+
}
94+
// ⚠️ `pending` is reported but deliberately NOT the evidence that the bytes
95+
// were kept. Measured: it reads 0 here even on a perfectly healthy guarded run,
96+
// because libuv has taken every chunk into its own write queue and
97+
// `writableLength` only counts what the STREAM still holds above the handle.
98+
// `bytesWritten` and `destroyed` are the readings that separate "buffered" from
99+
// "thrown away", so those are what the harness asserts on.
100+
mark(
101+
`WRITES RETURNED pending=${process.stderr.writableLength} bytesWritten=${process.stderr.bytesWritten} ` +
102+
`destroyed=${process.stderr.destroyed} backpressured=${backpressured}`,
103+
);
104+
105+
// A distinctive status, so "exited on its own" is evidence about THIS file
106+
// rather than about any process that happens to end in 0 or 1.
107+
process.exit(7);

0 commit comments

Comments
 (0)