Skip to content

Commit 1727827

Browse files
docs(cli): name the writer that actually made the first failing stderr write
`bin/run-dev.js` explained #14858's crash with "oclif's `displayWarnings()` makes the first write". Re-traced with a `--import` observer that wraps `process.stderr.write` and logs the call site of the first EPIPE-ing call: node's OWN default `warning` handler (`internal/process/warning.js`: `onWarning` -> `writeOut` -> `console.error`) makes write #1, and `displayWarnings()` makes writes #2 and #3 of the same warning. Every write on that path is a `console.error`, and the reason that is fatal here while `bin/run.js` measured it harmless is not payload size. Console's `ignoreErrors` keep-alive is installed by the write CALLBACK and only `if (stream.listenerCount('error') === 0)`. `tsx` registers an off-thread module-customization hook, so node pipes the hooks worker's stderr into `process.stderr` and `Stream.prototype.pipe` prepends an `onerror` there; the count is 1, the keep-alive never installs, `onerror` takes the first EPIPE and re-emits it with nothing listening. Controls, node 22.22.2, read end destroyed, one variable between the legs: `console.error` alone 0/3, `module.register()` of a no-op hook plus the same `console.error` 3/3, raw `process.stderr.write` 3/3. The shim as shipped is 0/3 (exit 2); with the #14858 listener ablated it is 3/3 (exit 1). Comment text only. No behaviour changes, the listener stays exactly as it is, and the three `displayWarnings()` sites that state listener TIMING rather than authorship are untouched. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_015QE8qk46e5CHJxyQEUjbf8
1 parent fcddd15 commit 1727827

4 files changed

Lines changed: 78 additions & 22 deletions

File tree

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,14 @@
1+
---
2+
"@objectstack/cli": patch
3+
---
4+
5+
`bin/run.js` no longer states Node's `console.error` protection as an unconditional fact — it is conditional, and the condition is a property of the process's listener census rather than of `console.error`.
6+
7+
The docblock over that file's `process.stderr` `error` listener explained the last row of its measurement table with "`ignoreErrors` … parks a temporary `error` listener across the write — so oclif's warning blocks cannot crash this process at any size". Both halves needed correcting, and only the second one was visible:
8+
9+
- The listener parked *across* the write is not what saves anything. `kWriteToConsole`'s `finally` removes it before the completion arrives. What keeps the process alive is Console's write CALLBACK re-attaching a `noop`, and it does that only `if (stream.listenerCount('error') === 0)`.
10+
- That count is 0 on this entry point and is not universal. `bin/run-dev.js` runs under `tsx`, which registers an off-thread module-customization hook; node pipes that worker's stderr into `process.stderr` and `Stream.prototype.pipe` prepends its own `onerror` there. With the count at 1 the keep-alive is never installed, `onerror` takes the first EPIPE and re-emits it with nothing listening, and **one short `console.error` crashes the process 3/3** — no payload size involved.
11+
12+
Measured on node 22.22.2 against a destroyed read end, one variable changed between the legs: `console.error` alone 0/3, `module.register()` of a no-op hook plus the same `console.error` 3/3, a raw `process.stderr.write` 3/3.
13+
14+
Comment text only. No behaviour, no accepted arguments, no exported member and no runtime contract changes; the listener itself, its name and the pin that waits for it are untouched. It publishes because npm packs a `bin` target regardless of `files[]` (#14874) — measured: the tarball ships `bin/run.js` verbatim and the corrected prose is in it — which is why this is a `patch` rather than a `skip-changeset`.

‎packages/cli/bin/run-dev.js‎

Lines changed: 41 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -63,11 +63,15 @@ const STDERR_DRAIN_POLL_MS = 50;
6363
* asynchronously and `process.exit` tears the process down with the buffer only
6464
* partly drained; `src/utils/format.ts` carries the whole argument for stdout
6565
* (`emitJson`). One thing makes it worse here: `settings.debug` is on, so
66-
* oclif's `displayWarnings()` has already queued ~138 KB of `ModuleLoadError`
67-
* blocks AHEAD of these lines. Measured on the #12964 repro with a reader that
68-
* was not draining: the pipe delivered exactly one 64 KiB buffer and everything
69-
* after it was lost — this diagnostic AND oclif's own `command … not found`,
70-
* which `handle()` writes a moment later and which the same tear-down takes.
66+
* ~143 KB of `ModuleLoadError` blocks is already queued AHEAD of these lines —
67+
* three quarters of it from oclif's `displayWarnings()` and the rest from node's
68+
* OWN default `warning` handler, which stays attached and prints every warning
69+
* as well (#16691, drained run: 147 729 bytes over 179 writes, 111 751 of them
70+
* from `config.js`, 35 133 from `internal/process/warning.js`). Measured on the
71+
* #12964 repro with a reader that was not draining: the pipe delivered exactly
72+
* one 64 KiB buffer and everything after it was lost — this diagnostic AND
73+
* oclif's own `command … not found`, which `handle()` writes a moment later and
74+
* which the same tear-down takes.
7175
* That is why the merge queue saw it and a developer's terminal never does: a
7276
* TTY is written synchronously, a captured pipe is not.
7377
*
@@ -374,15 +378,18 @@ if (!process.env.TSX_TSCONFIG_PATH) {
374378
*
375379
* `process.stderr` is an `EventEmitter`, and an `error` event with nothing
376380
* listening IS an uncaught exception. With the parent's read end DESTROYED
377-
* (`stdio: ['ignore', 'ignore', 'pipe']`, then `child.stderr.destroy()`)
378-
* oclif's `displayWarnings()` makes the first write, the pipe is already gone,
379-
* node raises `write EPIPE` on `process.stderr`, and this process died of an
380-
* uncaught exception — 12 of 12 runs, 938-1174 ms in, well before `run()`
381-
* settles and before `writeStderr()` above is ever called. Traced with a
382-
* `--import` observer that installs NO listener on this stream and wraps no
383-
* write (`uncaughtExceptionMonitor`, which observes without preventing the
384-
* default crash — an `uncaughtException` handler would have changed the very
385-
* thing being read):
381+
* (`stdio: ['ignore', 'ignore', 'pipe']`, then `child.stderr.destroy()`) the
382+
* first write comes from node's OWN default `warning` handler
383+
* (`internal/process/warning.js`: `onWarning` → `writeOut` → `console.error`),
384+
* and oclif's `displayWarnings()` makes writes 2 and 3 of the same warning
385+
* (#16691 re-traced the order; #15558 named `displayWarnings()` for the first
386+
* one). The pipe is already gone, node raises `write EPIPE` on
387+
* `process.stderr`, and this process died of an uncaught exception — 12 of 12
388+
* runs, 938-1174 ms in, well before `run()` settles and before `writeStderr()`
389+
* above is ever called. Traced with a `--import` observer that installs NO
390+
* listener on this stream and wraps no write (`uncaughtExceptionMonitor`, which
391+
* observes without preventing the default crash — an `uncaughtException` handler
392+
* would have changed the very thing being read):
386393
*
387394
* uncaughtException code=EPIPE msg=write EPIPE
388395
* at afterWriteDispatched (node:internal/stream_base_commons:159:15)
@@ -395,6 +402,26 @@ if (!process.env.TSX_TSCONFIG_PATH) {
395402
* tell "the command failed" from "the CLI crashed", on the only channel it had
396403
* left.
397404
*
405+
* ⚠️ EVERY write on that path is a `console.error`, which is worth stating
406+
* because it reads as if it should be survivable — `bin/run.js` records that
407+
* Console's `ignoreErrors` keeps a warning block from crashing a process, and
408+
* THERE it does. What saves a process is not the temporary listener
409+
* `kWriteToConsole` parks across the write (its `finally` removes that one
410+
* before the completion arrives) but Console's write CALLBACK, which re-attaches
411+
* a `noop` when the completion reports an error — and only
412+
* `if (stream.listenerCount('error') === 0)`. Under `tsx` that count is never 0:
413+
* tsx registers an off-thread module-customization hook, so node pipes the hooks
414+
* worker's stderr into `process.stderr` and `Stream.prototype.pipe` prepends its
415+
* own `onerror` there (`node:internal/streams/legacy`). Console's keep-alive is
416+
* therefore never installed; `onerror` takes the first EPIPE, tears the pipe's
417+
* own listeners down including itself, finds no other `error` listener left and
418+
* RE-EMITS on `process.stderr` — that second emit is the uncaught one.
419+
* Ablated on plain node, one short line and nothing else changed: `console.error`
420+
* alone 0/3, `module.register()` of a no-op hook plus the SAME `console.error`
421+
* 3/3, a raw `process.stderr.write` 3/3 (#16691). ⇒ Payload size decides nothing
422+
* here, and this listener is what covers the `console.error` sites too, not only
423+
* `writeStderr()` above.
424+
*
398425
* ⛔ Deliberately NOT narrowed to `error.code === 'EPIPE'`, even though EPIPE is
399426
* the only code this path was measured to raise (4 events per run, no other
400427
* code, observed with a listener installed on purpose for that one question).

‎packages/cli/bin/run.js‎

Lines changed: 15 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -102,10 +102,21 @@ try {
102102
* at one write 1 ms before exit, and at 59 warning blocks whose EPIPE
103103
* arrives synchronously inside the write.
104104
* • a RAW `process.stderr.write`. Node's `console.error` carries
105-
* `ignoreErrors`, which parks a temporary `error` listener across the write
106-
* — so oclif's warning blocks cannot crash this process at any size
107-
* (measured: 1 MiB through `console.error` does not, one line through
108-
* `process.stderr.write` does, 3/3 each).
105+
* `ignoreErrors`: its write CALLBACK re-attaches a `noop` `error` listener
106+
* when the completion reports one — so oclif's warning blocks cannot crash
107+
* this process at any size (measured: 1 MiB through `console.error` does
108+
* not, one line through `process.stderr.write` does, 3/3 each).
109+
*
110+
* ⚠️ That protection is CONDITIONAL, and the condition is a fact about THIS
111+
* process rather than about `console.error`: the callback re-attaches only
112+
* `if (stream.listenerCount('error') === 0)`. Here nothing else ever listens
113+
* — measured, the only `error` listener on `process.stderr` for a whole run
114+
* is this file's own, below. `bin/run-dev.js` runs under `tsx`, which
115+
* registers an off-thread module-customization hook; node pipes that
116+
* worker's stderr into `process.stderr`, `Stream.prototype.pipe` prepends an
117+
* `onerror` there, the count is 1, the keep-alive is never installed, and
118+
* ONE SHORT `console.error` crashes 3/3 (#16691). ⛔ So "a `console.error`
119+
* site needs no guard" is never a general reading of this paragraph.
109120
*
110121
* `os serve` is both: `printDiagnostic` in `src/commands/serve.ts` writes
111122
* straight to stderr (#7915) and the boot around it is asynchronous, so the

‎packages/cli/test/run-dev-unbuilt-workspace.e2e.test.ts‎

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -461,10 +461,14 @@ describe('the mirror direction: a reader that is never coming back', () => {
461461
// anyone contracted — and #14858 is the card that changed the CLI. ⛔ This
462462
// was not a broken test and the flip is not a regression.
463463
//
464-
// What the child USED TO DO with its read end destroyed: oclif's
465-
// `displayWarnings()` makes the first stderr write, the pipe is already
466-
// gone, node raises `write EPIPE` as an `error` event on `process.stderr`,
467-
// NOTHING WAS LISTENING, and the process died of an uncaught exception —
464+
// What the child USED TO DO with its read end destroyed: node's OWN default
465+
// `warning` handler makes the first stderr write and oclif's
466+
// `displayWarnings()` the next two (#16691 re-traced the order — and every
467+
// write on this path is a `console.error`, which is NOT the guard here that
468+
// it is on `bin/run.js`; the docblock over the listener in `bin/run-dev.js`
469+
// carries why). The pipe is already gone, node raises `write EPIPE` as an
470+
// `error` event on `process.stderr`, NOTHING WAS LISTENING, and the process
471+
// died of an uncaught exception —
468472
// exit 1, 938-1174 ms in, 12 of 12 runs, traced with a `--import` observer
469473
// that installed no listener here and wrapped no write. `writeStderr()` was
470474
// never called at all, so the bound this case was once named after was

0 commit comments

Comments
 (0)