console: output goes behind what process.stdout/stderr have buffered, as in Node
What
console.* writes to fd 1/2 directly. process.stdout / process.stderr buffer whatever a full pipe or socket refuses and write it later from the event loop. The two do not know about each other, so a console.log issued after a process.stdout.write() can land in the middle of it.
In Node the console writes through the stream, so its output queues behind what the stream already holds. This PR does the same: while a stream's sink is backed up, console output for that stream is appended to the sink's buffer. When nothing is buffered, the console writes as it does today.
const K = 256 * 1024;
process.stdout.write(Buffer.alloc(K, "x")); console.log("\nMARK1");
process.stdout.write(Buffer.alloc(K, "y")); console.log("\nMARK2");
Run as ... | (sleep 0.5; cat), runs of a byte collapsed. Linux x64, debug builds, node v26.7.0:
| output | |
|---|---|
| main | <x*65536> MARK1 <x*65536> MARK2 <x*131072><y*262144> |
| this PR | <x*262144> MARK1 <y*262144> MARK2 |
| node | <x*262144> MARK1 <y*262144> MARK2 |
Same result for process.stderr with console.error, and over a socketpair (Bun.spawn({ stdout: "pipe" })).
How
Processkeeps the twoFileSinkwrappers thatprocess.stdout/process.stderrare built on (m_stdioSinks, visited by GC, so no lifetime code). Until a program touches those streams there is no sink.message_with_type_and_level_asks__bun_stdio_sink_is_backed_up(global, fd)when it picks its writer. If so, the message is formatted into aVecand, on the way out of the function,__bun_stdio_sink_appendadds it to the writer'soutgoingbuffer. The poll that is already armed for the bytes in that buffer writes it after them.- The append makes no syscall, settles nothing and runs no JS, so the sink's state machine, its callbacks and its errors are untouched: the event loop drains and reports exactly as it does on main.
- Formatting can run user code (
inspect.custom), and that code can write until the backlog is gone. Then there is nothing to go behind: the append says so and the message is written directly. - A writer whose poll failed to register is closed with bytes left in its buffer; nothing would ever write an appended message, so it does not count as backed up.
console.log()with no arguments now prints its newline through the writer the function picked, like every other message, instead of always through the stdout writer.- On Windows these sinks are
SyncFile(start_syncinBlob::get_writer): every write blocks until it is out, so they are never backed up.
Behaviour
Every row is either what Node does or exactly what main does. Pipe with a reader that starts late, stalls or leaves:
| main | this PR | node | |
|---|---|---|---|
order of write() and console output | interleaved | call order | call order |
write(big, cb1); console.log(); write("small", cb2) | ret2 false, then nextTick, microtask, immediate, timeout, drain, cb1, drain, cb2 | same as main | as main with one drain |
write(big); console.log(); write(big, () => process.exit(0)) | wrong order | every byte, in order | every byte, in order |
| unref'd timer due while the backlog drains | fires | fires | fires |
a signal listener against 'drain' and the callback | signal, drain, cb | same | same |
reader gone, no listener / 'error' listener | cb1 EPIPE, (error,) cb2 EPIPE | same as main | cb1 EPIPE, cb2 EPIPE, (error) |
console.log in 'beforeExit' / 'exit' listeners with a backlog | no callback runs inside it | same as main | same |
write(1 MiB); console.log("LAST"); process.exit() | truncated, LAST in the middle | truncated, LAST lost | truncated, LAST lost |
console.error() / console.warn() with no arguments | newline on stdout | newline on stderr | newline on stderr |
- The last-but-one row is the one place where a program prints less than on main: console output behind a backlog is no longer out when
console.logreturns, soprocess.exit()or a crash right after it drops it, as in Node. - With a
'SIGPIPE'listener and the reader gone, the listener runs 4 times on main, once here, never in node: the console no longer writes into the broken pipe itself. - Also the same output as main: a failing poll registration inside
write()(injectedepoll_ctlerror; the console message is still printed), a one-off injectedEPIPEon a sink write,finished(process.stdout), a worker'sconsole.logwhile the main thread has a backlog, stdout to a file and to a tty. - By method, with a backlog on the fd the method prints to:
log,info,debug,dir,table,group,trace,warn,error,assert(false, msg)go behind it.count,time*andassert(false)without a message print through other paths and jump ahead, as on main.traceprints on stdout, as on main. - Syscall counts for 1000
console.log, with and withoutprocess.stdouttouched, to a pipe, a file and/dev/null: identical to main. Bun.stdout.writer(),Bun.file(1|2).writer(),Bun.write(Bun.stdout)andconsole.writehave their own sinks, as on main.
Tests
test/js/node/process/process-stdio.test.ts, five tests next to #43868's, using its gated reader (nothing reads the fd until the first write() has returned false, no sleeps). The pipeline tests also assert the writer's own exit status and that it printed nothing else:
log/info/debug/log()on a stdout pipe;warn/error/error()on a stderr pipe; stdout on a socketpair. Fail on main with the interleaving above.write(big); console.log(); write(big, () => process.exit(0))delivers every byte in order. Fails on main.- A message whose
inspect.customwrites until the backlog is gone is still printed. Passes on main; it covers the direct write when there is nothing left to go behind.
test/js/web/console/console-log.test.ts: console.error() and console.warn() with no arguments print their newline on stderr. Fails on main.