fix(cli): stop run-dev.js freezing in write(2) when its stderr reader stops reading

.changeset/run-dev-stderr-blocking-write-hang.md

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

packages/cli/bin/run-dev.js

@@ -13,6 +13,8 @@
 // exactly as it did.
 import { flush, handle, run, settings } from '@oclif/core';
 
+import { keepStderrNonBlocking } from './stderr-nonblocking.mjs';
+
 /**
  * How long stderr may make NO PROGRESS before this shim stops waiting for it.
  *
@@ -74,6 +76,15 @@ const STDERR_DRAIN_POLL_MS = 50;
  * ⛔ Deliberately NOT `process.stderr._handle.setBlocking(true)`: `format.ts`
  * records why — the same binary runs `os serve` / `os dev`, and a blocking
  * write to a pipe with a slow reader stalls the event loop.
+ *
+ * ⚠️ That last sentence is also this function's own PREMISE, not just a reason
+ * to avoid a call: a bound enforced by a `setInterval` is worth nothing if a
+ * write can park the thread. The premise is not free — libuv clears
+ * `O_NONBLOCK` on fd 2's shared description in the pre-exec of any child
+ * spawned with inherited stdio, and this shim runs under `tsx`, which spawns
+ * the esbuild service on a cold transform cache. `keepStderrNonBlocking()`,
+ * installed above `run()`, is what holds the premise true; without it this
+ * bound is unreachable rather than late, which is a HANG and not a long wait.
  */
 function writeStderr(text) {
   return new Promise((resolve) => {
@@ -169,6 +180,21 @@ async function announceUnbuiltWorkspace(error) {
 process.env.NODE_ENV = 'development';
 settings.debug = true;
 
+// ⚠️ BEFORE `run()`, and that order is the whole point rather than tidiness.
+// The bound in `writeStderr` is a `setInterval`, so it can only fire while this
+// process's event loop is running — and every byte oclif is about to put on
+// stderr is written by `Config.load()`, long before this file gets control
+// back. If one of those writes parks the main thread inside `write(2)`, no
+// bound in this file has run yet or ever will: the process is frozen in the
+// kernel with the diagnostic still unwritten, and only a reader or a kill ends
+// it. Measured that way on an unbuilt workspace with the reader gone — 27 of 30
+// cold-cache runs, main thread in `write(2)` on fd 2 at `sock_alloc_send_pskb`,
+// still alive at a 90 s ceiling. `stderr-nonblocking.mjs` carries the whole
+// derivation, including who clears the flag (a child spawned with inherited
+// stdio — libuv clears `O_NONBLOCK` on the SHARED open file description) and
+// why the re-assert has to sit on the write path rather than run once here.
+keepStderrNonBlocking();
+
 const running = run(process.argv.slice(2), import.meta.url);
 
 // ⚠️ ATTACHED AFTER `run()`, and that order is load-bearing rather than style.

packages/cli/bin/stderr-nonblocking.mjs

@@ -0,0 +1,109 @@
+// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
+
+/**
+ * Keep this process's stderr writes off the BLOCKING path for the whole run.
+ *
+ * `bin/run-dev.js` bounds how long it waits for stderr to drain, and the bound
+ * is enforced by a 50 ms `setInterval`. That instrument — and every other
+ * timer, callback and promise in the process — only exists while the event loop
+ * is running, so the bound is worth exactly as much as the premise underneath
+ * it: that a write to a pipe nobody is reading gets BUFFERED rather than
+ * parking the thread inside `write(2)`.
+ *
+ * ## The premise is not free, and it was measured false
+ *
+ * Node makes that premise true when it opens the pipe: `uv_pipe_open()` sets
+ * `O_NONBLOCK` on fd 2 the moment `process.stderr` is first touched. What is
+ * easy to miss is that libuv CLEARS it again in the pre-exec of every child
+ * spawned with inherited stdio (`uv__process_child_init` does exactly that for
+ * fds 0-2, deliberately, because a child expects blocking stdio) — and since
+ * inheriting is `dup2`, the child shares the parent's OPEN FILE DESCRIPTION.
+ * The flag lives on the description, not on the fd number, so clearing it for
+ * the child clears it for the SPAWNER TOO.
+ *
+ * Measured on one `os dev`-shaped run over an unbuilt workspace, sampling
+ * `/proc/PID/fdinfo/2` from outside the process every 50 ms:
+ *
+ * ```
+ *  102ms pid=19236 O_NONBLOCK=true            (process.stderr materialised)
+ * 1132ms pid=19236 O_NONBLOCK=false           (esbuild service spawned; same sample)
+ * 1132ms pid=19248 …/@esbuild/linux-x64/bin/esbuild --service=…
+ * 2730ms pid=19236 O_NONBLOCK=false inWrite=true
+ * ```
+ *
+ * and from there the main thread never left `write(2)`:
+ *
+ * ```
+ * pid=19236 state=S syscall=1(write) args=0x2,…,0x244 wchan=sock_alloc_send_pskb
+ *     tid=19236 (node) syscall=1(write)      ← the MAIN thread
+ * ```
+ *
+ * With the loop parked in the kernel there is no late timer to catch up: the
+ * no-progress bound is not slow, it is UNREACHABLE, and no ceiling of any size
+ * distinguishes that from a wait. The process ends only when someone reads the
+ * pipe or kills it. That is the hang.
+ *
+ * ⚠️ Nothing in the spawn is ours. The service is esbuild's, spawned by `tsx`
+ * when it has to transform a module, which is why this reproduces on a COLD
+ * transform cache (a fresh CI checkout) and almost never on a warm developer
+ * box: measured 27 of 30 cold against 1 of 90 warm.
+ *
+ * ## Why the re-assert is on the WRITE path and not done once at startup
+ *
+ * Because the clearing happens at 1132 ms and is caused by a spawn this process
+ * does not control or even know about. A one-shot at module top is undone by
+ * the next `spawn(…, { stdio: 'inherit' })` anywhere in the process — including
+ * from a module-hooks worker thread, which shares the same descriptions — and
+ * it fails SILENTLY, back into the hang it was meant to prevent. Re-asserting
+ * immediately before each write costs one `fcntl` and cannot be outrun by a
+ * later spawn, whoever makes it.
+ *
+ * ## ⛔ This is not the prohibited call, it is its inverse
+ *
+ * `run-dev.js` and `src/utils/format.ts` both refuse
+ * `_handle.setBlocking(TRUE)`, and that refusal stands: forcing blocking writes
+ * process-wide is what stalls `os serve` / `os dev` on its own logs. This
+ * function forces the other direction — it is the thing that KEEPS those two
+ * docblocks true when something else has quietly flipped the flag.
+ *
+ * ⛔ It does not touch a TTY. A terminal is written synchronously on POSIX by
+ * design, has no unread-reader failure mode (the reader is a human's terminal),
+ * and prompt-adjacent output would change behaviour for no benefit.
+ */
+
+/** Marks the stream so a second install cannot stack wrappers. */
+const INSTALLED = Symbol.for('objectstack.stderr-nonblocking');
+
+/**
+ * @param {NodeJS.WriteStream} [stream] The stream to guard; defaults to
+ *   `process.stderr`. Parameterised for the pin, which drives the guard against
+ *   a manufactured blocking pipe rather than waiting for a cold cache.
+ * @returns {boolean} `true` when this process's writes are now guarded,
+ *   `false` when there was nothing to guard (a TTY, a file, a stream with no
+ *   libuv handle). The boolean is returned rather than logged: a reporter that
+ *   announces itself on the very stream it is repairing is the one thing this
+ *   file must not do.
+ */
+export function keepStderrNonBlocking(stream = process.stderr) {
+  if (!stream || stream.isTTY === true) return false;
+  const handle = stream._handle;
+  if (!handle || typeof handle.setBlocking !== 'function') return false;
+  if (stream[INSTALLED]) return true;
+
+  const write = stream.write;
+  if (typeof write !== 'function') return false;
+
+  stream[INSTALLED] = true;
+  stream.write = function guardedWrite(...args) {
+    // One `fcntl`, immediately ahead of the syscall that would otherwise park
+    // this thread. Wrapped because a stream that lost its handle mid-run must
+    // still take the write — a repair that throws is worse than the defect.
+    try {
+      handle.setBlocking(false);
+    } catch {
+      // Nothing to say and nowhere safe to say it.
+    }
+    return write.apply(this, args);
+  };
+  return true;
+}

packages/cli/test/fixtures/stderr-nonblocking-probe.mjs

@@ -0,0 +1,107 @@
+// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
+
+/**
+ * The hazard `bin/stderr-nonblocking.mjs` exists for, MANUFACTURED rather than
+ * waited for — driven by `run-dev-stderr-nonblocking.e2e.test.ts`.
+ *
+ * ⚠️ The reason this fixture exists at all is that the real occurrence is
+ * INTERMITTENT: over the real CLI it reproduced 27 of 30 runs on a cold `tsx`
+ * transform cache and 1 of 90 on a warm one. A pin that drove the real child
+ * would therefore be green most of the time on a developer box while the defect
+ * was fully present — a test that only fails intermittently is not a pin. So
+ * this fixture reproduces the CONDITION deterministically and in ~200 ms:
+ *
+ *   1. materialise `process.stderr`, which is when node opens the pipe and sets
+ *      `O_NONBLOCK` on it — the state every healthy run starts in;
+ *   2. spawn a trivial child with INHERITED stdio. libuv clears `O_NONBLOCK` on
+ *      fds 0-2 in the child's pre-exec, and inheriting is `dup2`, so the flag —
+ *      which lives on the shared open file description — is cleared for THIS
+ *      process too. In the real defect this spawn is the esbuild service that
+ *      `tsx` starts when it has to transform a module; nothing about the
+ *      mechanism needs it to be esbuild;
+ *   3. write far past every buffer on the path (2 MiB, against ~128 KiB of
+ *      kernel pipe plus the parent's own readable buffer) to a reader that is
+ *      never coming back.
+ *
+ * With the flag cleared, step 3 parks the MAIN THREAD inside `write(2)` and the
+ * event loop stops: no timer, no callback, no bound of any kind can run, and the
+ * process ends only when someone reads the pipe or kills it. With the guard
+ * installed, the same writes queue in userland and the process exits on its own.
+ *
+ * Every step announces itself into a MARKER FILE rather than onto stderr —
+ * stderr is the thing under test and, in the failing arm, the thing that is
+ * blocked. The markers are what let the harness tell "froze at the write" from
+ * "was still booting", so its verdict never rests on wall clock alone.
+ *
+ * argv: `<marker file> guarded|unguarded`
+ */
+
+import { spawnSync } from 'node:child_process';
+import { appendFileSync, readFileSync } from 'node:fs';
+
+import { keepStderrNonBlocking } from '../../bin/stderr-nonblocking.mjs';
+
+const [, , MARKS, ARM] = process.argv;
+const mark = (line) => appendFileSync(MARKS, `${line}\n`);
+
+/**
+ * The flag itself, read from the kernel rather than inferred.
+ *
+ * Linux-only. `unreadable` elsewhere, and the harness treats that as "cannot
+ * confirm" instead of quietly assuming the hazard was armed — the one reading
+ * that would make the control vacuous is `true`, and only that one is refused.
+ */
+function nonBlocking() {
+  try {
+    const flags = /flags:\s*(\d+)/.exec(readFileSync('/proc/self/fdinfo/2', 'utf8'))?.[1];
+    return flags === undefined ? 'unreadable' : String((parseInt(flags, 8) & 0o4000) !== 0);
+  } catch {
+    return 'unreadable';
+  }
+}
+
+// Touching the stream is what materialises it; `writableLength` is the cheapest
+// touch that cannot itself write anything.
+void process.stderr.writableLength;
+mark(`START O_NONBLOCK=${nonBlocking()}`);
+
+spawnSync(process.execPath, ['-e', '0'], { stdio: 'inherit' });
+mark(`HAZARD O_NONBLOCK=${nonBlocking()}`);
+
+if (ARM === 'guarded') mark(`GUARD ${keepStderrNonBlocking()}`);
+
+mark('WRITING');
+const chunk = 'x'.repeat(8 * 1024);
+// ⚠️ 2 MiB, and the size is a MEASUREMENT rather than a round number. A reader
+// that is merely paused is not the only absorber: the kernel pipe holds 64 KiB
+// and node's own readable buffer in the parent holds about another 64 KiB, so
+// ~128 KiB can disappear before the writer ever meets backpressure. 192 KiB was
+// tried first and the unguarded arm reached the end of its loop unblocked on
+// one run in two — a control that green-lights the very hazard it exists to
+// prove. 2 MiB is 16x that headroom, so no absorber on this path can swallow it.
+let backpressured = 0;
+for (let i = 0; i < 256; i++) {
+  if (process.stderr.write(chunk) === false) backpressured += 1;
+  // Progress, so a frozen arm shows WHERE it stopped rather than only that it
+  // never finished — the difference between evidence and an empty timeout.
+  //
+  // ⚠️ Every 4 chunks (32 KiB), not every 32. The block lands around chunk 16 —
+  // one kernel pipe plus one reader-side buffer in — so a coarser interval puts
+  // the FIRST marker after the freeze, and the control then reads "froze before
+  // any write landed" on a perfectly good reproduction. Measured that way.
+  if ((i + 1) % 4 === 0) mark(`WROTE ${(i + 1) * 8} KiB`);
+}
+// ⚠️ `pending` is reported but deliberately NOT the evidence that the bytes
+// were kept. Measured: it reads 0 here even on a perfectly healthy guarded run,
+// because libuv has taken every chunk into its own write queue and
+// `writableLength` only counts what the STREAM still holds above the handle.
+// `bytesWritten` and `destroyed` are the readings that separate "buffered" from
+// "thrown away", so those are what the harness asserts on.
+mark(
+  `WRITES RETURNED pending=${process.stderr.writableLength} bytesWritten=${process.stderr.bytesWritten} ` +
+    `destroyed=${process.stderr.destroyed} backpressured=${backpressured}`,
+);
+
+// A distinctive status, so "exited on its own" is evidence about THIS file
+// rather than about any process that happens to end in 0 or 1.
+process.exit(7);