fix(core): make output.drain() actually flush queued stdout - #36580
fix(core): make output.drain() actually flush queued stdout#36580FrozenPandaz wants to merge 11 commits into
Conversation
✅ Deploy Preview for nx-docs ready!
To edit notification comments on pull requests, go to your Netlify project configuration. |
✅ Deploy Preview for nx-dev ready!
To edit notification comments on pull requests, go to your Netlify project configuration. |
|
View your CI Pipeline Execution ↗ for commit 85b3782
☁️ Nx Cloud last updated this comment at |
602211b to
a50d4f8
Compare
drain() gated on process.stdout.writableNeedDrain, which Node only sets once a single write pushes the queue past the high-water mark. A shorter queue reported false, so drain() resolved immediately and the following process.exit() discarded up to 64KB of already-written output. Wait on a zero-length write callback instead, which fires only after every queued chunk has reached the fd, and treat a vanished reader as drained so EPIPE cannot fail an otherwise successful run.
These share the exit shape affected.ts has: runCommand resolves, then process.exit(status) preempts the flush. nx run-many -t test | tee and nx test <project> | tee truncate their task output the same way. nx affected is covered separately by #36569.
These stood in for a flush that drain() did not actually perform, and carried a 'TODO: Find a better fix for this'. Now that drain() waits for the write queue to empty, an extra event-loop tick adds nothing.
The listener was never detached, so after one drain() every later stdout
error was silently swallowed for the rest of the process — an unrelated
ENOSPC exited 0 where it previously crashed with a diagnostic. Detach it
once the write settles; the removal is deferred because the write callback
runs before the 'error' event.
The comment justifying `on` over `once` described a mechanism that cannot
occur: a write callback never consumes a once('error') registration. The
real hazard is removing the listener from a callback shared with write(),
which is now what the comment names.
The spec's EPIPE case hand-emitted 'error', which that hazardous refactor
passed cleanly. It now drives the error through Node's real ordering and
kills the mutant, plus asserts no listener survives.
Also drains the five sibling release handlers that exit on a status.
The deferred cleanup re-read process.stdout a macrotask later, so a caller that swapped the stream in between left the listener attached to the old one while removeListener no-oped on the new. Capture the stream once. The EPIPE test also passed on code that crashes on a real pipe: its only assertion was that the promise resolves, which the write callback satisfies on its own. Assert the listener is still attached when 'error' fires, so a listener-removing refactor fails in that test rather than surfacing as an unhandled error attributed to whichever test runs next.
… callback run-command.ts and task-orchestrator.ts replace process.stdout.write with (chunk, encoding, callback) taken positionally. drain() called the two-argument form, so its callback landed in the encoding slot and was never invoked: the promise never resolved. The orchestrator's SIGINT patch is installed when the TUI is off - i.e. when stdio is a pipe, exactly when the queue is non-empty - and is never restored, so Ctrl-C on a piped nx run-many wedged instead of exiting. Base was immune because 'drain' fires from the stream's own queue. Also names setImmediate in the comment: 'next tick' reads as process.nextTick, which drains before the 'error' emit and re-introduces the crash the sentence warns about. Adds tests for both, plus a nextTick guard for the deferral itself.
… writers All three patches replaced process.stdout.write with a function reading (chunk, encoding, callback) positionally, so the equally valid write(chunk, cb) form left the callback stranded and never invoked it. drain() now passes the encoding explicitly, but any other caller awaiting the callback hit the same hang, and createPatchedLogWrite additionally passed a function to chunk.toString() as the encoding. Normalize the callback out of whichever slot it arrives in.
…ed parameter The comment justifying drain()'s explicit encoding described the three stdout patches as positional, which the previous commit made false - it pointed a reader at two files that now contradict it. State the durable reason instead: any non-normalizing positional patch, third-party ones included, drops a two-argument write's callback. Names the parameter encodingOrCallback, matching the existing precedent in tui-summary-life-cycle.spec.ts, so the shadowing is self-documenting.
…tional test The SIGINT silencer had no test at all, so the callback normalization on the one patch that is never restored was verified only by replaying extracted bytes. Drive it through setupSignalHandlers with the constructor bypass the suite already uses; it fails against the pre-fix shape. The positional-patch test asserted only that drain resolves, which an early return also satisfies. Count the writes so it cannot pass without reaching the patched writer, and bound its timeout so a regression fails in 5s rather than 35.
…e check The five as-any/ts-ignore suppressions at these sites were hiding the exact defect this PR fixes: with them removed tsc reports 'Target signature provides too few arguments. Expected 3 or more, but got 2' - the stranded-callback bug, stated by the compiler. Adopt the signature already used in tui-summary-life-cycle.spec.ts so a fourth patch site, or a revert of one of these, fails the build instead of hanging at runtime. Also uses Buffer.isEncoding for the decode, which additionally rejects the 'buffer', '' and null values toString() cannot take, and drops the dead originalWrite/isError parameters whose two branches were byte-identical.
ArrayBuffer.isView covers the Uint8Array chunks Buffer.isBuffer missed, which
reached logDebug and the TUI cloud message as a byte list ('104,101,108,...')
rather than text.
nx run <project>:<target> --help printed and exited without draining, the same
truncation the rest of this PR fixes at an exit site the earlier sweep missed.
Passes null to the write callbacks: Node's console handler branches on
err !== null, so a bare cb() nominally signals failure.
Records on drain() that it cannot flush through a replaced process.stdout.write,
which the SIGINT silencer does deliberately.
f551f35 to
85b3782
Compare
There was a problem hiding this comment.
Nx Cloud has identified a possible root cause for your failed CI:
We reviewed the 86 @nx/dependency-checks lint errors and found they all point at packages declared in packages/nx/package.json that have no corresponding imports — none of which are touched by this PR's diff. Because the failure is unrelated to the stdout-drain changes and does not appear on master, we classify this as a pre-existing environment/configuration drift rather than a regression introduced by this PR.
No code changes were suggested for this issue.
Trigger a rerun:
🔔 Heads up, your workspace has pending recommendations ↗ to auto-apply fixes for similar failures.
🎓 Learn more about Self-Healing CI on nx.dev
Current Behavior
output.drain()doesn't reliably flush. It gates entirely onprocess.stdout.writableNeedDrain:Node only sets that flag when a single
write()pushes the queue past the high-water mark (65,536for a pipe), and only clears it by emitting
'drain'. A queue shorter than the mark reportsfalse,so
drain()resolves in 0 ms and the followingprocess.exit()discards everything still queued.That's the normal state, not a corner case.
output.logCommandOutput()emits five separateprocess.stdout.write()calls per task (newlines, the status header, the body, plusGH_GROUP_SUFFIXunderGITHUB_ACTIONS). Once the reader is slower than Nx the OS pipe fills and thenext chunk queues — and if that chunk is under 64 KB the flag never sets.
Measured, two writes into a stalled pipe with a drain in place:
Byte-identical to not draining at all. The band that gets dropped is the trailing output — the
::endgroup::marker and the failure summary that land after a large task body, which is the partthat matters most in a failing CI log.
Two call sites already worked around this with an extra event-loop tick and a
// TODO: Find a better fix for this(show/projects.ts,show/project.ts). Measured, thatworkaround doesn't close the gap either.
Separately, three commands that exit on a task status never drained at all:
affected/affected.tsrun-many/run-many.tsrun/run-one.tsrelease/command-object.tsSo
nx run-many -t e2e | teeandnx test <project> | teetruncate exactly the waynx affecteddid.
Expected Behavior
output.drain()waits until the write queue is actually empty, using the callback of a zero-lengthwrite — which fires only after every previously queued chunk has reached the fd. A vanished reader is
treated as drained, so
EPIPEfromnx ... | headcan't fail an otherwise successful run.Measured with this change:
> fileTwo variants that look right and are not, both tested and rejected:
writableLengthand re-arming on'drain'delivers the bytes but exits 0 instead of thetask status — Node emits
'drain'only whenneedDrainwas set, so in exactly the broken casethe promise never settles and the process exits naturally, silently destroying the exit code.
once('error', done)plusremoveListenerinsidedonestill crashes: the write callback fireswith the error first and removes the listener before
'error'is emitted. Henceon(...).The change is in three separable commits:
fix(core): make output.drain() flush queued stdout— the fix itself, pluspackages/nx/src/utils/output.spec.ts. The regression test fails against the old implementation(verified by reverting) and drives the real shipped
drain()against genuine stream backpressurerather than a copy.
fix(core): drain stdout before exiting run-many, run and release publish— adds the missingawait output.drain()at the three remaining status exits.nx affectedis left alone; fix(core): drain to stdout before exitingnx affected#36569covers it, so these don't conflict.
cleanup(core): drop setImmediate workarounds around output.drain()— retires both TODOs andthe third
setImmediate-as-flush ingraph.ts, now thatdrain()does the job.Note this is what makes #36569 effective: that PR puts
await output.drain()on thenx affectedpath, but until
drain()itself flushes, it still drops the trailing ≤64 KB.Not included, worth a follow-up:
drain()only inspectsprocess.stdout, andoutput.error/output.warnwrite to stderr — so thecatchblocks thatprintError(e)thenprocess.exit(1)still truncate under
2>&1 | tee. That needs astreamparameter ondrain()and is a separatechange.
Related Issue(s)
Fixes #36568
Follows up #36569.