diff --git a/docs/guides/write-file/stdout.mdx b/docs/guides/write-file/stdout.mdx index 64937c9188c5..1394b28b4130 100644 --- a/docs/guides/write-file/stdout.mdx +++ b/docs/guides/write-file/stdout.mdx @@ -18,6 +18,21 @@ Bun also exposes `stdout` as a `BunFile` with the `Bun.stdout` property. Pass it await Bun.write(Bun.stdout, "Lorem ipsum"); ``` +For many small writes, `Bun.stdout.writer()` returns a buffered `FileSink` over the same destination. + +```ts +const writer = Bun.stdout.writer(); +writer.write("Lorem "); +writer.write("ipsum\n"); +writer.flush(); +``` + +--- + +`console.log`, `process.stdout.write()`, `Bun.write(Bun.stdout, ...)`, `Bun.stdout.writer()` and `console.write()` all end at one output queue per thread, so bytes each of them has handed over come out in call order, however slowly the other end of a pipe reads. As in Node.js, `console.log` is a `write()` on `process.stdout` from the point of view of anything that replaces or wraps `process.stdout.write` — so it also respects `process.stdout.cork()` and waits behind chunks `process.stdout` is still buffering. `Bun.write(Bun.stdout, ...)` and `Bun.stdout.writer()` write to the queue directly and are not held back by `process.stdout`'s stream-level state. + +When the program exits — including through `process.exit()` or an uncaught exception — everything already written to `process.stdout` and `process.stderr` is flushed to the operating system first. (Node.js can truncate pending output to a slow pipe on `process.exit()`; Bun waits for it.) + --- See [`Bun.write()`](/runtime/file-io#writing-files-bun-write). diff --git a/src/bun_core/output.rs b/src/bun_core/output.rs index 3274e5c074cb..6b44e266cf6d 100644 --- a/src/bun_core/output.rs +++ b/src/bun_core/output.rs @@ -454,6 +454,19 @@ impl Source { Self::get_force_color_depth().unwrap_or(ColorDepth::None) != ColorDepth::None } + /// What `FORCE_COLOR` / `NO_COLOR` alone say (the part of the colour + /// decision that doesn't depend on which stream is being written to), for + /// callers colouring output bound for a stream other than fd 1/2. + pub fn env_color_override() -> Option { + if Self::get_force_color_depth().is_some() { + Some(Self::is_force_color()) + } else if Self::is_no_color() { + Some(false) + } else { + None + } + } + pub(crate) fn is_color_terminal() -> bool { #[cfg(windows)] { @@ -2318,6 +2331,12 @@ pub fn print_errorln(args: impl core::fmt::Display) { print_to(Destination::Stderr, format_args!("{args}\n")); } +/// See [`Source::env_color_override`]. +#[inline] +pub fn env_color_override() -> Option { + Source::env_color_override() +} + /// `Output.enable_ansi_colors_stdout` — safe relaxed-load wrapper over the /// startup-initialized atomic. #[inline] @@ -2503,6 +2522,12 @@ impl ErrName for crate::CrateError { // ── ScopedDebugWriter ───────────────────────────────────────────────────── +/// True while this thread is inside a `scoped_log!` write (debug builds). +#[inline] +pub fn is_inside_scoped_log() -> bool { + crate::env::IS_DEBUG && scoped_debug_writer::DISABLE_INSIDE_LOG.get() > 0 +} + pub mod scoped_debug_writer { use super::*; diff --git a/src/codegen/generate-jssink.ts b/src/codegen/generate-jssink.ts index 5555d32e7e59..1299d70d6c3d 100644 --- a/src/codegen/generate-jssink.ts +++ b/src/codegen/generate-jssink.ts @@ -493,6 +493,7 @@ JSC_DEFINE_HOST_FUNCTION(${controller}__end, (JSC::JSGlobalObject * lexicalGloba } extern "C" JSC::EncodedJSValue ${name}__getInternalFd(void* sinkPtr); +${name === "FileSink" ? `extern "C" bool FileSink__isStdio(void* sinkPtr);` : ""} // TODO: how to make this a property callback. then, we can expose this as a documented field // It should not be shipped as a function call. @@ -532,7 +533,20 @@ JSC_DEFINE_HOST_FUNCTION(${name}__doClose, (JSC::JSGlobalObject * lexicalGlobalO if (ptr == nullptr) { return JSC::JSValue::encode(JSC::jsUndefined()); } - +${ + name === "FileSink" + ? ` + // The per-thread stdio sink is shared (process.stdout, Bun.stdout.writer(), + // console.*): closing one handle to it flushes, it does not take the + // wrapper away from the others. + if (FileSink__isStdio(ptr)) { + FileSink__close(lexicalGlobalObject, ptr); + RETURN_IF_EXCEPTION(scope, {}); + return JSC::JSValue::encode(JSC::jsUndefined()); + } +` + : "" +} sink->detach(); ${name}__close(lexicalGlobalObject, ptr); // detach() nulled m_sinkPtr so ~${className} won't finalize ptr; do the diff --git a/src/io/PipeWriter.rs b/src/io/PipeWriter.rs index 69ec758b42d8..5c3acbf66b4f 100644 --- a/src/io/PipeWriter.rs +++ b/src/io/PipeWriter.rs @@ -73,9 +73,11 @@ pub trait PosixPipeWriter { FileType::File }; match ft { - FileType::NonblockingPipe | FileType::File => { - self.try_write_with_write_fn(buf, sys::write) - } + FileType::NonblockingPipe => self.try_write_with_write_fn(buf, sys::write), + // No poll backs this fd, so an `EAGAIN` (someone else made the + // description non-blocking) could never be resumed; behave as the + // blocking fd we asked for. + FileType::File => self.try_write_with_write_fn(buf, sys::write_retrying), FileType::Pipe => self.try_write_with_write_fn(buf, write_to_blocking_pipe), FileType::Socket => self.try_write_with_write_fn(buf, sys::send_non_block), } @@ -600,6 +602,12 @@ pub struct PosixStreamingWriter { pub is_done: bool, pub(crate) closed_without_reporting: bool, pub force_sync: bool, + /// Sub-`CHUNK_SIZE` writes are coalesced and normally also arm the poll, + /// so the next writable event flushes them. An owner that flushes at end + /// of tick itself (FileSink's `AutoFlusher` on the stdio sink, whose poll + /// is deliberately unregistered while idle) turns this off to save the + /// registration syscall per buffered write. + pub poll_flushes_buffer: bool, /// Last reported `WriteStatus == Pending` (i.e. write(2) returned EAGAIN). backed_up: core::cell::Cell, } @@ -613,6 +621,7 @@ impl Default for PosixStreamingWriter PosixStreamingWriter { self.parent } + /// [`parent`](Self::parent), for the poll dispatcher. + #[inline] + pub fn parent_ptr(&self) -> *mut Parent { + self.parent() + } + /// Single nonnull-asref dispatch for the set-once `parent` backref. /// /// Type invariant (encapsulated `unsafe`): `self.parent` is populated by @@ -697,7 +712,7 @@ impl PosixStreamingWriter { self.handle.get_poll() } - pub(crate) fn get_fd(&self) -> Fd { + pub fn get_fd(&self) -> Fd { self.handle.get_fd() } @@ -742,6 +757,16 @@ impl PosixStreamingWriter { self.close(); } + /// A write the parent issued on this writer's fd itself (bypassing + /// `write()`) failed terminally; tear down exactly as if `write()` had hit + /// the error. + pub fn fail(&mut self, err: sys::Error) { + if self.is_done || self.closed_without_reporting { + return; + } + self._on_error(err); + } + fn _on_write(&mut self, written: usize, status: WriteStatus) { self.outgoing.wrote(written); @@ -800,6 +825,15 @@ impl PosixStreamingWriter { } pub fn write_utf16(&mut self, buf: &[u16]) -> WriteResult { + self.write_utf16_impl(buf, true) + } + + /// See [`write_now`](Self::write_now). + pub fn write_utf16_now(&mut self, buf: &[u16]) -> WriteResult { + self.write_utf16_impl(buf, false) + } + + fn write_utf16_impl(&mut self, buf: &[u16], may_buffer: bool) -> WriteResult { if self.is_done || self.closed_without_reporting { return WriteResult::Done(0); } @@ -812,16 +846,25 @@ impl PosixStreamingWriter { let buf_len = self.outgoing.size() - before_len; - self.maybe_write_newly_buffered_data(buf_len) + self.maybe_write_newly_buffered_data(buf_len, may_buffer) } pub fn write_latin1(&mut self, buf: &[u8]) -> WriteResult { + self.write_latin1_impl(buf, true) + } + + /// See [`write_now`](Self::write_now). + pub fn write_latin1_now(&mut self, buf: &[u8]) -> WriteResult { + self.write_latin1_impl(buf, false) + } + + fn write_latin1_impl(&mut self, buf: &[u8], may_buffer: bool) -> WriteResult { if self.is_done || self.closed_without_reporting { return WriteResult::Done(0); } if bun_core::strings::is_all_ascii(buf) { - return self.write(buf); + return self.write_impl(buf, may_buffer); } let before_len = self.outgoing.size(); @@ -833,15 +876,17 @@ impl PosixStreamingWriter { let buf_len = self.outgoing.size() - before_len; - self.maybe_write_newly_buffered_data(buf_len) + self.maybe_write_newly_buffered_data(buf_len, may_buffer) } - fn maybe_write_newly_buffered_data(&mut self, buf_len: usize) -> WriteResult { + fn maybe_write_newly_buffered_data(&mut self, buf_len: usize, may_buffer: bool) -> WriteResult { debug_assert!(!self.is_done); - if self.should_buffer(0) { + if may_buffer && self.should_buffer(0) { self.parent_on_write(buf_len, WriteStatus::Drained); - Self::register_poll(self); + if self.poll_flushes_buffer { + Self::register_poll(self); + } return WriteResult::Wrote(buf_len); } @@ -889,11 +934,22 @@ impl PosixStreamingWriter { } pub fn write(&mut self, buf: &[u8]) -> WriteResult { + self.write_impl(buf, true) + } + + /// `write` that never coalesces: the syscall is attempted now (anything + /// already queued goes first), the remainder queued on EAGAIN / short + /// write. What a stream's `_write` wants, as opposed to a batching writer. + pub fn write_now(&mut self, buf: &[u8]) -> WriteResult { + self.write_impl(buf, false) + } + + fn write_impl(&mut self, buf: &[u8], may_buffer: bool) -> WriteResult { if self.is_done || self.closed_without_reporting { return WriteResult::Done(0); } - if self.should_buffer(buf.len()) { + if may_buffer && self.should_buffer(buf.len()) { // this is streaming, but we buffer the data below `chunk_size` to // reduce the number of writes if self.outgoing.write(buf).is_err() { @@ -903,7 +959,9 @@ impl PosixStreamingWriter { // noop, but need this to have a chance // to register deferred tasks (onAutoFlush) self.parent_on_write(buf.len(), WriteStatus::Drained); - Self::register_poll(self); + if self.poll_flushes_buffer { + Self::register_poll(self); + } // it's buffered, but should be reported as written to // callers @@ -977,6 +1035,9 @@ impl PosixStreamingWriter { self.outgoing.wrote(written); if self.outgoing.is_empty() { self.outgoing.reset(); + } else { + // Backed up: the writable event is what drains the rest. + Self::register_poll(self); } } WriteResult::Wrote(written) => { @@ -1048,21 +1109,9 @@ impl PosixStreamingWriter { return sys::Result::Ok(()); } + let poll = self.ensure_poll(fd); // SAFETY: parent BACKREF set via set_parent; outlives this writer. let loop_ = unsafe { Parent::event_loop(self.parent()) }; - let poll = match self.get_poll() { - Some(p) => p, - None => { - let p = FilePollRef::init( - loop_, - fd, - Owner::new(Parent::POLL_OWNER_TAG, std::ptr::from_mut(self).cast()), - ); - self.handle = PollOrFd::Poll(p); - p - } - }; - match poll.register_with_fd(loop_.loop_(), FilePollKind::Writable, fd) { sys::Result::Err(err) => { return sys::Result::Err(err); @@ -1072,6 +1121,47 @@ impl PosixStreamingWriter { sys::Result::Ok(()) } + + /// `start` without registering the poll with the loop: the `FilePoll` + /// exists (so `FileType` and keep-alive work) but the kernel isn't asked + /// for writability until the first backpressure (`register_poll`). For a + /// long-lived writer whose fd is rarely full — an idle `EVFILT_WRITE` / + /// `EPOLLOUT` registration on a pipe makes every `write(2)` *and* the + /// reader's `read(2)` pay for knote/wakeup bookkeeping. Pair with + /// [`unregister_poll`](Self::unregister_poll) once drained. + pub fn start_lazy(&mut self, fd: Fd, is_pollable: bool) -> sys::Result<()> { + if !is_pollable { + return self.start(fd, false); + } + let _ = self.ensure_poll(fd); + sys::Result::Ok(()) + } + + /// Undo `register_poll` (keeps the `FilePoll`). No-op if not registered. + pub fn unregister_poll(&mut self) { + let Some(poll) = self.get_poll() else { return }; + if !poll.is_registered() { + return; + } + // SAFETY: parent BACKREF set via set_parent; outlives this writer. + let loop_ = unsafe { Parent::loop_(self.parent()) }.cast(); + let _ = poll.unregister(loop_, false); + } + + fn ensure_poll(&mut self, fd: Fd) -> FilePollRef { + if let Some(p) = self.get_poll() { + return p; + } + // SAFETY: parent BACKREF set via set_parent; outlives this writer. + let loop_ = unsafe { Parent::event_loop(self.parent()) }; + let p = FilePollRef::init( + loop_, + fd, + Owner::new(Parent::POLL_OWNER_TAG, std::ptr::from_mut(self).cast()), + ); + self.handle = PollOrFd::Poll(p); + p + } } impl Drop for PosixStreamingWriter { @@ -2487,6 +2577,21 @@ impl WindowsStreamingWriter { self.write_internal_u8(buffer, WriteKind::Bytes) } + /// Windows never coalesces (`uv_write` / `WriteFile` per call), so these + /// are the plain writes; see the posix `write_now`. + #[inline] + pub fn write_now(&mut self, buffer: &[u8]) -> WriteResult { + self.write(buffer) + } + #[inline] + pub fn write_latin1_now(&mut self, buffer: &[u8]) -> WriteResult { + self.write_latin1(buffer) + } + #[inline] + pub fn write_utf16_now(&mut self, buf: &[u16]) -> WriteResult { + self.write_utf16(buf) + } + pub fn flush(&mut self) -> WriteResult { if self.is_done { return WriteResult::Done(0); diff --git a/src/io/lib.rs b/src/io/lib.rs index e17d52e9384b..4d4a350e8627 100644 --- a/src/io/lib.rs +++ b/src/io/lib.rs @@ -480,8 +480,10 @@ pub mod pipes; #[cfg(windows)] #[path = "source.rs"] pub mod source; +pub mod stdio_lock; #[path = "write.rs"] pub mod write; +pub use stdio_lock::StdioLock; // ── re-exports for higher tiers ───────────────────────────────────────────── // Byte-level `Write` trait + helpers. Downstream @@ -1888,6 +1890,10 @@ impl FilePollRef { self.inner().flags.insert(f); } #[inline] + pub fn clear_flag(self, f: FilePollFlag) { + self.inner().flags.remove(f); + } + #[inline] pub(crate) fn file_type(self) -> crate::pipes::FileType { #[cfg(not(windows))] { diff --git a/src/io/openForWriting.rs b/src/io/openForWriting.rs index ac898e686bea..bd6c0d079b6e 100644 --- a/src/io/openForWriting.rs +++ b/src/io/openForWriting.rs @@ -147,7 +147,10 @@ where // this.force_sync = true; // this.writer.force_sync = true; on_force_sync_or_isa_tty(ctx); - } else if !is_nonblocking { + } else if !is_nonblocking && *pollable { + // O_NONBLOCK is meaningless on regular files / char devices + // and lives on the shared open file description, so only + // set it where it buys us EAGAIN semantics. let flags = match bun_sys::get_fcntl_flags(fd) { Ok(flags) => flags, Err(err) => { diff --git a/src/io/stdio_lock.rs b/src/io/stdio_lock.rs new file mode 100644 index 000000000000..d82fd022f8b2 --- /dev/null +++ b/src/io/stdio_lock.rs @@ -0,0 +1,75 @@ +//! Process-wide, per-fd, reentrant lock around "one message to fd 1 / fd 2". +//! +//! Every JS thread has its own stdio sink for stdout and stderr (poll +//! registration, `'drain'` delivery and keep-alive are event-loop-affine), but +//! they all end at the same two file descriptors. Holding this lock for the +//! duration of one console message / one synchronous drain is what keeps a +//! worker's `console.log` from landing in the middle of the main thread's. +//! Reentrant per thread because formatting can re-enter (`console.log` inside +//! a getter that `console.log`s). + +use core::cell::Cell; + +use bun_sys::Fd; +use bun_threading::Mutex; + +static STDOUT_MUTEX: Mutex = Mutex::new(); +static STDERR_MUTEX: Mutex = Mutex::new(); + +thread_local! { + static DEPTH: [Cell; 2] = const { [Cell::new(0), Cell::new(0)] }; +} + +#[inline] +fn slot(fd: Fd) -> Option { + if fd == Fd::stdout() { + Some(0) + } else if fd == Fd::stderr() { + Some(1) + } else { + None + } +} + +#[inline] +fn mutex(slot: usize) -> &'static Mutex { + if slot == 0 { + &STDOUT_MUTEX + } else { + &STDERR_MUTEX + } +} + +/// RAII guard; no-op for fds other than 1 and 2. `!Send`: the depth it +/// balances is this thread's. +pub struct StdioLock(Option, core::marker::PhantomData<*mut ()>); + +impl StdioLock { + #[inline] + pub fn acquire(fd: Fd) -> Self { + let slot = slot(fd); + if let Some(i) = slot { + DEPTH.with(|d| { + if d[i].get() == 0 { + mutex(i).lock(); + } + d[i].set(d[i].get() + 1); + }); + } + Self(slot, core::marker::PhantomData) + } +} + +impl Drop for StdioLock { + #[inline] + fn drop(&mut self) { + if let Some(i) = self.0 { + DEPTH.with(|d| { + d[i].set(d[i].get() - 1); + if d[i].get() == 0 { + mutex(i).unlock(); + } + }); + } + } +} diff --git a/src/js/builtins/BunBuiltinNames.h b/src/js/builtins/BunBuiltinNames.h index c2efbaa08d25..7144cfe1036f 100644 --- a/src/js/builtins/BunBuiltinNames.h +++ b/src/js/builtins/BunBuiltinNames.h @@ -65,6 +65,7 @@ using namespace JSC; macro(close) \ macro(cmd) \ macro(code) \ + macro(consoleStream) \ macro(controller) \ macro(createCommonJSModule) \ macro(createFIFO) \ @@ -182,8 +183,11 @@ using namespace JSC; macro(statusCode) \ macro(statusMessage) \ macro(statusText) \ + macro(stderr) \ + macro(stdout) \ macro(stream) \ macro(syscall) \ + macro(takeBuffered) \ macro(text) \ macro(textDecoder) \ macro(textDecoderStreamDecoder) \ diff --git a/src/js/builtins/ConsoleObject.ts b/src/js/builtins/ConsoleObject.ts index 830676866b24..dc5327386229 100644 --- a/src/js/builtins/ConsoleObject.ts +++ b/src/js/builtins/ConsoleObject.ts @@ -118,16 +118,54 @@ export function asyncIterator(this: Console) { export function write(this: Console, input) { if (!$isObject(this)) throw $ERR_INVALID_THIS("Console"); + // Same routing as console.log: if the console's stdout is something user code + // can observe (a worker's port stream, console._stdout = x, a patched + // process.stdout.write, ...) go through its write(); otherwise the shared + // native stdout sink. + var consoleStream = $getByIdDirectPrivate(this, "consoleStream"); + if (!consoleStream) { + consoleStream = $newCppFunction("BunProcess.cpp", "jsFunctionConsoleStream", 1); + $putByIdDirectPrivate(this, "consoleStream", consoleStream); + } + const observed = consoleStream(1); + const count = $argumentCount(); + if (observed) { + // Same error policy as console.log on this path (`writeToObservedStream` + // below, Node's ignoreErrors): a broken stream neither throws out of + // console.write nor becomes an unhandled 'error'. + const noop = () => {}; + const isEmitter = + typeof observed.listenerCount === "function" && + typeof observed.once === "function" && + typeof observed.removeListener === "function"; + let guarded = false; + var wrote = 0; + try { + if (isEmitter && observed.listenerCount("error") === 0) { + observed.once("error", noop); + guarded = true; + } + for (var i = 0; i < count; i++) { + const chunk = arguments[i]; + observed.write(chunk); + wrote += typeof chunk === "string" ? Buffer.byteLength(chunk) : $toLength(chunk?.byteLength ?? 0); + } + } catch (e: any) { + if (e?.name === "RangeError" && e?.message === "Maximum call stack size exceeded.") throw e; + } finally { + if (guarded) observed.removeListener("error", noop); + } + return wrote; + } + var writer = $getByIdDirectPrivate(this, "writer"); if (!writer) { - var length = $toLength(input?.length ?? 0); - writer = Bun.stdout.writer({ highWaterMark: length > 65536 ? length : 65536 }); + // The per-VM stdout sink, shared with console.log / process.stdout. + writer = Bun.stdout.writer(); $putByIdDirectPrivate(this, "writer", writer); } var wrote = writer.write(input); - - const count = $argumentCount(); for (var i = 1; i < count; i++) { wrote += writer.write(arguments[i]); } @@ -136,6 +174,48 @@ export function write(this: Console, input) { return wrote; } +// The global console's slow path: user code can observe the write (patched +// `process.stdout.write`, `console._stdout = other`, corked/ended stream), so +// deliver the already-formatted message through `stream.write()` exactly like +// Node's kWriteToConsole with `ignoreErrors: true`. +// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L280-L322 +$visibility = "Private"; +export function writeToObservedStream(stream, chunk: string) { + const noop = () => {}; + // There may be an error occurring synchronously (e.g. for files or TTYs + // on POSIX systems) or asynchronously (e.g. pipes on POSIX systems), so + // handle both situations. + const isEmitter = + typeof stream?.listenerCount === "function" && + typeof stream?.once === "function" && + typeof stream?.removeListener === "function"; + let guarded = false; + try { + // Add and later remove a noop error handler to catch synchronous errors. + if (isEmitter && stream.listenerCount("error") === 0) { + stream.once("error", noop); + guarded = true; + } + stream.write(chunk, err => { + // Errors that were not already emitted (async _write callback) surface + // as an 'error' event; a `once` noop keeps that from becoming an + // uncaught exception without swallowing it for other writers. + if (err != null && isEmitter && !stream._writableState?.errorEmitted) { + if (stream.listenerCount("error") === 0) { + stream.once("error", noop); + } + } + }); + } catch (e: any) { + // Console is a debugging utility, so it swallowing errors is not + // desirable even in edge cases such as low stack space. + if (e?.name === "RangeError" && e?.message === "Maximum call stack size exceeded.") throw e; + // Sorry, there's no proper way to pass along the error here. + } finally { + if (guarded) stream.removeListener("error", noop); + } +} + // This is the `console.Console` constructor. It is mostly copied from Node. // https://github.com/nodejs/node/blob/d2c7c367741bdcb6f7f77f55ce95a745f0b29fef/lib/internal/console/constructor.js // Some parts are copied from imported files and inlined here. Not too much of a performance issue diff --git a/src/js/builtins/ProcessObjectInternals.ts b/src/js/builtins/ProcessObjectInternals.ts index 84f559291595..6e4597e1c999 100644 --- a/src/js/builtins/ProcessObjectInternals.ts +++ b/src/js/builtins/ProcessObjectInternals.ts @@ -38,6 +38,8 @@ export function getStdioWriteStream( ) { $assert(fd === 1 || fd === 2, `Expected fd to be 1 or 2, got ${fd}`); + // Both constructors below sit on the per-VM stdio FileSink for `fd` (via + // `Bun.file(fd).writer()`), the same object console.* writes through. let stream; if (isTTY) { const tty = require("node:tty"); @@ -65,54 +67,144 @@ export function getStdioWriteStream( // stdout/stderr don't produce readable data, so yield nothing })(); }; - } else { - // File-backed stdio: Node's SyncWriteStream runs end() -> finish -> - // destroy -> the _destroy override below -> _undestroy(), which resets - // writable state so later writes succeed. autoClose:false disabled that. - stream._writableState.autoDestroy = true; } } - if (fd === 1 || fd === 2) { - stream.destroySoon = stream.destroy; - stream._destroy = function (err, cb) { - cb(err); - this._undestroy(); - - if (!this._writableState.emitClose) { - process.nextTick(() => { - this.emit("close"); - }); - } - }; + // Node's stdio streams (net.Socket / SyncWriteStream) run with autoDestroy: + // end() -> finish -> destroy -> the _destroy override below -> _undestroy() + // resets state so later writes succeed, and a failed write goes + // errorOrDestroy -> destroy -> _undestroy -> 'error' *every* time instead + // of latching on errorEmitted after the first. autoClose:false turned it off. + stream._writableState.autoDestroy = true; + + // Node terminates on the first unhandled 'error'; Bun keeps running after an + // uncaught exception, so a write loop on a dead pipe would otherwise print + // one uncaught EPIPE per write. Surface the first, drop the repeats. + let unhandledErrorSeen = false; + stream._destroy = function (err, cb) { + if (err && this.listenerCount("error") === 0) { + if (unhandledErrorSeen) err = null; + unhandledErrorSeen = true; + } + cb(err); + this._undestroy(); + updateObserved(this); + + // `_undestroy()` above reset the state before Writable's own close path + // ran, so with emitClose off nothing would announce the (transient) + // destruction; keep it observable for `finished()` / `pipeline()`. + if (!this._writableState.emitClose) { + process.nextTick(() => { + this.emit("close"); + }); + } + }; - const kFastPath = require("internal/fs/streams").kWriteStreamFastPath; - stream._final = function (cb) { - try { - const sink = this[kFastPath]; - if (sink && sink !== true) { - const result = sink.flush(); - if ($isPromise(result)) { - result.then( - () => cb(null), - err => cb(err), - ); - return; - } + const { kWriteStreamFastPath, kOnPendingWrite } = require("internal/fs/streams"); + stream._final = function (cb) { + try { + const sink = this[kWriteStreamFastPath]; + if (sink && sink !== true) { + const result = sink.flush(); + if ($isPromise(result)) { + result.then( + () => cb(null), + err => cb(err), + ); + return; } - cb(null); - } catch (err) { - cb(err); } - }; + cb(null); + } catch (err) { + cb(err); + } + }; + + // console.* writes straight to the shared native sink unless doing so could + // be told apart from a `write()` call: while this Writable is corked, is + // ending/ended, or has a write in flight (later chunks queue in *its* + // buffer, and a native write would jump that queue). Keep the native side + // informed; it checks a bitfield, never these JS objects. + const setStdioObserved = $newCppFunction("BunProcess.cpp", "jsFunctionSetStdioObserved", 2); + let pendingWrite = false; + function updateObserved(stream) { + const state = stream._writableState; + setStdioObserved( + fd, + (state.corked ? 1 : 0) | (state.ending || state.ended || state.destroyed ? 2 : 0) | (pendingWrite ? 4 : 0), + ); } + stream[kOnPendingWrite] = function (pending) { + pendingWrite = pending; + updateObserved(this); + }; + const { cork: baseCork, uncork: baseUncork, end: baseEnd, destroy: baseDestroy } = stream; + // Same shape a user sees on any Writable: named, non-enumerable methods. + const hidden = (value: Function) => ({ value, writable: true, configurable: true, enumerable: false }); + Object.defineProperties(stream, { + cork: hidden(function cork(this: any) { + baseCork.$call(this); + updateObserved(this); + }), + uncork: hidden(function uncork(this: any) { + baseUncork.$call(this); + updateObserved(this); + }), + end: hidden(function end(this: any, ...args) { + const ret = baseEnd.$apply(this, args); + updateObserved(this); + return ret; + }), + destroy: hidden(function destroy(this: any, ...args) { + const ret = baseDestroy.$apply(this, args); + updateObserved(this); + return ret; + }), + }); + stream.destroySoon = stream.destroy; stream._isStdio = true; stream.fd = fd; - const underlyingSink = stream[require("internal/fs/streams").kWriteStreamFastPath]; - $assert(underlyingSink); - return [stream, underlyingSink]; + $assert(stream[kWriteStreamFastPath], "stdio stream must be FileSink-backed"); + return stream; +} + +// A console.* write on the shared stdio sink failed (EPIPE etc.). Node's +// console swallows write errors, but the stream still emits 'error' for +// whoever listens; with nobody listening it must not become an uncaught +// exception (that is what console's once('error', noop) guard is for). +// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L380-L399 +export function reportStdioSinkError(stream, err) { + if (typeof stream?.listenerCount === "function" && stream.listenerCount("error") > 0) { + stream.destroy(err); + } +} + +// process.exit() / end of program: chunks this stdio Writable had queued in +// JS behind an in-flight write are handed to the native sink now, so the exit +// drain (FileSink::drain_sync) writes them instead of dropping them. Chunks +// held by an explicit, never-released cork() stay held. +export function flushStdioWriteStreamOnExit(stream) { + const state = stream?._writableState; + if (!state || state.corked) return; + const sink = stream[require("internal/fs/streams").kWriteStreamFastPath]; + if (!sink || sink === true) return; + const buffered = $getByIdDirectPrivate(require("internal/streams/writable"), "takeBuffered")(state); + for (let i = 0; i < buffered.length; i++) { + const { chunk, encoding } = buffered[i]; + // A failure here (rejected promise: the sink's latched EPIPE/EIO; throw: a + // closed sink) was already surfaced by the write ahead of these chunks; + // the exit must go on. + try { + const result = sink.write( + typeof chunk === "string" && encoding !== "utf8" && encoding !== "utf-8" && encoding !== "buffer" + ? Buffer.from(chunk, encoding) + : chunk, + ); + if ($isPromise(result)) result.then(undefined, () => {}); + } catch {} + } } export function getStdinStream( diff --git a/src/js/internal/fs/streams.ts b/src/js/internal/fs/streams.ts index 37c061993518..54c12fbfce5a 100644 --- a/src/js/internal/fs/streams.ts +++ b/src/js/internal/fs/streams.ts @@ -471,8 +471,11 @@ function WriteStream(this: FSStream, path: string | null, options?: any): void { if (fastPath) { this[kWriteStreamFastPath] = fd != null ? fastWriter : true; this._write = underscoreWriteFast; - this._writev = undefined; - this.write = writeFast as any; + this._writev = underscoreWritevFast; + // The FileSink encodes strings straight into its own buffer, so skip the + // Buffer.from() round-trip. node's process.stdout/stderr (net.Socket) also + // run with decodeStrings: false. + options.decodeStrings = false; if (fd != null) { // Already-open fd (stdio): skip the async _construct round-trip so the // stream is born constructed, like node's stdio streams (net.Socket / @@ -590,13 +593,28 @@ function _write(data, encoding, cb) { } writeStreamPrototype._write = _write; -function underscoreWriteFast(this: FSStream, data: any, encoding: any, cb: any) { +// `_write` for FileSink-backed streams (process.stdout/stderr, tty.WriteStream, +// child.stdin). Hands the chunk to the fd now: completes synchronously when it +// all went out, so back-to-back writes don't pile up in the Writable buffer, +// and on the sink's promise when the fd is backed up — which is what keeps +// writableLength / writableNeedDrain / 'drain' honest. `kOnPendingWrite`, if the owner set one, +// hears about a write going async and settling (process.stdout uses it to +// keep console.* from overtaking chunks queued behind that write). +const kOnPendingWrite = Symbol("kOnPendingWrite"); +// `FileSink.prototype.write` coalesces small chunks until end of tick — right +// for a batching `Bun.file(fd).writer()` and kept for `child.stdin` / +// `tty.WriteStream(fd)` (chatty pipe protocols); process.stdout/stderr's +// `_write` wants the syscall now like Node's, with the same return contract. +const fileSinkWriteNow = $newRustFunction("runtime/webcore/FileSink.rs", "writeNow", 2); +function underscoreWriteFast(this: FSStream, chunk: any, encoding: any, cb: any) { let fileSink = this[kWriteStreamFastPath]; if (!fileSink) { // When the fast path is disabled, the write function gets reset. this._write = _write; - return this._write(data, encoding, cb); + return this._write(chunk, encoding, cb); } + + let maybePromise; try { if (fileSink === true) { fileSink = this[kWriteStreamFastPath] = Bun.file(this.path).writer(); @@ -604,83 +622,57 @@ function underscoreWriteFast(this: FSStream, data: any, encoding: any, cb: any) this.fd = fileSink._getFd(); } - const maybePromise = fileSink.write(data); - if ($isPromise(maybePromise)) { - maybePromise.then( - () => { - if (cb) cb(null); - this.emit("drain"); - }, - err => { - if (cb) cb(err); - require("internal/streams/destroy").errorOrDestroy(this, err); - }, - ); - return false; - } else { - if (cb) process.nextTick(cb, null); - return true; + // decodeStrings is off for this path: the sink encodes UTF-8 itself, but + // every other encoding has to be decoded here. + if (typeof chunk === "string" && encoding !== "utf8" && encoding !== "utf-8") { + chunk = Buffer.from(chunk, encoding); } + + maybePromise = this._isStdio === true ? fileSinkWriteNow(fileSink, chunk) : fileSink.write(chunk); } catch (e) { - if (cb) process.nextTick(cb, e); - require("internal/streams/destroy").errorOrDestroy(this, e, true); - return false; + cb(e); + return; } -} -// This function implementation is not correct. -const writablePrototypeWrite = Writable.prototype.write; -const kWriteMonkeyPatchDefense = Symbol("!"); -function writeFast(this: FSStream, data: any, encoding: any, cb: any) { - if (this[kWriteMonkeyPatchDefense]) return writablePrototypeWrite.$call(this, data, encoding, cb); + settleFastWrite(this, maybePromise, typeof chunk === "string" ? Buffer.byteLength(chunk) : chunk.byteLength, cb); +} - // After end()/destroy() the Writable contract requires write() to fail with - // ERR_STREAM_WRITE_AFTER_END / ERR_STREAM_DESTROYED and not reach the sink. - const state = this._writableState; - if (state !== undefined && (state.ending || state.destroyed)) { - return writablePrototypeWrite.$call(this, data, encoding, cb); +function settleFastWrite(stream, maybePromise, size, cb) { + if ($isPromise(maybePromise)) { + const onPending = stream[kOnPendingWrite]; + if (onPending) onPending.$call(stream, true); + maybePromise.then( + () => { + stream.bytesWritten += size; + if (onPending) onPending.$call(stream, false); + cb(null); + }, + err => { + if (onPending) onPending.$call(stream, false); + cb(err); + }, + ); + } else { + stream.bytesWritten += size; + cb(null); } +} - if (typeof encoding === "function") { - cb = encoding; - encoding = undefined; - } - if (typeof cb !== "function") { - cb = streamNoop; +// `_writev` for the same streams. A corked burst (and a backlog drained after +// backpressure) reaches the fd as one write — what cork() is for; node's stdio +// over a pipe coalesces the same burst into a single writev(2). +function underscoreWritevFast(this: FSStream, data: any, cb: any) { + const len = data.length; + if (len === 1) { + const { chunk, encoding } = data[0]; + return underscoreWriteFast.$call(this, chunk, encoding, cb); } - - const fileSink = this[kWriteStreamFastPath]; - if (fileSink && fileSink !== true) { - const maybePromise = fileSink.write(data); - if ($isPromise(maybePromise)) { - // Two-arg then(): a throw from the fulfillment handler must not be - // mistaken for a write failure. - maybePromise.then( - () => { - this.emit("drain"); // Emit drain event - cb(null); - }, - err => { - cb(err); - // Node.js onwriteError: callback AND destroy are both invoked; the - // callback is additive, not a replacement for the 'error' event. - require("internal/streams/destroy").errorOrDestroy(this, err); - }, - ); - return false; // Indicate backpressure - } else { - cb(null); - return true; // No backpressure - } - } else { - const result: any = this._write(data, encoding, cb); - if (this.write === writeFast) { - this.write = writablePrototypeWrite; - } else { - this[kWriteMonkeyPatchDefense] = true; - } - return result; + const chunks = new Array(len); + for (let i = 0; i < len; i++) { + const { chunk, encoding } = data[i]; + chunks[i] = typeof chunk === "string" ? Buffer.from(chunk, encoding) : chunk; } + return underscoreWriteFast.$call(this, Buffer.concat(chunks), "buffer", cb); } writeStreamPrototype._writev = function (data, cb) { @@ -811,5 +803,6 @@ export default { ReadStream, WriteStream, kWriteStreamFastPath, + kOnPendingWrite, writableFromFileSink, }; diff --git a/src/js/internal/streams/legacy.ts b/src/js/internal/streams/legacy.ts index 2ed60fff0b9c..8686b2e79b53 100644 --- a/src/js/internal/streams/legacy.ts +++ b/src/js/internal/streams/legacy.ts @@ -1,7 +1,7 @@ "use strict"; const EE = require("node:events"); -const { isArrayBufferView, isUint8Array } = require("node:util/types"); +const { isArrayBufferView, isUint8Array, isAnyArrayBuffer } = require("node:util/types"); const ReflectOwnKeys = Reflect.ownKeys; const ArrayIsArray = Array.isArray; @@ -119,6 +119,7 @@ function prependListener(emitter, event, fn) { // Add helper methods to Stream Stream._isArrayBufferView = isArrayBufferView; +Stream._isAnyArrayBuffer = isAnyArrayBuffer; Stream._isUint8Array = isUint8Array; Stream._uint8ArrayToBuffer = function _uint8ArrayToBuffer(chunk) { return new $Buffer(chunk.buffer, chunk.byteOffset, chunk.byteLength); diff --git a/src/js/internal/streams/writable.ts b/src/js/internal/streams/writable.ts index d0fe11d84d4a..c86b2af318b8 100644 --- a/src/js/internal/streams/writable.ts +++ b/src/js/internal/streams/writable.ts @@ -334,6 +334,19 @@ function resetBuffer(state) { state[kState] &= ~kBuffered; } +// Detach and return whatever is queued behind the in-flight write (their +// callbacks will never run). For handing the chunks to another sink when this +// stream is being abandoned, e.g. stdio at process exit. +function takeBuffered(state) { + if ((state[kState] & kBuffered) === 0) return []; + const buffered = ArrayPrototypeSlice.$call(state.buffered, state.bufferedIndex); + for (let i = 0; i < buffered.length; i++) { + state.length -= (state[kState] & kObjectMode) !== 0 ? 1 : buffered[i].chunk.length; + } + resetBuffer(state); + return buffered; +} + WritableState.prototype.getBuffer = function getBuffer() { return (this[kState] & kBuffered) === 0 ? [] : ArrayPrototypeSlice.$call(this.buffered, this.bufferedIndex); }; @@ -397,6 +410,9 @@ function Writable(options): void { $toClass(Writable, "Writable", Stream); Writable.WritableState = WritableState; +// Internal-only (process stdio at exit); a private name keeps it off the public +// `stream.Writable` surface. +$putByIdDirectPrivate(Writable, "takeBuffered", takeBuffered); ObjectDefineProperty(Writable, SymbolHasInstance, { __proto__: null, @@ -444,6 +460,15 @@ function _write(stream, chunk, encoding, cb?) { } else if (Stream._isArrayBufferView(chunk)) { chunk = Stream._uint8ArrayToBuffer(chunk); encoding = "buffer"; + } else if ( + Stream._isAnyArrayBuffer(chunk) && + (stream._isStdio === true || stream[require("internal/fs/streams").kWriteStreamFastPath]) + ) { + // Bun's FileSink-backed streams (process.stdout/stderr, child.stdin, + // tty.WriteStream(fd)) have always taken a bare (Shared)ArrayBuffer; keep + // accepting it there (Node rejects it, so nothing relies on the throw). + chunk = new Uint8Array(chunk); + encoding = "buffer"; } else { throw $ERR_INVALID_ARG_TYPE("chunk", ["string", "Buffer", "TypedArray", "DataView"], chunk); } diff --git a/src/js/node/diagnostics_channel.ts b/src/js/node/diagnostics_channel.ts index 4c26ff1017fe..9cb41ccc4007 100644 --- a/src/js/node/diagnostics_channel.ts +++ b/src/js/node/diagnostics_channel.ts @@ -62,6 +62,7 @@ function markActive(channel) { ObjectSetPrototypeOf.$call(null, channel, ActiveChannel.prototype); channel._subscribers = []; channel._stores = new SafeMap(); + updateConsoleChannel(channel, true); } function maybeMarkInactive(channel) { @@ -70,9 +71,33 @@ function maybeMarkInactive(channel) { ObjectSetPrototypeOf.$call(null, channel, Channel.prototype); channel._subscribers = undefined; channel._stores = undefined; + updateConsoleChannel(channel, false); } } +// The global console publishes its arguments on these channels before +// formatting, but only while somebody is subscribed: +// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L66-L70 +// The console is native, so tell it which of the five currently have +// subscribers (a bitmask it can test for free) and hand it one function to +// publish through. +const kConsoleChannelNames = ["console.log", "console.warn", "console.error", "console.debug", "console.info"]; +let consoleChannelMask = 0; +let setConsoleChannels; +function publishToConsoleChannel(index: number, args: unknown[]) { + channels.get(kConsoleChannelNames[index])?.publish(args); +} +function updateConsoleChannel(channel, active: boolean) { + const index = ArrayPrototypeIndexOf.$call(kConsoleChannelNames, channel.name); + if (index === -1) return; + const bit = 1 << index; + const next = active ? consoleChannelMask | bit : consoleChannelMask & ~bit; + if (next === consoleChannelMask) return; + consoleChannelMask = next; + setConsoleChannels ??= $newCppFunction("BunProcess.cpp", "jsFunctionSetConsoleChannels", 2); + setConsoleChannels(consoleChannelMask, publishToConsoleChannel); +} + function defaultTransform(data) { return data; } diff --git a/src/js/node/worker_threads.ts b/src/js/node/worker_threads.ts index 5fa6aa8707f8..1b825baf98b8 100644 --- a/src/js/node/worker_threads.ts +++ b/src/js/node/worker_threads.ts @@ -450,43 +450,34 @@ function makePortWritable(port) { function setupWorkerStdio(stdio) { const { stdin, stdout, stderr } = stdio; + // Plain assignment, not Object.defineProperty: `process.stdout/stderr/stdin` + // are lazy native properties, and defineProperty would reify (and so build, + // and dup an fd for) the fd-backed stream we are replacing. Assignment just + // replaces the slot; the descriptor comes out {writable,enumerable,configurable} + // either way. The native console is then pointed at the port streams, which is + // what routes a worker's console.log to the parent (Node: console._stdout is + // process.stdout, which in a worker is a port-backed Writable). + const setConsoleStream = $newCppFunction("BunProcess.cpp", "jsFunctionSetConsoleStream", 2); if (stdout) { - Object.defineProperty(process, "stdout", { - value: makePortWritable(stdout), - writable: true, - configurable: true, - enumerable: true, - }); + const stream = makePortWritable(stdout); + (process as any).stdout = stream; + setConsoleStream(1, stream); } if (stderr) { - Object.defineProperty(process, "stderr", { - value: makePortWritable(stderr), - writable: true, - configurable: true, - enumerable: true, - }); + const stream = makePortWritable(stderr); + (process as any).stderr = stream; + setConsoleStream(2, stream); } // node always replaces a worker's process.stdin: port-backed when { stdin: true }, // otherwise an immediately-EOF'd stream — never the process-wide fd 0, which // would race the main thread (and hang on a TTY). - Object.defineProperty(process, "stdin", { - value: stdin - ? makePortReadable(stdin, true) - : new Readable({ - read() { - this.push(null); - }, - }), - writable: true, - configurable: true, - enumerable: true, - }); - // node routes console.log through process.stdout/stderr; Bun's global console - // writes the fd directly, so rebind it to the captured streams when present. - if (stdout || stderr) { - const { Console } = require("node:console"); - globalThis.console = new Console(process.stdout, process.stderr); - } + (process as any).stdin = stdin + ? makePortReadable(stdin, true) + : new Readable({ + read() { + this.push(null); + }, + }); } // Emulation of Node's JSTransferable protocol (kTransfer/kTransferList/kDeserialize) for diff --git a/src/jsc/ConsoleObject.rs b/src/jsc/ConsoleObject.rs index 29152e29c5cf..c63e881e32d6 100644 --- a/src/jsc/ConsoleObject.rs +++ b/src/jsc/ConsoleObject.rs @@ -3,16 +3,17 @@ //! `console.count`/`time`/`timeEnd`, and the C ABI shims that JavaScriptCore //! calls into. -use crate::{ComptimeStringMapExt as _, ZigStringJsc as _}; +use crate::{ComptimeStringMapExt as _, StringJsc as _, ZigStringJsc as _}; use core::cell::{Cell, RefCell}; use core::ffi::c_void; use crate as jsc; use crate::virtual_machine::VirtualMachine; -use crate::{EventType, JSGlobalObject, JSPromise, JSValue, JsResult, ZigString}; +use crate::{EventType, JSGlobalObject, JSPromise, JSValue, JsError, JsResult, ZigString}; use bun_collections::HashMap; use bun_core::{Output, StackCheck}; use bun_core::{OwnedString, String as BunString, strings}; +use bun_io::Write as _; /// Thin facade over `bun_js_parser::lexer` / `bun_js_printer` so the call /// sites below can use the `JSLexer.isLatin1Identifier` / @@ -88,19 +89,17 @@ const DEFAULT_CONSOLE_LOG_DEPTH: u16 = 2; type Counter = HashMap; pub struct ConsoleObject { - stderr_buffer: [u8; 4096], - stdout_buffer: [u8; 4096], - - error_writer_backing: Output::QuietWriterAdapter, - writer_backing: Output::QuietWriterAdapter, + /// A console message is formatted in full into this buffer and only then + /// handed to the stdio sink (or, when the stream is observed by user code, + /// to JS) — the same shape as Node's `formatWithOptions` → `stream.write`. + /// Taken (`mem::take`) for the duration of a call so a `console.*` that + /// re-enters during formatting (a getter that logs) formats into its own + /// buffer and is emitted first, as in Node. + scratch: Vec, pub(crate) default_indent: u16, counts: Counter, - - // The writer adapters above hold raw pointers into `{stderr,stdout}_buffer`; - // moving the struct would dangle them, so opt out of `Unpin`. - _pin: core::marker::PhantomPinned, } impl core::fmt::Display for ConsoleObject { @@ -110,52 +109,280 @@ impl core::fmt::Display for ConsoleObject { } } +impl Default for ConsoleObject { + fn default() -> Self { + Self::new() + } +} + impl ConsoleObject { - /// `adapt_to_new_api(&mut self.stderr_buffer)` captures a raw pointer into - /// the buffer field, so the struct is self-referential once initialized: - /// the address of `*out` MUST be stable for the value's entire lifetime — - /// moving it afterwards leaves the writer adapters dangling. - pub(crate) fn init_in_place( - out: &mut core::mem::MaybeUninit, - error_writer: Output::StreamType, - writer: Output::StreamType, - ) -> &mut ConsoleObject { - let out = out.write(ConsoleObject { - stderr_buffer: [0; 4096], - stdout_buffer: [0; 4096], - error_writer_backing: Output::QuietWriterAdapter::uninit(), - writer_backing: Output::QuietWriterAdapter::uninit(), + pub fn new() -> ConsoleObject { + ConsoleObject { + scratch: Vec::new(), default_indent: 0, counts: Counter::default(), - _pin: core::marker::PhantomPinned, - }); - let p: *mut ConsoleObject = out; - // SAFETY: `out` is now fully initialized at its final address; the - // adapters store raw pointers into `out.stderr_buffer` / - // `out.stdout_buffer`, which remain valid for `out`'s lifetime - // *provided the caller never moves it* (see fn doc). + } + } + + #[inline] + fn take_scratch(this: *mut ConsoleObject) -> Vec { + // SAFETY: `this` is the live per-VM console (see [`vm_console`]); + // single field move-out, no reference held past this statement. + unsafe { core::mem::take(&mut (*this).scratch) } + } + + #[inline] + fn put_scratch(this: *mut ConsoleObject, mut buf: Vec) { + buf.clear(); + // The native path never holds more than `SPILL_AT`; only a message that + // had to be handed to JS whole (or one oversized chunk) grows past it, + // and that one shouldn't pin its buffer for the life of the VM. + if buf.capacity() > SPILL_AT { + buf.shrink_to(SPILL_AT); + } + // SAFETY: as above. If a re-entrant call left its (smaller) buffer + // here, keep whichever is larger. unsafe { - (*p).error_writer_backing = error_writer - .quiet_writer() - .adapt_to_new_api(&mut (*p).stderr_buffer); - (*p).writer_backing = writer - .quiet_writer() - .adapt_to_new_api(&mut (*p).stdout_buffer); - } - out + if (*this).scratch.capacity() < buf.capacity() { + (*this).scratch = buf; + } + } + } +} + +// ─────────────────────────────────────────────────────────────────────────── +// Delivery: stdio sink (fast) or the observed JS stream (Node's kWriteToConsole) +// ─────────────────────────────────────────────────────────────────────────── + +unsafe extern "Rust" { + /// `bun_runtime::webcore::file_sink::__bun_stdio_sink_write` — hand one + /// whole console message to this VM's stdio sink for `fd`; returns once it + /// has reached the fd (queued `process.stdout` bytes go out first). + fn __bun_stdio_sink_write( + vm: *mut VirtualMachine, + fd: bun_sys::Fd, + bytes: &[u8], + ) -> Result<(), bun_sys::Error>; + /// `bun_runtime::webcore::file_sink::__bun_stdio_sink_drain_fd` — flush + /// this fd's stdio sink queue now (no-op if it doesn't exist). + fn __bun_stdio_sink_drain_fd(vm: *mut VirtualMachine, fd: bun_sys::Fd); +} + +unsafe extern "C" { + /// `BunProcess.cpp` — the stream the console must go through via JS + /// `write()` for `fd`, or the empty value when the native sink may be used. + /// A structure compare in the steady state; the very first call may run + /// (and rethrow from) a user getter installed on `process.stdout`. + fn Bun__Process__consoleStream(global: &JSGlobalObject, fd: i32, threw: &mut bool) -> JSValue; + /// `BunProcess.cpp` — `consoleObjectWriteToObservedStream(stream, chunk)`. + fn Bun__Console__writeToStream(global: &JSGlobalObject, stream: JSValue, chunk: JSValue); + /// `BunProcess.cpp` — the console's stream for `fd` is a foreign object + /// (not Bun's own stdio stream). Never runs user code. + safe fn Bun__Process__consoleStreamIsCustom(global: &JSGlobalObject, fd: i32) -> bool; + /// `BunProcess.cpp` — the console's stream *object* for `fd` if any exists + /// (custom binding or Bun's materialised stream), else empty. For + /// `console.clear()`'s `isTTY` check. Same throw contract as + /// `Bun__Process__consoleStream`. + fn Bun__Process__consoleStreamObject( + global: &JSGlobalObject, + fd: i32, + threw: &mut bool, + ) -> JSValue; +} + +/// Which of the two console streams a message goes to. Node: +/// `log/info/debug/dir/dirxml/table/count/timeLog/timeEnd/group` → stdout, +/// `warn/error/trace/assert` → stderr. +#[derive(Clone, Copy, PartialEq, Eq)] +pub enum ConsoleStream { + Stdout, + Stderr, +} + +impl ConsoleStream { + /// 1 or 2 — the number `BunProcess.cpp` keys its per-stream state by. + #[inline] + pub fn number(self) -> i32 { + match self { + ConsoleStream::Stdout => 1, + ConsoleStream::Stderr => 2, + } + } + + #[inline] + pub fn fd(self) -> bun_sys::Fd { + match self { + ConsoleStream::Stdout => bun_sys::Fd::stdout(), + ConsoleStream::Stderr => bun_sys::Fd::stderr(), + } } - /// Returns the buffered stderr writer interface. #[inline] - pub(crate) fn error_writer(&mut self) -> &mut bun_core::io::Writer { - self.error_writer_backing.new_interface() + pub fn colors(self) -> bool { + match self { + ConsoleStream::Stdout => Output::enable_ansi_colors_stdout(), + ConsoleStream::Stderr => Output::enable_ansi_colors_stderr(), + } } - /// Returns the buffered stdout writer interface. #[inline] - pub(crate) fn writer(&mut self) -> &mut bun_core::io::Writer { - self.writer_backing.new_interface() + fn for_message(message_type: MessageType, level: MessageLevel) -> Self { + if matches!(level, MessageLevel::Warning | MessageLevel::Error) + || matches!(message_type, MessageType::Assert | MessageType::Trace) + { + ConsoleStream::Stderr + } else { + ConsoleStream::Stdout + } + } +} + +/// Where one console message is going: the stdio sink, or — when user code +/// could tell the difference — the bound stream's JS `write()` (Node's +/// `kWriteToConsole`). +#[inline] +fn console_target(global: &JSGlobalObject, stream: ConsoleStream) -> JsResult { + let mut threw = false; + // SAFETY: plain FFI; `threw` is its throw contract. + let target = unsafe { Bun__Process__consoleStream(global, stream.number(), &mut threw) }; + if threw { + Err(JsError::Thrown) + } else { + Ok(target) + } +} + +/// Whether to colour a message bound for `target`: Bun's own fd 1/2 (native +/// or observed) → the usual per-fd answer; a foreign stream (worker port, +/// `console._stdout = x`) → `FORCE_COLOR`/`NO_COLOR`, else its own `isTTY`, +/// as Node's `Console` does for `colorMode: 'auto'`. +fn console_colors( + global: &JSGlobalObject, + stream: ConsoleStream, + target: JSValue, +) -> JsResult { + if target.is_empty() || !Bun__Process__consoleStreamIsCustom(global, stream.number()) { + return Ok(stream.colors()); + } + if let Some(forced) = Output::env_color_override() { + return Ok(forced); + } + if !target.is_object() { + return Ok(false); + } + Ok(target + .get(global, b"isTTY")? + .is_some_and(|v| v.to_boolean())) +} + +/// Deliver one whole formatted message to `target` (see [`console_target`]). +/// Errors reaching the fd (EPIPE, ...) are the sink's to surface on +/// `process.stdout`/`stderr`; the console itself never throws for them +/// (`ignoreErrors: true`). +fn deliver_to( + global: &JSGlobalObject, + stream: ConsoleStream, + target: JSValue, + bytes: &[u8], +) -> JsResult<()> { + if bytes.is_empty() { + return Ok(()); + } + let vm: *mut VirtualMachine = global.bun_vm().as_mut(); + if target.is_empty() { + // SAFETY: `vm` is the live per-thread VM that owns `global`. + let _ = unsafe { __bun_stdio_sink_write(vm, stream.fd(), bytes) }; + return Ok(()); } + // Switching to JS delivery: whatever the native side still has queued for + // this fd must land first or it would come out after this message. + // SAFETY: as above. + unsafe { __bun_stdio_sink_drain_fd(vm, stream.fd()) }; + let chunk = bun_core::String::borrow_utf8(bytes).to_js(global)?; + crate::from_js_host_call_generic(global, || { + // SAFETY: plain FFI; both values are live on this stack. + unsafe { Bun__Console__writeToStream(global, target, chunk) } + }) +} + +pub fn deliver(global: &JSGlobalObject, stream: ConsoleStream, bytes: &[u8]) -> JsResult<()> { + let target = console_target(global, stream)?; + deliver_to(global, stream, target, bytes) +} + +/// The writer console formatting goes through. Normally just the scratch +/// buffer; on the native path a message that outgrows [`SPILL_AT`] is written +/// out as it is produced (bounded memory, and a giant `console.log` starts +/// appearing before it is fully formatted) — the observed-stream path must +/// hand JS one string, as Node does, so it never spills. +pub struct ConsoleWriter<'a> { + buf: &'a mut Vec, + spill: Option<(*mut VirtualMachine, bun_sys::Fd)>, + /// A spill already failed (EPIPE, ...) and was reported: the rest of this + /// message is dropped rather than re-failing (and re-reporting) per block. + failed: bool, +} + +/// How much of one message to accumulate before writing it out on the native +/// path (and so the most scratch capacity kept between calls): the default +/// pipe capacity on Linux and macOS, so each spill is at most one pipe-full and +/// anything shorter is still a single `write(2)`. +const SPILL_AT: usize = 64 * 1024; + +impl bun_io::Write for ConsoleWriter<'_> { + #[inline] + fn write_all(&mut self, bytes: &[u8]) -> bun_core::CrateResult<()> { + if self.failed { + return Ok(()); + } + self.buf.extend_from_slice(bytes); + if self.buf.len() >= SPILL_AT { + if let Some((vm, fd)) = self.spill { + // SAFETY: `vm` is the live per-thread VM (set in `emit`). + self.failed = unsafe { __bun_stdio_sink_write(vm, fd, self.buf) }.is_err(); + self.buf.clear(); + } + } + Ok(()) + } +} + +/// Format a message with `f` and deliver it. If `f` fails (a JS exception +/// thrown while formatting — a throwing getter, `toJSON`, ...) the exception +/// propagates and nothing further is written, as in Node — except that on the +/// native path a message already past [`SPILL_AT`] has had its earlier 64 KiB +/// blocks written, so the reader sees it torn (bounded memory wins there). +pub fn emit( + global: &JSGlobalObject, + stream: ConsoleStream, + f: impl FnOnce(&mut ConsoleWriter<'_>, bool) -> JsResult<()>, +) -> JsResult<()> { + let target = console_target(global, stream)?; + let native = target.is_empty(); + let colors = console_colors(global, stream, target)?; + // No lock here: formatting runs user JS (getters, toJSON, inspect.custom) + // that may log to the *other* stream or exit; each write / spill takes the + // per-fd lock for itself (`FileSink::write_all_sync`). + + let console = vm_console(global); + let mut buf = ConsoleObject::take_scratch(console); + let mut writer = ConsoleWriter { + buf: &mut buf, + spill: native.then(|| { + ( + std::ptr::from_mut::(global.bun_vm().as_mut()), + stream.fd(), + ) + }), + failed: false, + }; + let result = match f(&mut writer, colors) { + Ok(()) if writer.failed => Ok(()), + Ok(()) => deliver_to(global, stream, target, &buf), + Err(err) => Err(err), + }; + ConsoleObject::put_scratch(console, buf); + result } #[repr(u32)] @@ -238,8 +465,6 @@ impl MessageType { // Bun__ConsoleObject__* shims. // ─────────────────────────────────────────────────────────────────────────── -use bun_threading::Mutex; - /// `globalThis.bunVM().console` — `VirtualMachine.console` is typed /// `*mut c_void` (erased so `virtual_machine.rs` need not name this module's /// type). This is the single re-entry point that casts it back; every body @@ -270,63 +495,6 @@ unsafe fn vm_console_mut<'a>(global: &JSGlobalObject) -> &'a mut ConsoleObject { unsafe { &mut *vm_console(global) } } -static STDERR_MUTEX: Mutex = Mutex::new(); -static STDOUT_MUTEX: Mutex = Mutex::new(); - -thread_local! { - static STDERR_LOCK_COUNT: Cell = const { Cell::new(0) }; - static STDOUT_LOCK_COUNT: Cell = const { Cell::new(0) }; -} - -/// RAII guard for the per-stream reentrant console lock. Acquires on -/// construction (incrementing the thread-local count and locking the global -/// mutex on first entry), releases on `Drop` (decrementing and unlocking on -/// last exit). -struct ConsoleStreamLock { - use_stderr: bool, -} - -impl ConsoleStreamLock { - fn acquire(use_stderr: bool) -> Self { - if use_stderr { - STDERR_LOCK_COUNT.with(|c| { - if c.get() == 0 { - STDERR_MUTEX.lock(); - } - c.set(c.get() + 1); - }); - } else { - STDOUT_LOCK_COUNT.with(|c| { - if c.get() == 0 { - STDOUT_MUTEX.lock(); - } - c.set(c.get() + 1); - }); - } - Self { use_stderr } - } -} - -impl Drop for ConsoleStreamLock { - fn drop(&mut self) { - if self.use_stderr { - STDERR_LOCK_COUNT.with(|c| { - c.set(c.get() - 1); - if c.get() == 0 { - STDERR_MUTEX.unlock(); - } - }); - } else { - STDOUT_LOCK_COUNT.with(|c| { - c.set(c.get() - 1); - if c.get() == 0 { - STDOUT_MUTEX.unlock(); - } - }); - } - } -} - /// RAII flush of a borrowed `bun_io::Write` at scope exit when `enabled`. /// /// Owns the `&mut dyn Write` for its lifetime; the body of the scope must @@ -405,60 +573,32 @@ fn message_with_type_and_level_( return Ok(()); } - // Lock/unlock a mutex incase two JS threads are console.log'ing at the same - // time. We do this the slightly annoying way to avoid assigning a pointer. - let use_stderr = matches!(level, MessageLevel::Warning | MessageLevel::Error) - || message_type == MessageType::Assert; - let _stream_lock = ConsoleStreamLock::acquire(use_stderr); + let stream = ConsoleStream::for_message(message_type, level); if message_type == MessageType::Clear { - Output::reset_terminal(); - return Ok(()); - } - - if message_type == MessageType::Assert && len == 0 { - let text: &str = if Output::enable_ansi_colors_stderr() { - pfmt!("Assertion failed\n", true) + // Node: only when `this._stdout.isTTY`, `cursorTo(0, 0)` + `clearScreenDown()`. + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L487-L501 + let mut threw = false; + // SAFETY: plain FFI; `threw` is its throw contract. + let stream_object = unsafe { Bun__Process__consoleStreamObject(global, 1, &mut threw) }; + if threw { + return Err(JsError::Thrown); + } + let is_tty = if stream_object.is_empty() { + Output::is_stdout_tty() } else { - "Assertion failed\n" + stream_object + .get(global, b"isTTY")? + .is_some_and(|v| v.to_boolean()) }; - // SAFETY: no other borrow of the console is live in this - // early-return arm (the deferred `_indent_guard` only holds the raw - // pointer, not a reference). - let ew = unsafe { vm_console_mut(global) }.error_writer(); - let _ = ew.write_all(text.as_bytes()); - let _ = ew.flush(); + if is_tty && bun_core::env_var::TERM::get().is_none_or(|t| t != b"dumb") { + return deliver(global, ConsoleStream::Stdout, b"\x1b[1;1H\x1b[0J"); + } return Ok(()); } - let enable_colors = if matches!(level, MessageLevel::Warning | MessageLevel::Error) { - Output::enable_ansi_colors_stderr() - } else { - Output::enable_ansi_colors_stdout() - }; - - // Snapshot before borrowing the writer; `default_indent` is not mutated - // again until the deferred `_indent_guard` runs on scope exit, so the two - // later reads (FormatOptions / TablePrinter) can use this cached copy - // instead of re-dereferencing the raw `console` pointer. // SAFETY: see [`vm_console`] — single-JS-thread; no other `&mut` is live. - let default_indent = unsafe { vm_console_mut(global) }.default_indent; - - // SAFETY: see [`vm_console`] — `console` points at the live boxed - // `ConsoleObject` for this VM; JS-thread-only. Kept as a raw deref (not - // `vm_console_mut`) so the resulting `writer` borrow does not pin a - // long-lived `&mut ConsoleObject` across the re-derive in the empty-`Log` - // arm below. - let raw_writer: &mut bun_core::io::Writer = unsafe { - if matches!(level, MessageLevel::Warning | MessageLevel::Error) { - (*console).error_writer() - } else { - (*console).writer() - } - }; - // `bun_core::io::Writer: bun_io::Write` — `&mut Writer` unsize-coerces directly. - let writer: &mut dyn bun_io::Write = raw_writer; - + let default_indent = unsafe { (*console).default_indent }; // LAYERING: `Jest::runner()` lives in `bun_runtime::test_runner` (forward // dep on the high tier). Dispatch through `RuntimeHooks` instead — the // high-tier hook checks `Jest.runner` and calls `onBeforePrint()`; no-op @@ -467,96 +607,112 @@ fn message_with_type_and_level_( (hooks.console_on_before_print)(); } - let mut print_length = len; - // Get console depth from CLI options or bunfig, fallback to default. - let console_depth = bun_options_types::context::try_get() - .and_then(|ctx| ctx.runtime_options.console_depth) - .unwrap_or(DEFAULT_CONSOLE_LOG_DEPTH); - - let mut print_options = FormatOptions { - enable_colors, - add_newline: true, - flush: true, - default_indent, - max_depth: console_depth, - error_display_level: match level { - MessageLevel::Error => ErrorDisplayLevel::Full, - MessageLevel::Warning => ErrorDisplayLevel::Warn, - _ => ErrorDisplayLevel::Normal, - }, - ..FormatOptions::default() - }; - // SAFETY: caller (JSC C++) guarantees `vals` points to `len` JSValues. let vals_slice = unsafe { bun_core::ffi::slice(vals, len) }; - if message_type == MessageType::Table && len >= 1 { - // if value is not an object/array/iterable, don't print a table and just print it - let tabular_data = vals_slice[0]; - if tabular_data.is_object() { - let properties: JSValue = if len >= 2 && vals_slice[1].js_type().is_array() { - vals_slice[1] - } else { - JSValue::UNDEFINED + emit(global, stream, |writer, enable_colors| { + if message_type == MessageType::Assert { + // Node prefixes the first argument and forwards to `warn`, so the + // prefix takes part in the same `%s` substitution pass: + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L474-L485 + let first_is_string = len > 0 && vals_slice[0].is_string(); + let text: &str = match (len == 0, first_is_string, enable_colors) { + (true, _, true) => pfmt!("Assertion failed\n", true), + (true, _, false) => "Assertion failed\n", + // `Assertion failed: ${args[0]}` when it's a string, + (false, true, true) => pfmt!("Assertion failed: ", true), + (false, true, false) => "Assertion failed: ", + // else 'Assertion failed' is unshifted as its own argument. + (false, false, true) => pfmt!("Assertion failed ", true), + (false, false, false) => "Assertion failed ", }; - let mut table_printer = TablePrinter::init(global, level, tabular_data, properties)?; - table_printer.value_formatter.indent += u32::from(default_indent); - - if enable_colors { - let _ = table_printer.print_table::(writer); - } else { - let _ = table_printer.print_table::(writer); + let _ = writer.write_all(text.as_bytes()); + if len == 0 { + return Ok(()); } - let _ = writer.flush(); - return Ok(()); } - } - if message_type == MessageType::Dir && len >= 2 { - print_length = 1; - let opts = vals_slice[1]; - if opts.is_object() { - if let Some(depth_prop) = opts.get(global, b"depth")? { - if depth_prop.is_int32() || depth_prop.is_number() || depth_prop.is_big_int() { - // Clamp negatives to 0, then truncate (not saturate) to u16. - print_options.max_depth = depth_prop.to_int32().max(0) as u32 as u16; - } else if depth_prop.is_null() { - print_options.max_depth = u16::MAX; + let mut print_length = len; + // Get console depth from CLI options or bunfig, fallback to default. + let console_depth = bun_options_types::context::try_get() + .and_then(|ctx| ctx.runtime_options.console_depth) + .unwrap_or(DEFAULT_CONSOLE_LOG_DEPTH); + + let mut print_options = FormatOptions { + enable_colors, + add_newline: true, + flush: false, + default_indent, + max_depth: console_depth, + error_display_level: match level { + MessageLevel::Error => ErrorDisplayLevel::Full, + MessageLevel::Warning => ErrorDisplayLevel::Warn, + _ => ErrorDisplayLevel::Normal, + }, + ..FormatOptions::default() + }; + + if message_type == MessageType::Table && len >= 1 { + // if value is not an object/array/iterable, don't print a table and just print it + let tabular_data = vals_slice[0]; + if tabular_data.is_object() { + let properties: JSValue = if len >= 2 && vals_slice[1].js_type().is_array() { + vals_slice[1] + } else { + JSValue::UNDEFINED + }; + let mut table_printer = + TablePrinter::init(global, level, tabular_data, properties)?; + table_printer.value_formatter.indent += u32::from(default_indent); + + if enable_colors { + let _ = table_printer.print_table::(writer); + } else { + let _ = table_printer.print_table::(writer); } + return Ok(()); } - if let Some(colors_prop) = opts.get(global, b"colors")? { - if colors_prop.is_boolean() { - print_options.enable_colors = colors_prop.to_boolean(); + } + + if message_type == MessageType::Dir && len >= 2 { + print_length = 1; + let opts = vals_slice[1]; + if opts.is_object() { + if let Some(depth_prop) = opts.get(global, b"depth")? { + if depth_prop.is_int32() || depth_prop.is_number() || depth_prop.is_big_int() { + // Clamp negatives to 0, then truncate (not saturate) to u16. + print_options.max_depth = depth_prop.to_int32().max(0) as u32 as u16; + } else if depth_prop.is_null() { + print_options.max_depth = u16::MAX; + } + } + if let Some(colors_prop) = opts.get(global, b"colors")? { + if colors_prop.is_boolean() { + print_options.enable_colors = colors_prop.to_boolean(); + } } } } - } - - if print_length > 0 { - format2( - level, - global, - &vals_slice[..print_length], - writer, - print_options, - )?; - } else if message_type == MessageType::Log { - // SAFETY: see [`vm_console`]. `writer` (above) is dead in this arm — - // the only later uses are in the mutually-exclusive `Trace` block, and - // `message_type == Log` here. - let w = unsafe { (*console).writer() }; - let _ = w.write_all(b"\n"); - let _ = w.flush(); - } else if message_type != MessageType::Trace { - let _ = writer.write_all(b"undefined\n"); - } - if message_type == MessageType::Trace { - write_trace(writer, global); - let _ = writer.flush(); - } + if print_length > 0 { + format2( + level, + global, + &vals_slice[..print_length], + writer, + print_options, + )?; + } else if message_type == MessageType::Log { + let _ = writer.write_all(b"\n"); + } else if message_type != MessageType::Trace { + let _ = writer.write_all(b"undefined\n"); + } - Ok(()) + if message_type == MessageType::Trace { + write_trace(writer, global); + } + Ok(()) + }) } // ─────────────────────────────────────────────────────────────────────────── @@ -5791,37 +5947,41 @@ pub(crate) extern "C" fn Bun__ConsoleObject__count( ptr: *const u8, len: usize, ) { - // SAFETY: top-level JS-thread host call ⇒ exclusive access to the - // set-once `VirtualMachine.console` box. - let this = unsafe { vm_console_mut(global_this) }; // SAFETY: caller passes a valid (ptr, len) pair. let slice = unsafe { bun_core::ffi::slice(ptr, len) }; let hash = bun_wyhash::hash(slice); - // we don't want to store these strings, it will take too much memory - let counter = this.counts.get_or_put(hash).expect("unreachable"); - let current: u32 = if counter.found_existing { - *counter.value_ptr - } else { - 0 - } + 1; - *counter.value_ptr = current; - - let writer = this.writer(); - if Output::enable_ansi_colors_stdout() { - let _ = writeln!( - writer, - "{}{}{}: {}{}{}", - pfmt!("", true), - bstr::BStr::new(slice), - pfmt!("", true), - pfmt!("", true), - current, - pfmt!("", true), - ); - } else { - let _ = writeln!(writer, "{}: {}", bstr::BStr::new(slice), current); - } - let _ = writer.flush(); + let current: u32 = { + // SAFETY: top-level JS-thread host call ⇒ exclusive access to the + // set-once `VirtualMachine.console` box; borrow ends before `emit`. + let this = unsafe { vm_console_mut(global_this) }; + // we don't want to store these strings, it will take too much memory + let counter = this.counts.get_or_put(hash).expect("unreachable"); + let current = if counter.found_existing { + *counter.value_ptr + } else { + 0 + } + 1; + *counter.value_ptr = current; + current + }; + + let _ = emit(global_this, ConsoleStream::Stdout, |writer, colors| { + if colors { + let _ = writeln!( + writer, + "{}{}{}: {}{}{}", + pfmt!("", true), + bstr::BStr::new(slice), + pfmt!("", true), + pfmt!("", true), + current, + pfmt!("", true), + ); + } else { + let _ = writeln!(writer, "{}: {}", bstr::BStr::new(slice), current); + } + Ok(()) + }); } #[unsafe(no_mangle)] @@ -5850,60 +6010,193 @@ thread_local! { static PENDING_TIME_LOGS_LOADED: Cell = const { Cell::new(false) }; } +/// `process.emitWarning(text)` for the console timers, as Node does; a +/// failure to warn is not the caller's problem. +fn console_warn(global: &JSGlobalObject, args: core::fmt::Arguments<'_>) { + let text = OwnedString::new(BunString::create_format(args)); + let Ok(js) = text.to_js(global) else { + return; + }; + let _ = global.emit_warning( + js, + JSValue::UNDEFINED, + JSValue::UNDEFINED, + JSValue::UNDEFINED, + ); +} + +/// Node's `formatTime` for `console.timeLog` / `console.timeEnd`. +/// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/util/debuglog.js#L155-L187 +fn write_elapsed(writer: &mut dyn bun_io::Write, mut ms: f64) { + const SECOND: f64 = 1000.0; + const MINUTE: f64 = 60.0 * SECOND; + const HOUR: f64 = 60.0 * MINUTE; + + let mut hours = 0u64; + let mut minutes = 0u64; + let mut seconds = 0.0f64; + if ms >= SECOND { + if ms >= MINUTE { + if ms >= HOUR { + hours = (ms / HOUR).floor() as u64; + ms %= HOUR; + } + minutes = (ms / MINUTE).floor() as u64; + ms %= MINUTE; + } + seconds = ms / SECOND; + } + + if hours != 0 || minutes != 0 { + // `seconds.toFixed(3)` split on '.' → zero-padded whole seconds + millis. + let whole = seconds.trunc() as u64; + let mut millis = ((seconds - seconds.trunc()) * 1000.0).round() as u64; + let mut whole = whole; + if millis == 1000 { + millis = 0; + whole += 1; + } + if hours != 0 { + let _ = write!( + writer, + "{}:{:02}:{:02}.{:03} (h:mm:ss.mmm)", + hours, minutes, whole, millis + ); + } else { + let _ = write!(writer, "{}:{:02}.{:03} (m:ss.mmm)", minutes, whole, millis); + } + return; + } + + if seconds != 0.0 { + let _ = write!(writer, "{:.3}s", seconds); + return; + } + + // `Number(ms.toFixed(3))`: round to three decimals, print as a JS number. + let _ = write!( + writer, + "{}ms", + bun_core::fmt::double((ms * 1000.0).round() / 1000.0) + ); +} + #[unsafe(no_mangle)] #[crate::host_call] pub(crate) extern "C" fn Bun__ConsoleObject__time( _console: *mut ConsoleObject, - _global: &JSGlobalObject, + global: &JSGlobalObject, chars: *const u8, len: usize, ) { // SAFETY: caller passes a valid (ptr, len) pair. - let id = bun_wyhash::hash(unsafe { bun_core::ffi::slice(chars, len) }); + let label = unsafe { bun_core::ffi::slice(chars, len) }; + let id = bun_wyhash::hash(label); if !PENDING_TIME_LOGS_LOADED.with(|c| c.get()) { PENDING_TIME_LOGS.with_borrow_mut(|m| *m = PendingTimers::default()); PENDING_TIME_LOGS_LOADED.with(|c| c.set(true)); } - PENDING_TIME_LOGS.with_borrow_mut(|map| { + let existed = PENDING_TIME_LOGS.with_borrow_mut(|map| { let result = map.get_or_put(id).expect("unreachable"); if !result.found_existing || result.value_ptr.is_none() { *result.value_ptr = Some(bun_core::time::Timer::start()); + false + } else { + true } }); + if existed { + console_warn( + global, + format_args!( + "Label '{}' already exists for console.time()", + bstr::BStr::new(label) + ), + ); + } +} + +/// Shared tail of `timeEnd` / `timeLog`: `label: [ ...args]\n` on +/// stdout, exactly what Node's `timeLogImpl` → `console.log('%s: %s', ...)` +/// prints. +fn time_log_impl( + global: &JSGlobalObject, + implementation: &str, + label: &[u8], + take: bool, + args: &[JSValue], +) { + if !PENDING_TIME_LOGS_LOADED.with(|c| c.get()) { + console_warn( + global, + format_args!( + "No such label '{}' for {}", + bstr::BStr::new(label), + implementation + ), + ); + return; + } + let id = bun_wyhash::hash(label); + let timer = PENDING_TIME_LOGS.with_borrow_mut(|m| match m.get_mut(&id) { + Some(slot) if take => slot.take(), + Some(slot) => *slot, + None => None, + }); + let Some(timer) = timer else { + console_warn( + global, + format_args!( + "No such label '{}' for {}", + bstr::BStr::new(label), + implementation + ), + ); + return; + }; + let ms = timer.read() as f64 / bun_core::time::NS_PER_MS as f64; + + let _ = emit(global, ConsoleStream::Stdout, |writer, colors| { + let _ = writer.write_all(label); + let _ = writer.write_all(b": "); + write_elapsed(writer, ms); + + if !args.is_empty() { + // `Formatter` has a `Drop` impl, so struct-update from a + // temporary is rejected (E0509). Construct via `new()` then mutate. + let mut fmt = Formatter::new(global); + fmt.max_depth = bun_options_types::context::try_get() + .and_then(|ctx| ctx.runtime_options.console_depth) + .unwrap_or(DEFAULT_CONSOLE_LOG_DEPTH); + fmt.stack_check = StackCheck::init(); + fmt.can_throw_stack_overflow = true; + for &arg in args { + let tag = formatter::Tag::get(arg, global)?; + let _ = writer.write_all(b" "); + if colors { + fmt.format::(tag, writer, arg, global)?; + } else { + fmt.format::(tag, writer, arg, global)?; + } + } + } + let _ = writer.write_all(b"\n"); + Ok(()) + }); } #[unsafe(no_mangle)] #[crate::host_call] pub(crate) extern "C" fn Bun__ConsoleObject__timeEnd( _console: *mut ConsoleObject, - _global: &JSGlobalObject, + global: &JSGlobalObject, chars: *const u8, len: usize, ) { - if !PENDING_TIME_LOGS_LOADED.with(|c| c.get()) { - return; - } - // SAFETY: caller passes a valid (ptr, len) pair. - let slice = unsafe { bun_core::ffi::slice(chars, len) }; - let id = bun_wyhash::hash(slice); - // Replace the slot with `None`, returning the previous value. - let Some(prev) = PENDING_TIME_LOGS.with_borrow_mut(|m| m.get_mut(&id).map(|slot| slot.take())) - else { - return; - }; - let Some(value) = prev else { return }; - // get the duration in microseconds, then display it in milliseconds - Output::print_elapsed( - (value.read() / bun_core::time::NS_PER_US) as f64 / bun_core::time::US_PER_MS as f64, - ); - match len { - 0 => Output::print_errorln(format_args!("")), - _ => Output::print_errorln(format_args!(" {}", bstr::BStr::new(slice))), - } - - Output::flush(); + let label = unsafe { bun_core::ffi::slice(chars, len) }; + time_log_impl(global, "console.timeEnd()", label, true, &[]); } #[unsafe(no_mangle)] @@ -5916,55 +6209,11 @@ pub(crate) extern "C" fn Bun__ConsoleObject__timeLog( args: *const JSValue, args_len: usize, ) { - if !PENDING_TIME_LOGS_LOADED.with(|c| c.get()) { - return; - } - - // SAFETY: caller passes a valid (ptr, len) pair. - let slice = unsafe { bun_core::ffi::slice(chars, len) }; - let id = bun_wyhash::hash(slice); - let Some(Some(value)) = PENDING_TIME_LOGS.with_borrow(|m| m.get(&id).copied()) else { - return; - }; - // get the duration in microseconds, then display it in milliseconds - Output::print_elapsed( - (value.read() / bun_core::time::NS_PER_US) as f64 / bun_core::time::US_PER_MS as f64, - ); - match len { - 0 => {} - _ => Output::print_error(format_args!(" {}", bstr::BStr::new(slice))), - } - Output::flush(); - - // print the arguments - // `Formatter` has a `Drop` impl, so struct-update from a - // temporary is rejected (E0509). Construct via `new()` then mutate. - let mut fmt = Formatter::new(global); - fmt.max_depth = bun_options_types::context::try_get() - .and_then(|ctx| ctx.runtime_options.console_depth) - .unwrap_or(DEFAULT_CONSOLE_LOG_DEPTH); - fmt.stack_check = StackCheck::init(); - fmt.can_throw_stack_overflow = true; - let console = vm_console(global); - // SAFETY: see [`vm_console`] — points at the live boxed `ConsoleObject` for - // this VM; JS-thread-only. Kept as a raw deref (not `vm_console_mut`) so the - // resulting `writer` borrow does not pin a long-lived `&mut ConsoleObject` - // across the `fmt.format(...)` calls below, which can re-enter JS. - let mut writer = unsafe { (*console).error_writer() }; - // SAFETY: caller passes a valid (args, args_len) pair. - for &arg in unsafe { bun_core::ffi::slice(args, args_len) } { - let Ok(tag) = formatter::Tag::get(arg, global) else { - return; - }; - let _ = bun_io::Write::write_all(&mut writer, b" "); - if Output::enable_ansi_colors_stderr() { - let _ = fmt.format::(tag, &mut writer, arg, global); - } else { - let _ = fmt.format::(tag, &mut writer, arg, global); - } - } - let _ = bun_io::Write::write_all(&mut writer, b"\n"); - let _ = bun_io::Write::flush(&mut writer); + // SAFETY: caller passes valid (ptr, len) pairs. + let label = unsafe { bun_core::ffi::slice(chars, len) }; + // SAFETY: as above. + let args = unsafe { bun_core::ffi::slice(args, args_len) }; + time_log_impl(global, "console.timeLog()", label, false, args); } /// Stamp out the empty `Bun__ConsoleObject__*` C-ABI hooks that JSC's diff --git a/src/jsc/VirtualMachine.rs b/src/jsc/VirtualMachine.rs index 0ee8a9c4075e..b90dcee9c962 100644 --- a/src/jsc/VirtualMachine.rs +++ b/src/jsc/VirtualMachine.rs @@ -404,6 +404,9 @@ unsafe extern "C" { safe fn Zig__GlobalObject__stopActiveDOMObjectsForTestIsolation(global: &JSGlobalObject); safe fn Zig__GlobalObject__destructOnExit(global: &JSGlobalObject); safe fn WebWorker__teardownJSCVM(global: &JSGlobalObject); + /// `BunProcess.cpp`: signals that were only forwarded to JS listeners go + /// back to `SIG_DFL` (no-op on Windows). + safe fn bun_reset_signal_handlers_for_exit(); } bun_core::define_scoped_log!(teardown_log, Worker, hidden); @@ -1599,6 +1602,40 @@ impl VirtualMachine { } } + /// Synchronously flush this VM's stdio sinks (fd 1/2). No-op when they were + /// never created. Called before anything that must not overtake or discard + /// already-accepted `process.stdout`/`stderr` bytes: fatal-error printing + /// and exit. + #[inline] + pub fn drain_stdio(&mut self) { + if self + .rare_data + .as_ref() + .is_some_and(|r| r.stdio_sinks.iter().any(Option::is_some)) + { + let vm = core::ptr::from_mut::(self); + // SAFETY: `vm` is the live per-thread VM; no `&mut` is held across the call. + unsafe { crate::rare_data::__bun_stdio_sink_drain(vm) }; + } + } + + /// The exit-time drain. JS will not run again, so its signal listeners + /// can't either: hand the signals they had claimed back to their defaults + /// first (cf. Node's `ResetSignalHandlers` at teardown) so that waiting on + /// a reader that never reads stays killable the ordinary way. + fn drain_stdio_for_exit(&mut self) { + if self + .rare_data + .as_ref() + .is_some_and(|r| r.stdio_sinks.iter().any(Option::is_some)) + { + if self.is_main_thread() { + bun_reset_signal_handlers_for_exit(); + } + self.drain_stdio(); + } + } + pub fn on_exit(&mut self) { // Decide once whether the exit sequence may run script. It can be // entered with an exception pending: `process.exit()` from inside a @@ -1650,6 +1687,11 @@ impl VirtualMachine { self.is_inside_deferred_task_queue.set(false); } + // Whatever process.stdout/stderr still had queued behind a slow reader + // is written now (blocking), like console.log always has been: an exit + // must not silently truncate output that was accepted before it. + self.drain_stdio_for_exit(); + self.is_shutting_down = true; // Make sure we run new cleanup hooks introduced by running cleanup @@ -1681,6 +1723,9 @@ impl VirtualMachine { pub fn global_exit(&mut self) -> ! { debug_assert!(self.is_shutting_down()); + // Paths that get here without `on_exit()` (early CLI/test-runner + // exits) still owe the fd whatever process.stdout/stderr queued. + self.drain_stdio_for_exit(); // FIXME: we should be doing this, but we're not, but unfortunately // doing it causes like 50+ tests to break // self.event_loop().tick(); @@ -2382,20 +2427,8 @@ impl VirtualMachine { MAIN_THREAD_VM.store(vm, core::sync::atomic::Ordering::Release); } - // ConsoleObject is self-referential (buffers + adapters) — allocate - // stable storage and init in place. - // `console.init(Output.rawErrorWriter(), Output.rawWriter())` must - // happen BEFORE the pointer is stored/passed; the previous port left - // it as raw `MaybeUninit` (UB on first C++ read). - let mut console_box: Box> = - Box::new(core::mem::MaybeUninit::uninit()); - crate::console_object::ConsoleObject::init_in_place( - &mut console_box, - bun_core::Output::raw_error_writer(), - bun_core::Output::raw_writer(), - ); let console = - bun_core::heap::into_raw(console_box).cast::(); + bun_core::heap::into_raw(Box::new(crate::console_object::ConsoleObject::new())); let context_id = opts .context_id @@ -4688,6 +4721,12 @@ impl VirtualMachine { } /// Worker-thread teardown. pub fn destroy(&mut self) { + // Stdio sinks need the loop (poll teardown) and `RareData.file_polls`; + // the usual exit paths released them in `release_js_handles()` already, + // this covers VMs torn down directly (e.g. `bun build`'s bake VM). + if let Some(rare) = self.rare_data.as_deref_mut() { + rare.release_stdio_sinks(); + } self.regular_event_loop.deinit(); self.macro_event_loop.deinit(); // The VM's own clone of its handle; the shared inner is freed when the @@ -5020,6 +5059,17 @@ impl VirtualMachine { }; } } + // The stdio sinks carry over (they own the fd state); their JS wrapper + // belongs to the outgoing global and must not. + if self + .rare_data + .as_ref() + .is_some_and(|r| r.stdio_sinks.iter().any(Option::is_some)) + { + let vm = core::ptr::from_mut::(self); + // SAFETY: `vm` is the live per-thread VM; no `&mut` is held across the call. + unsafe { crate::rare_data::__bun_stdio_sink_release_js(vm) }; + } if let Some(rare) = self.rare_data.as_deref_mut() { rare.listening_sockets_for_watch_mode.lock().clear(); // `setCallbacks` is once-only (node/src/quic/bindingdata.cc diff --git a/src/jsc/bindings/BunProcess.cpp b/src/jsc/bindings/BunProcess.cpp index ce39ea85cff8..7771d2dce3fa 100644 --- a/src/jsc/bindings/BunProcess.cpp +++ b/src/jsc/bindings/BunProcess.cpp @@ -873,6 +873,19 @@ extern "C" void Process__dispatchOnBeforeExit(Zig::GlobalObject* globalObject, u } } +// Run an internal builtin whose failure is not the caller's to propagate: a +// throw is reported like any other uncaught exception. +static void callReportingException(Zig::GlobalObject* globalObject, JSFunction* fn, const MarkedArgumentBuffer& args) +{ + auto& vm = JSC::getVM(globalObject); + auto scope = DECLARE_TOP_EXCEPTION_SCOPE(vm); + JSC::call(globalObject, fn, JSC::getCallData(fn), jsUndefined(), args); + if (auto* exception = scope.exception()) [[unlikely]] { + (void)scope.tryClearException(); + Zig::GlobalObject::reportUncaughtExceptionAtEventLoop(globalObject, exception); + } +} + extern "C" void Process__dispatchOnExit(Zig::GlobalObject* globalObject, uint8_t exitCode) { if (!globalObject->hasProcessObject()) { @@ -883,6 +896,24 @@ extern "C" void Process__dispatchOnExit(Zig::GlobalObject* globalObject, uint8_t if (exitCode > 0) process->m_isExitCodeObservable = true; dispatchExitInternal(globalObject, process, exitCode); + + // 'exit' handlers may still write; after them, move whatever the stdio + // Writables have queued in JS into the native sinks so the exit drain + // (FileSink::drain_sync) delivers it. Only for streams that exist. + auto& vm = JSC::getVM(globalObject); + if (vm.hasTerminationRequest() || vm.hasExceptionsAfterHandlingTraps()) + return; + JSFunction* flush = nullptr; + for (int fd = 1; fd <= 2; ++fd) { + JSObject* stream = process->stdioStream(fd); + if (!stream) + continue; + if (!flush) + flush = JSFunction::create(vm, globalObject, processObjectInternalsFlushStdioWriteStreamOnExitCodeGenerator(vm), globalObject); + MarkedArgumentBuffer args; + args.append(stream); + callReportingException(globalObject, flush, args); + } } JSC_DEFINE_HOST_FUNCTION(Process_functionUptime, (JSC::JSGlobalObject * lexicalGlobalObject, JSC::CallFrame* callFrame)) @@ -1569,6 +1600,32 @@ extern "C" void Bun__installWatchModeSignalHandler(int signalNumber) } #endif +// At exit, once JS can no longer run, a signal that was only being forwarded +// to `process.on(...)` listeners would be swallowed; give those (and only +// those — not JSC's thread-suspend signal, our stdio-restore handler, or an +// inherited SIG_IGN) back their default action so a process still writing out +// the last of its stdio stays killable with ^C / SIGTERM. (Node resets every +// signal here: ResetSignalHandlers.) +extern "C" void bun_reset_signal_handlers_for_exit() +{ +#if !OS(WINDOWS) + for (int nr = 1; nr < NSIG; nr++) { + if (nr == SIGKILL || nr == SIGSTOP) + continue; + struct sigaction current; + if (sigaction(nr, nullptr, ¤t) != 0) + continue; + if ((current.sa_flags & SA_SIGINFO) || current.sa_handler != forwardSignal) + continue; + struct sigaction dfl; + memset(&dfl, 0, sizeof(dfl)); + dfl.sa_handler = SIG_DFL; + sigemptyset(&dfl.sa_mask); + sigaction(nr, &dfl, nullptr); + } +#endif +} + extern "C" void Bun__MemoryPressure__install(JSC::JSGlobalObject* global); extern "C" void Bun__MemoryPressure__uninstall(JSC::JSGlobalObject* global); @@ -1862,6 +1919,8 @@ struct ExecveCloexecRestorer { }; #endif +extern "C" void bun_restore_stdio(); + JSC_DEFINE_HOST_FUNCTION(Process_functionExecve, (JSGlobalObject * lexicalGlobalObject, CallFrame* callFrame)) { Zig::GlobalObject* globalObject = defaultGlobalObject(lexicalGlobalObject); @@ -2015,6 +2074,10 @@ JSC_DEFINE_HOST_FUNCTION(Process_functionExecve, (JSGlobalObject * lexicalGlobal } } + // The new image gets our stdio; hand it over in the state we found it + // (termios, O_NONBLOCK), exactly as a normal exit would. + bun_restore_stdio(); + int savedErrno; #if OS(DARWIN) @@ -2885,7 +2948,6 @@ enum class BunProcessStdinFdType : int32_t { }; extern "C" BunProcessStdinFdType Bun__Process__getStdinFdType(void*, int fd); -extern "C" void Bun__ForceFileSinkToBeSynchronousForProcessObjectStdio(JSC::JSGlobalObject*, JSC::EncodedJSValue); static JSValue constructStdioWriteStream(JSC::JSGlobalObject* globalObject, JSC::JSObject* processObject, int fd) { auto& vm = JSC::getVM(globalObject); @@ -2908,31 +2970,245 @@ static JSValue constructStdioWriteStream(JSC::JSGlobalObject* globalObject, JSC: return jsUndefined(); } - ASSERT_WITH_MESSAGE(JSC::isJSArray(result), "Expected an array from getStdioWriteStream"); - JSC::JSArray* resultObject = uncheckedDowncast(result); + // Everything about how bytes reach fd 1/2 (sync vs. queued, fd flags, + // ordering against console.*) is decided by the per-VM stdio FileSink the + // stream was built over; see FileSink::create_stdio. + if (JSObject* streamObject = result.getObject()) + uncheckedDowncast(processObject)->setStdioStream(vm, fd, streamObject); + return result; +} - // process.stdout and process.stderr differ from other Node.js streams in important ways: - // 1. They are used internally by console.log() and console.error(), respectively. - // 2. Writes may be synchronous depending on what the stream is connected to and whether the system is Windows or POSIX: - // Files: synchronous on Windows and POSIX - // TTYs (Terminals): asynchronous on Windows, synchronous on POSIX - // Pipes (and sockets): synchronous on Windows, asynchronous on POSIX - bool forceSync = false; -#if OS(WINDOWS) - forceSync = fdType == BunProcessStdinFdType::file || fdType == BunProcessStdinFdType::pipe; -#else - // Note: files are always sync anyway. - // forceSync = fdType == BunProcessStdinFdType::file || bun_stdio_tty[fd]; +void Process::setStdioStream(JSC::VM& vm, int fd, JSObject* stream) +{ + ASSERT(fd == 1 || fd == 2); + unsigned slot = static_cast(fd) - 1; + m_stdioStream[slot].set(vm, this, stream); + m_stdioPristineStructureID[slot] = stream->structureID(); + // The O(1) "is `write` still ours" test in consoleStream() is a structure + // compare, which only works if a pristine stream has no *own* `write` + // (adding one transitions the structure). See internal/fs/streams.ts. + ASSERT_WITH_MESSAGE(stream->getDirectOffset(vm, WebCore::builtinNames(vm).writePublicName()) == invalidOffset, "stdio stream must inherit write() from its prototype"); +} - // TODO: once console.* is wired up to write/read through the same buffering mechanism as FileSink for process.stdout, process.stderr, we can make this non-blocking for sockets on POSIX. - // Until then, we have to force it to be sync EVEN for sockets or else console.log() may flush at a different time than process.stdout.write. - forceSync = true; -#endif - if (forceSync) { - Bun__ForceFileSinkToBeSynchronousForProcessObjectStdio(globalObject, JSValue::encode(resultObject->getIndex(globalObject, 1))); +void Process::setConsoleStream(JSC::VM& vm, int fd, JSValue value) +{ + ASSERT(fd == 1 || fd == 2); + unsigned slot = static_cast(fd) - 1; + if (value.isEmpty() || value.isUndefined() || (m_stdioStream[slot] && value == m_stdioStream[slot].get())) { + // Rebinding to Bun's own stream (or clearing) puts the fast path back. + m_consoleStreamState[slot] = ConsoleStreamState::Native; + m_consoleStream[slot].clear(); + return; } + m_consoleStreamState[slot] = ConsoleStreamState::Custom; + m_consoleStream[slot].set(vm, this, value); +} - return resultObject->getIndex(globalObject, 0); +JSValue Process::consoleStream(JSC::JSGlobalObject* globalObject, int fd) +{ + ASSERT(fd == 1 || fd == 2); + unsigned slot = static_cast(fd) - 1; + auto& vm = JSC::getVM(globalObject); + + switch (m_consoleStreamState[slot]) { + case ConsoleStreamState::Custom: + return m_consoleStream[slot].get(); + case ConsoleStreamState::Unresolved: { + // Node binds `console._stdout` to `process.stdout` on first use and + // caches it. If nobody has touched `process.stdout` yet the lazy + // property is unreified and would produce our own stream, so bind + // native *without* building the JS object; if user code already put + // something else there, that is what the console is bound to for good. + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L205-L234 + const Identifier& name = fd == 1 ? WebCore::builtinNames(vm).stdoutPublicName() : WebCore::builtinNames(vm).stderrPublicName(); + unsigned attributes = 0; + JSValue existing; + if (invalidOffset != structure()->get(vm, name, attributes)) { + if (attributes & PropertyAttribute::Accessor) { + // `Object.defineProperty(process, "stdout", { get })`: do the + // one [[Get]] Node's lazy binding would. May throw. + auto scope = DECLARE_THROW_SCOPE(vm); + existing = get(globalObject, name); + RETURN_IF_EXCEPTION(scope, {}); + } else { + existing = getDirect(vm, name); + } + } + if (existing && existing.isObject() && (!m_stdioStream[slot] || existing != m_stdioStream[slot].get())) { + m_consoleStreamState[slot] = ConsoleStreamState::Custom; + m_consoleStream[slot].set(vm, this, existing); + return existing; + } + m_consoleStreamState[slot] = ConsoleStreamState::Native; + [[fallthrough]]; + } + case ConsoleStreamState::Native: { + JSObject* stream = m_stdioStream[slot].get(); + if (!stream) + return {}; // never materialised: nothing can be observing it + if (m_stdioObserved[slot]) + return stream; + // A dictionary structure no longer changes ID per added property, so + // it can't vouch for "no own write" — look every time (still O(1)). + if (stream->structureID() == m_stdioPristineStructureID[slot] && !stream->structure()->isDictionary()) [[likely]] + return {}; + // Some own property was added/removed. If it wasn't `write`, adopt the + // new structure as pristine so the next call is one compare again. + if (stream->getDirectOffset(vm, WebCore::builtinNames(vm).writePublicName()) != invalidOffset) + return stream; + m_stdioPristineStructureID[slot] = stream->structureID(); + return {}; + } + } + return {}; +} + +JSValue Process::consoleStreamForGetter(JSC::JSGlobalObject* globalObject, int fd) +{ + ASSERT(fd == 1 || fd == 2); + unsigned slot = static_cast(fd) - 1; + auto& vm = JSC::getVM(globalObject); + auto scope = DECLARE_THROW_SCOPE(vm); + if (m_consoleStreamState[slot] == ConsoleStreamState::Unresolved) { + (void)consoleStream(globalObject, fd); + RETURN_IF_EXCEPTION(scope, {}); + } + if (m_consoleStreamState[slot] == ConsoleStreamState::Custom) + RELEASE_AND_RETURN(scope, m_consoleStream[slot].get()); + // Native: the real stream object (materialising it is fine here — the + // caller asked for it by name). + RELEASE_AND_RETURN(scope, get(globalObject, fd == 1 ? WebCore::builtinNames(vm).stdoutPublicName() : WebCore::builtinNames(vm).stderrPublicName())); +} + +// Whether the console's stream for `fd` is a *foreign* object (worker port +// stream, `console._stdout = x`, a replaced `process.stdout`) rather than Bun's +// own stdio stream in an observed state. Never runs user code. +extern "C" bool Bun__Process__consoleStreamIsCustom(Zig::GlobalObject* globalObject, int32_t fd) +{ + if (!globalObject->hasProcessObject()) [[unlikely]] + return false; + return globalObject->processObject()->consoleStreamIsCustom(fd); +} + +// Empty: use the native sink. Otherwise the stream to `write()` to. `*threw` +// is set (and empty returned) if user code made `process.stdout` a throwing +// getter and this was the console's first use. +extern "C" JSC::EncodedJSValue Bun__Process__consoleStream(Zig::GlobalObject* globalObject, int32_t fd, bool* threw) +{ + if (!globalObject->hasProcessObject()) [[unlikely]] + return JSValue::encode({}); + auto* process = globalObject->processObject(); + if (!process->consoleStreamIsResolved(fd)) [[unlikely]] { + // Top scope: the Rust caller learns about a throw through `*threw` + // (and propagates the pending exception), not through a ThrowScope. + auto scope = DECLARE_TOP_EXCEPTION_SCOPE(JSC::getVM(globalObject)); + JSValue result = process->consoleStream(globalObject, fd); + if (scope.exception()) [[unlikely]] { + *threw = true; + return JSValue::encode({}); + } + return JSValue::encode(result); + } + return JSValue::encode(process->consoleStream(globalObject, fd)); +} + +// The console's JS slow path: `stream.write(chunk)` with Node's kWriteToConsole +// error handling. `chunk` is one fully formatted message as a JS string. +extern "C" void Bun__Console__writeToStream(Zig::GlobalObject* globalObject, JSC::EncodedJSValue stream, JSC::EncodedJSValue chunk) +{ + auto& vm = JSC::getVM(globalObject); + auto scope = DECLARE_THROW_SCOPE(vm); + JSFunction* fn = globalObject->processObject()->consoleWriteFunction(); + JSC::MarkedArgumentBuffer args; + args.append(JSValue::decode(stream)); + args.append(JSValue::decode(chunk)); + JSC::call(globalObject, fn, JSC::getCallData(fn), jsUndefined(), args); + RETURN_IF_EXCEPTION(scope, ); +} + +// A console.* write on the shared stdio sink failed terminally (EPIPE, ...): +// deliver it as 'error' on our process.stdout/stderr object if that exists and +// is listened to (processObjectInternalsReportStdioSinkError decides). +extern "C" void Bun__Process__reportStdioSinkError(Zig::GlobalObject* globalObject, int32_t fd, JSC::EncodedJSValue err) +{ + if (!globalObject->hasProcessObject()) [[unlikely]] + return; + JSObject* stream = globalObject->processObject()->stdioStream(fd); + if (!stream) + return; + auto& vm = JSC::getVM(globalObject); + // A notification, not part of the console call's contract: a throwing + // 'error' listener is reported like any other uncaught exception rather + // than surfacing out of console.log(). + JSFunction* fn = JSFunction::create(vm, globalObject, processObjectInternalsReportStdioSinkErrorCodeGenerator(vm), globalObject); + MarkedArgumentBuffer args; + args.append(stream); + args.append(JSValue::decode(err)); + callReportingException(globalObject, fn, args); +} + +// (fd) -> the stream console output for `fd` must go through, or undefined +// when the native sink may be used. Builtin-JS face of Process::consoleStream. +JSC_DEFINE_HOST_FUNCTION(jsFunctionConsoleStream, (JSGlobalObject * lexicalGlobalObject, CallFrame* callFrame)) +{ + auto* globalObject = defaultGlobalObject(lexicalGlobalObject); + int32_t fd = callFrame->argument(0).asInt32(); + ASSERT(fd == 1 || fd == 2); + auto scope = DECLARE_THROW_SCOPE(JSC::getVM(globalObject)); + JSValue stream = globalObject->processObject()->consoleStream(globalObject, fd); + RETURN_IF_EXCEPTION(scope, {}); + return JSValue::encode(stream ? stream : jsUndefined()); +} + +// (mask, publish) — see m_consoleChannelMask. +JSC_DEFINE_HOST_FUNCTION(jsFunctionSetConsoleChannels, (JSGlobalObject * lexicalGlobalObject, CallFrame* callFrame)) +{ + auto* globalObject = defaultGlobalObject(lexicalGlobalObject); + auto* publish = dynamicDowncast(callFrame->argument(1)); + ASSERT(publish); + globalObject->processObject()->setConsoleChannels(JSC::getVM(globalObject), static_cast(callFrame->argument(0).toUInt32(lexicalGlobalObject)), publish); + return JSValue::encode(jsUndefined()); +} + +// console.clear() honours the console's *stream's* `isTTY` (Node checks +// `this._stdout.isTTY`), so hand back whatever object that is if one exists; +// empty means "nobody has a stream object, use the real fd". +extern "C" JSC::EncodedJSValue Bun__Process__consoleStreamObject(Zig::GlobalObject* globalObject, int32_t fd, bool* threw) +{ + if (!globalObject->hasProcessObject()) [[unlikely]] + return JSValue::encode({}); + auto* process = globalObject->processObject(); + auto scope = DECLARE_TOP_EXCEPTION_SCOPE(JSC::getVM(globalObject)); // see Bun__Process__consoleStream + JSValue custom = process->consoleStream(globalObject, fd); + if (scope.exception()) [[unlikely]] { + *threw = true; + return JSValue::encode({}); + } + if (custom) + return JSValue::encode(custom); + if (JSObject* stream = process->stdioStream(fd)) + return JSValue::encode(stream); + return JSValue::encode({}); +} + +// (fd, bits) — see m_stdioObserved. +JSC_DEFINE_HOST_FUNCTION(jsFunctionSetStdioObserved, (JSGlobalObject * lexicalGlobalObject, CallFrame* callFrame)) +{ + auto* globalObject = defaultGlobalObject(lexicalGlobalObject); + int32_t fd = callFrame->argument(0).asInt32(); + ASSERT(fd == 1 || fd == 2); + globalObject->processObject()->setStdioObserved(fd, static_cast(callFrame->argument(1).toUInt32(lexicalGlobalObject))); + return JSValue::encode(jsUndefined()); +} + +// (fd, stream | undefined) — worker_threads rebinding of the native console. +JSC_DEFINE_HOST_FUNCTION(jsFunctionSetConsoleStream, (JSGlobalObject * lexicalGlobalObject, CallFrame* callFrame)) +{ + auto* globalObject = defaultGlobalObject(lexicalGlobalObject); + int32_t fd = callFrame->argument(0).asInt32(); + ASSERT(fd == 1 || fd == 2); + globalObject->processObject()->setConsoleStream(JSC::getVM(globalObject), fd, callFrame->argument(1)); + return JSValue::encode(jsUndefined()); } static JSValue constructStdout(VM& vm, JSObject* processObject) @@ -3665,6 +3941,11 @@ void Process::visitChildrenImpl(JSCell* cell, Visitor& visitor) visitor.append(thisObject->m_cachedCwd); visitor.append(thisObject->m_argv); visitor.append(thisObject->m_execArgv); + for (unsigned i = 0; i < 2; ++i) { + visitor.append(thisObject->m_consoleStream[i]); + visitor.append(thisObject->m_stdioStream[i]); + } + visitor.append(thisObject->m_consolePublish); thisObject->m_cpuUsageStructure.visit(visitor); thisObject->m_resourceUsageStructure.visit(visitor); @@ -3672,6 +3953,7 @@ void Process::visitChildrenImpl(JSCell* cell, Visitor& visitor) thisObject->m_bindingUV.visit(visitor); thisObject->m_bindingNatives.visit(visitor); thisObject->m_emitHelperFunction.visit(visitor); + thisObject->m_consoleWriteFunction.visit(visitor); } DEFINE_VISIT_CHILDREN(Process); @@ -4933,6 +5215,9 @@ void Process::finishCreation(JSC::VM& vm) m_emitHelperFunction.initLater([](const JSC::LazyProperty::Initializer& init) { init.set(JSFunction::create(init.vm, init.owner->globalObject(), 2, "emit"_s, Process_functionEmitHelper, ImplementationVisibility::Private)); }); + m_consoleWriteFunction.initLater([](const JSC::LazyProperty::Initializer& init) { + init.set(JSFunction::create(init.vm, init.owner->globalObject(), consoleObjectWriteToObservedStreamCodeGenerator(init.vm), init.owner->globalObject())); + }); putDirect(vm, vm.propertyNames->toStringTagSymbol, jsString(vm, String("process"_s)), 0); putDirect(vm, Identifier::fromString(vm, "_exiting"_s), jsBoolean(false), 0); diff --git a/src/jsc/bindings/BunProcess.h b/src/jsc/bindings/BunProcess.h index 560b16e9dc50..e90565bf3409 100644 --- a/src/jsc/bindings/BunProcess.h +++ b/src/jsc/bindings/BunProcess.h @@ -26,6 +26,8 @@ class Process : public WebCore::JSEventEmitter { // Function that looks up "emit" on "process" and calls it with the provided arguments // Only used by internal code via passing to queueNextTick LazyProperty m_emitHelperFunction; + // consoleObjectWriteToObservedStream builtin (the console's JS slow path). + LazyProperty m_consoleWriteFunction; WriteBarrier m_uncaughtExceptionCaptureCallback; WriteBarrier m_nextTickFunction; // https://github.com/nodejs/node/blob/2eff28fb7a93d3f672f80b582f664a7c701569fb/lib/internal/bootstrap/switches/does_own_process_state.js#L113-L116 @@ -33,7 +35,58 @@ class Process : public WebCore::JSEventEmitter { WriteBarrier m_argv; WriteBarrier m_execArgv; + // ── console ⇄ process.stdout/stderr binding (index 0 = fd 1, 1 = fd 2) ── + // + // Node's global console writes through `this._stdout.write(chunk)`, where + // `_stdout` lazily binds to `process.stdout` on first use and can be + // reassigned. Bun's console formats natively and writes straight to the + // per-VM stdio sink *unless doing so would be observable*: the console's + // stream was reassigned or replaced, its `write` is no longer Bun's, or it + // is corked / ended. `consoleStream()` answers that per call in O(1). + enum class ConsoleStreamState : uint8_t { + Unresolved, // console has not written to this fd yet + Native, // bound to Bun's own stdio stream (whether or not the JS object exists yet) + Custom, // bound to m_consoleStream (console._stdout = x, or process.stdout replaced before first use) + }; + ConsoleStreamState m_consoleStreamState[2] = { ConsoleStreamState::Unresolved, ConsoleStreamState::Unresolved }; + // Bits set from JS while Bun's stdio stream is corked / ended, forcing the + // JS path so Writable semantics apply. See ProcessObjectInternals.ts. + uint8_t m_stdioObserved[2] = { 0, 0 }; + WriteBarrier m_consoleStream[2]; + // Bun's own process.stdout / process.stderr object once materialised, and + // the StructureID it had when pristine (no own `write`). + WriteBarrier m_stdioStream[2]; + StructureID m_stdioPristineStructureID[2] = {}; + // diagnostics_channel: bit i set while kConsoleChannelNames[i] has + // subscribers (log, warn, error, debug, info); m_consolePublish(i, args). + WriteBarrier m_consolePublish; + public: + uint8_t m_consoleChannelMask = 0; + JSFunction* consolePublish() { return m_consolePublish.get(); } + void setConsoleChannels(JSC::VM& vm, uint8_t mask, JSFunction* publish) + { + m_consoleChannelMask = mask; + m_consolePublish.set(vm, this, publish); + } + // fd is 1 or 2 for all of these. + void setStdioStream(JSC::VM&, int fd, JSObject* stream); + JSObject* stdioStream(int fd) { return m_stdioStream[fd - 1].get(); } + void setStdioObserved(int fd, uint8_t bits) { m_stdioObserved[fd - 1] = bits; } + // `console._stdout = value` / worker stdio rebinding. `value` may be anything. + void setConsoleStream(JSC::VM&, int fd, JSValue value); + // The stream the console must deliver through via JS `write()`, or the + // empty value when the native stdio sink may be used. A structure compare + // once resolved; the first (Unresolved) call may run — and throw from — a + // user getter installed on `process.stdout`/`stderr`. + JSValue consoleStream(JSC::JSGlobalObject*, int fd); + bool consoleStreamIsCustom(int fd) { return m_consoleStreamState[fd - 1] == ConsoleStreamState::Custom; } + bool consoleStreamIsResolved(int fd) const { return m_consoleStreamState[fd - 1] != ConsoleStreamState::Unresolved; } + // What `console._stdout` / `console._stderr` evaluate to (may materialise + // process.stdout; can throw). + JSValue consoleStreamForGetter(JSC::JSGlobalObject*, int fd); + JSFunction* consoleWriteFunction() { return m_consoleWriteFunction.getInitializedOnMainThread(this); } + Process(JSC::Structure* structure, WebCore::JSDOMGlobalObject& globalObject, Ref&& impl) : Base(structure, globalObject, WTF::move(impl)) { @@ -141,6 +194,14 @@ class Process : public WebCore::JSEventEmitter { }; JSC_DECLARE_HOST_FUNCTION(Process_functionDlopen); +// $newCppFunction("BunProcess.cpp", "jsFunctionSetStdioObserved", 2) +JSC_DECLARE_HOST_FUNCTION(jsFunctionSetStdioObserved); +// $newCppFunction("BunProcess.cpp", "jsFunctionSetConsoleStream", 2) +JSC_DECLARE_HOST_FUNCTION(jsFunctionSetConsoleStream); +// $newCppFunction("BunProcess.cpp", "jsFunctionSetConsoleChannels", 2) +JSC_DECLARE_HOST_FUNCTION(jsFunctionSetConsoleChannels); +// $newCppFunction("BunProcess.cpp", "jsFunctionConsoleStream", 1) +JSC_DECLARE_HOST_FUNCTION(jsFunctionConsoleStream); // Routes its argument onto the uncaught-exception path. Used by the // process.nextTick drain and, via $newCppFunction, by the node-style diff --git a/src/jsc/bindings/ConsoleObject.cpp b/src/jsc/bindings/ConsoleObject.cpp index 059994012fd5..8383ffc995ae 100644 --- a/src/jsc/bindings/ConsoleObject.cpp +++ b/src/jsc/bindings/ConsoleObject.cpp @@ -3,6 +3,8 @@ #include "JavaScriptCore/ArgList.h" #include "headers.h" #include "ConsoleObject.h" +#include "BunProcess.h" +#include "ZigGlobalObject.h" #include #include @@ -43,7 +45,7 @@ void ConsoleObject::messageWithTypeAndLevel(MessageType type, MessageLevel level auto args = arguments.ptr(); JSC::EncodedJSValue jsArgs[255]; - auto count = std::min(args->argumentCount(), (size_t)255); + size_t count = std::min(args->argumentCount(), (size_t)255); for (size_t i = 0; i < count; i++) { auto val = args->argumentAt(i); jsArgs[i] = JSC::JSValue::encode(val); @@ -55,6 +57,59 @@ void ConsoleObject::messageWithTypeAndLevel(MessageType type, MessageLevel level return; } + // diagnostics_channel 'console.log' / .warn / .error / .debug / .info: + // publish the argument list before formatting, only while subscribed. + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L409-L443 + if (type == MessageType::Log) { + auto* zigGlobal = defaultGlobalObject(globalObject); + if (zigGlobal->hasProcessObject()) [[likely]] { + auto* process = zigGlobal->processObject(); + if (uint8_t mask = process->m_consoleChannelMask) [[unlikely]] { + int index = -1; + switch (level) { + case MessageLevel::Log: + index = 0; + break; + case MessageLevel::Warning: + index = 1; + break; + case MessageLevel::Error: + index = 2; + break; + case MessageLevel::Debug: + index = 3; + break; + case MessageLevel::Info: + index = 4; + break; + default: + break; + } + if (index >= 0 && (mask & (1u << index))) { + auto scope = DECLARE_THROW_SCOPE(vm); + JSC::MarkedArgumentBuffer list; + for (size_t i = 0; i < count; i++) + list.append(JSC::JSValue::decode(jsArgs[i])); + JSC::JSArray* array = JSC::constructArray(globalObject, static_cast(nullptr), list); + RETURN_IF_EXCEPTION(scope, ); + JSC::MarkedArgumentBuffer publishArgs; + publishArgs.append(JSC::jsNumber(index)); + publishArgs.append(array); + JSC::JSFunction* publish = process->consolePublish(); + JSC::call(globalObject, publish, JSC::getCallData(publish), JSC::jsUndefined(), publishArgs); + RETURN_IF_EXCEPTION(scope, ); + // Subscribers get the live argument list in Node (the same + // array is then formatted), so take back whatever they did to it. + count = std::min(static_cast(array->length()), (size_t)255); + for (size_t i = 0; i < count; i++) { + jsArgs[i] = JSC::JSValue::encode(array->getIndex(globalObject, i)); + RETURN_IF_EXCEPTION(scope, ); + } + } + } + } + } + Bun__ConsoleObject__messageWithTypeAndLevel(this->m_client, static_cast(type), static_cast(level), globalObject, jsArgs, count); } void ConsoleObject::count(JSGlobalObject* globalObject, const String& label) diff --git a/src/jsc/bindings/ZigGlobalObject.cpp b/src/jsc/bindings/ZigGlobalObject.cpp index 3022c09cafe3..13061335e3d8 100644 --- a/src/jsc/bindings/ZigGlobalObject.cpp +++ b/src/jsc/bindings/ZigGlobalObject.cpp @@ -2928,34 +2928,27 @@ JSC_DEFINE_CUSTOM_GETTER(getConsoleConstructor, (JSGlobalObject * globalObject, return JSValue::encode(result); } -// `console._stdout` is equal to `process.stdout` -JSC_DEFINE_CUSTOM_GETTER(getConsoleStdout, (JSGlobalObject * globalObject, EncodedJSValue thisValue, PropertyName property)) +// `console._stdout` / `console._stderr`: what the global console writes +// through. Accessors (not cached data properties) so that assignment rebinds +// the native console, exactly like Node's kBindStreamsLazy get/set pair: +// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L205-L234 +JSC_DEFINE_CUSTOM_GETTER(getConsoleStdout, (JSGlobalObject * globalObject, EncodedJSValue thisValue, PropertyName)) { - auto& vm = JSC::getVM(globalObject); - auto console = JSValue::decode(thisValue).getObject(); - auto global = uncheckedDowncast(globalObject); - - // instead of calling the constructor builtin, go through the process.stdout getter to ensure it's only created once. - auto stdoutValue = global->processObject()->get(globalObject, Identifier::fromString(vm, "stdout"_s)); - if (!stdoutValue) return {}; - - console->putDirect(vm, property, stdoutValue, PropertyAttribute::DontEnum | 0); - return JSValue::encode(stdoutValue); + return JSValue::encode(uncheckedDowncast(globalObject)->processObject()->consoleStreamForGetter(globalObject, 1)); } - -// `console._stderr` is equal to `process.stderr` -JSC_DEFINE_CUSTOM_GETTER(getConsoleStderr, (JSGlobalObject * globalObject, EncodedJSValue thisValue, PropertyName property)) +JSC_DEFINE_CUSTOM_SETTER(setConsoleStdout, (JSGlobalObject * globalObject, EncodedJSValue thisValue, EncodedJSValue value, PropertyName)) { - auto& vm = JSC::getVM(globalObject); - auto console = JSValue::decode(thisValue).getObject(); - auto global = uncheckedDowncast(globalObject); - - // instead of calling the constructor builtin, go through the process.stdout getter to ensure it's only created once. - auto stderrValue = global->processObject()->get(globalObject, Identifier::fromString(vm, "stderr"_s)); - if (!stderrValue) return {}; - - console->putDirect(vm, property, stderrValue, PropertyAttribute::DontEnum | 0); - return JSValue::encode(stderrValue); + uncheckedDowncast(globalObject)->processObject()->setConsoleStream(JSC::getVM(globalObject), 1, JSValue::decode(value)); + return true; +} +JSC_DEFINE_CUSTOM_GETTER(getConsoleStderr, (JSGlobalObject * globalObject, EncodedJSValue thisValue, PropertyName)) +{ + return JSValue::encode(uncheckedDowncast(globalObject)->processObject()->consoleStreamForGetter(globalObject, 2)); +} +JSC_DEFINE_CUSTOM_SETTER(setConsoleStderr, (JSGlobalObject * globalObject, EncodedJSValue thisValue, EncodedJSValue value, PropertyName)) +{ + uncheckedDowncast(globalObject)->processObject()->setConsoleStream(JSC::getVM(globalObject), 2, JSValue::decode(value)); + return true; } // The CommonJS `require()` machinery (`@requireESM`, `@loadEsmIntoCjs`, @@ -3239,8 +3232,10 @@ void GlobalObject::addBuiltinGlobals(JSC::VM& vm) consoleObject->putDirectBuiltinFunction(vm, this, vm.propertyNames->asyncIteratorSymbol, consoleObjectAsyncIteratorCodeGenerator(vm), PropertyAttribute::Builtin | 0); consoleObject->putDirectBuiltinFunction(vm, this, clientData->builtinNames().writePublicName(), consoleObjectWriteCodeGenerator(vm), PropertyAttribute::Builtin | 0); consoleObject->putDirectCustomAccessor(vm, Identifier::fromString(vm, "Console"_s), CustomGetterSetter::create(vm, getConsoleConstructor, nullptr), PropertyAttribute::CustomValue | 0); - consoleObject->putDirectCustomAccessor(vm, Identifier::fromString(vm, "_stdout"_s), CustomGetterSetter::create(vm, getConsoleStdout, nullptr), PropertyAttribute::DontEnum | PropertyAttribute::CustomValue | 0); - consoleObject->putDirectCustomAccessor(vm, Identifier::fromString(vm, "_stderr"_s), CustomGetterSetter::create(vm, getConsoleStderr, nullptr), PropertyAttribute::DontEnum | PropertyAttribute::CustomValue | 0); + consoleObject->putDirectCustomAccessor(vm, Identifier::fromString(vm, "_stdout"_s), CustomGetterSetter::create(vm, getConsoleStdout, setConsoleStdout), PropertyAttribute::DontEnum | PropertyAttribute::CustomAccessor | 0); + consoleObject->putDirectCustomAccessor(vm, Identifier::fromString(vm, "_stderr"_s), CustomGetterSetter::create(vm, getConsoleStderr, setConsoleStderr), PropertyAttribute::DontEnum | PropertyAttribute::CustomAccessor | 0); + // Node parity: the global console ignores stream errors. + consoleObject->putDirect(vm, Identifier::fromString(vm, "_ignoreErrors"_s), jsBoolean(true), PropertyAttribute::DontEnum | 0); } // ===================== start conditional builtin globals ===================== diff --git a/src/jsc/bindings/c-bindings.cpp b/src/jsc/bindings/c-bindings.cpp index 1ead5980b9ba..f9541f12b9c1 100644 --- a/src/jsc/bindings/c-bindings.cpp +++ b/src/jsc/bindings/c-bindings.cpp @@ -538,12 +538,59 @@ static termios termios_to_restore_later[3]; // from normal execution; sig_atomic_t is the only integral type POSIX // guarantees can be accessed atomically across that boundary. extern "C" volatile sig_atomic_t bun_stdio_modified[3] = { 0, 0, 0 }; + +// Startup snapshot of each stdio fd's file status flags and identity, so the +// O_NONBLOCK bit can be put back on exit if we (or a child sharing the open +// file description) changed it. Same contract as Node's ResetStdio(): +// https://github.com/nodejs/node/blob/v24.0.0/src/node.cc#L662-L722 +static struct { + int flags; // fcntl(F_GETFL) at startup, or -1 + dev_t dev; + ino_t ino; +} bun_stdio_startup_state[3] = { { -1, 0, 0 }, { -1, 0, 0 }, { -1, 0, 0 } }; + +extern "C" void Bun__stdioMadeBlocking(int fd); + +static void bun_restore_stdio_nonblock() +{ + for (int fd = 0; fd < 3; fd++) { + auto& s = bun_stdio_startup_state[fd]; + if (s.flags == -1) + continue; + + struct stat st; + if (fstat(fd, &st) == -1) + continue; // Program closed the file descriptor. + if (st.st_dev != s.dev || st.st_ino != s.ino) + continue; // Program reopened the file descriptor as something else. + + int flags; + do + flags = fcntl(fd, F_GETFL); + while (flags == -1 && errno == EINTR); + if (flags == -1) + continue; + + if ((flags ^ s.flags) & O_NONBLOCK) { + flags = (flags & ~O_NONBLOCK) | (s.flags & O_NONBLOCK); + int err; + do + err = fcntl(fd, F_SETFL, flags); + while (err == -1 && errno == EINTR); + // If we keep running after this (a failed execve), the stdio sink + // that had set O_NONBLOCK must stop expecting EAGAIN. + if (err == 0 && !(flags & O_NONBLOCK)) + Bun__stdioMadeBlocking(fd); + } + } +} #endif extern "C" void bun_restore_stdio() { #if !OS(WINDOWS) + bun_restore_stdio_nonblock(); // Only suppress the restore when Bun is a pipeline producer (stdout is a // pipe, not a TTY) and it didn't touch termios itself. That's the #29592 @@ -630,7 +677,7 @@ extern "C" void bun_initialize_process() #if OS(LINUX) || OS(DARWIN) || OS(FREEBSD) int devNullFd_ = -1; - bool anyTTYs = false; + bool restoreOnSignal = false; const auto setDevNullFd = [&](int target_fd) -> void { bun_is_stdio_null[target_fd] = 1; @@ -662,8 +709,27 @@ extern "C" void bun_initialize_process() if (errno == EBADF) [[unlikely]] { // the fd is invalid, let's make sure it's always valid setDevNullFd(fd); + continue; + } + } + + { + struct stat st; + int flags; + do + flags = fcntl(fd, F_GETFL); + while (flags == -1 && errno == EINTR); + if (flags != -1 && fstat(fd, &st) == 0) { + bun_stdio_startup_state[fd] = { flags, st.st_dev, st.st_ino }; + // A FIFO is the one stdio kind whose O_NONBLOCK bit we may flip + // (FileSink::stdio_go_nonblocking), so make sure the signal-exit + // path restores it. + if (S_ISFIFO(st.st_mode)) + restoreOnSignal = true; } - } else { + } + + if (result != 0) { bun_stdio_tty[fd] = 1; int err = 0; @@ -672,7 +738,7 @@ extern "C" void bun_initialize_process() } while (err == -1 && errno == EINTR); if (err == 0) [[likely]] { - anyTTYs = true; + restoreOnSignal = true; } } } @@ -682,8 +748,8 @@ extern "C" void bun_initialize_process() close(devNullFd_); } - // Restore TTY state on exit - if (anyTTYs) { + // Restore TTY state / O_NONBLOCK on exit + if (restoreOnSignal) { struct sigaction sa; memset(&sa, 0, sizeof(sa)); sigemptyset(&sa.sa_mask); @@ -691,8 +757,15 @@ extern "C" void bun_initialize_process() sa.sa_flags = SA_RESETHAND; sa.sa_handler = onExitSignal; - sigaction(SIGTERM, &sa, nullptr); - sigaction(SIGINT, &sa, nullptr); + for (int sig : { SIGTERM, SIGINT }) { + // An inherited SIG_IGN (`trap '' INT TERM; bun ... | cat`) means the + // signal can't terminate us, so there is nothing to restore on it — + // and replacing it would make us (and our children) killable again. + struct sigaction current; + if (sigaction(sig, nullptr, ¤t) == 0 && current.sa_handler == SIG_IGN) + continue; + sigaction(sig, &sa, nullptr); + } } #elif OS(WINDOWS) for (int fd = 0; fd <= 2; ++fd) { diff --git a/src/jsc/rare_data.rs b/src/jsc/rare_data.rs index 8476ef60cb1b..eab45c87fb5d 100644 --- a/src/jsc/rare_data.rs +++ b/src/jsc/rare_data.rs @@ -207,6 +207,13 @@ pub struct RareData { pub stdout_store: Option>, pub(crate) stdout_mode: Mode, + /// Erased `*mut bun_runtime::webcore::FileSink` — the per-VM stdio sink for + /// fd 1 (`[0]`) and fd 2 (`[1]`). Everything this JS thread writes to those + /// fds (console, `process.stdout/stderr`, `Bun.stdout.writer()`, ...) goes + /// through these; created lazily by `bun_runtime` (`stdio_sink_for`), one + /// intrusive ref owned here and released in `Drop`. + pub stdio_sinks: [Option>; 2], + pub(crate) entropy_cache: Option>, pub(crate) hot_map: Option, @@ -304,6 +311,7 @@ impl Default for RareData { stdin_mode: 0, stdout_store: None, stdout_mode: 0, + stdio_sinks: [None, None], entropy_cache: None, hot_map: None, cron_jobs: Vec::new(), @@ -624,6 +632,18 @@ impl RareData { pub(crate) fn release_js_handles(&mut self) { self.s3_default_client.deinit(); self.node_quic_callbacks.deinit(); + self.release_stdio_sinks(); + } + + /// Drop `RareData`'s ref on the stdio sinks. Must run while the event loop + /// (poll deregistration) and JSC (a live `JSFileSink` wrapper may hold the + /// other ref) are both still up — i.e. from `release_js_handles`, never + /// from `Drop`. + pub fn release_stdio_sinks(&mut self) { + for sink in self.stdio_sinks.iter_mut().filter_map(Option::take) { + // SAFETY: `sink` is the +1 pointer `stdio_sink_for` stored. + unsafe { __bun_stdio_sink_deinit(sink.as_ptr().cast()) }; + } } // ── trivial field accessors ──────────────────────────────────────────── @@ -913,6 +933,13 @@ impl RareData { unsafe extern "Rust" { safe fn __bun_stdio_blob_store_deinit(ptr: *mut ()); + /// Releases `RareData`'s ref on a stdio `FileSink` (defined in + /// `bun_runtime::webcore::file_sink`). `ptr` is the exact pointer stored in + /// `stdio_sinks`. + fn __bun_stdio_sink_deinit(ptr: *mut ()); + /// Synchronously drain both stdio sinks of `vm` (defined next to the above). + pub(crate) fn __bun_stdio_sink_drain(vm: *mut VirtualMachine); + pub(crate) fn __bun_stdio_sink_release_js(vm: *mut VirtualMachine); } impl RareData { @@ -1100,6 +1127,9 @@ impl Drop for RareData { { __bun_stdio_blob_store_deinit(store.as_ptr().cast()); } + // `release_js_handles()` ran before the loop / JSC went away; a sink + // still here would need both to deinit, so it is deliberately leaked. + debug_assert!(self.stdio_sinks.iter().all(Option::is_none)); self.detach_socket_groups_from_loop(); } diff --git a/src/runtime/cli/test_command.rs b/src/runtime/cli/test_command.rs index a682e399fa12..b7f1943b8b91 100644 --- a/src/runtime/cli/test_command.rs +++ b/src/runtime/cli/test_command.rs @@ -2365,6 +2365,13 @@ impl TestCommand { _ = vm.global().set_time_zone(&ZigString::init(tz_name)); } + // Materialise the runner's stdio sinks (a dup of fd 1 / fd 2 each) up + // front rather than at some test's first `console.log`, so tests that + // audit open fds around their own work see a stable set. + for fd in [bun_sys::Fd::stdout(), bun_sys::Fd::stderr()] { + let _ = crate::webcore::file_sink::stdio_sink_for(vm, fd); + } + if ctx.test_options.test_worker { // Worker mode: skip discovery; files arrive over stdin and // results go out over fd 3. Never returns. diff --git a/src/runtime/dispatch.rs b/src/runtime/dispatch.rs index df0996b0438a..8d7de9500b24 100644 --- a/src/runtime/dispatch.rs +++ b/src/runtime/dispatch.rs @@ -721,7 +721,15 @@ pub(crate) unsafe fn __bun_run_file_poll(poll: *mut FilePoll, size_or_offset: i6 } } - poll_tag::FILE_SINK => poll_arm!(FileSinkPoll), + poll_tag::FILE_SINK => poll_arm!(FileSinkPoll, |h| { + // SAFETY: tag matched (see `poll_arm!`); `parent_ptr` is the owning + // FileSink. A stdio sink re-checks its fd mode before the writable + // callback flushes (spawn may have made the description blocking). + unsafe { + crate::webcore::FileSink::before_writable((*h).parent_ptr()); + (*h).on_poll(size_or_offset as isize, hup) + } + }), poll_tag::STATIC_PIPE_WRITER => poll_arm!(StaticPipeWriterPoll>), poll_tag::SHELL_STATIC_PIPE_WRITER => { poll_arm!(StaticPipeWriterPoll) diff --git a/src/runtime/jsc_hooks.rs b/src/runtime/jsc_hooks.rs index 60b81f6a0412..84498e8d5e55 100644 --- a/src/runtime/jsc_hooks.rs +++ b/src/runtime/jsc_hooks.rs @@ -367,6 +367,8 @@ unsafe fn init_runtime_state( // PORTING.md §Forbidden permits // `into_raw`-without-reclaim only for true process-lifetime singletons via // `OnceLock`, which this is not (per-VM / per-Worker-thread). + bun_sys::set_stdio_write_hook(crate::webcore::file_sink::before_output_write); + let state = bun_core::heap::into_raw(Box::new(RuntimeState { timer: timer::All::init(), sql_rare: bun_sql_jsc::jsc::RareData { diff --git a/src/runtime/node/node_fs.rs b/src/runtime/node/node_fs.rs index 75e13e84411a..56134188c069 100644 --- a/src/runtime/node/node_fs.rs +++ b/src/runtime/node/node_fs.rs @@ -4773,7 +4773,7 @@ impl NodeFS { let mut broke = false; 'toplevel: while remain > 0 { let read_len = (buf.len() as u64).min(remain) as usize; - let amt = match Syscall::read(src_fd, &mut buf[..read_len]) { + let amt = match Syscall::read_retrying(src_fd, &mut buf[..read_len]) { Ok(result) => result, Err(err) => { return Err(if !src.is_empty() { @@ -4793,7 +4793,7 @@ impl NodeFS { let mut slice = &buf[..amt]; while !slice.is_empty() { - let written = match Syscall::write(dest_fd, slice) { + let written = match Syscall::write_retrying(dest_fd, slice) { Ok(result) => result, Err(err) => { return Err(if !dest.is_empty() { @@ -4812,7 +4812,7 @@ impl NodeFS { } if !broke { 'outer: loop { - let amt = match Syscall::read(src_fd, buf) { + let amt = match Syscall::read_retrying(src_fd, buf) { Ok(result) => result, Err(err) => { return Err(if !src.is_empty() { @@ -4831,7 +4831,7 @@ impl NodeFS { let mut slice = &buf[..amt]; while !slice.is_empty() { - let written = match Syscall::write(dest_fd, slice) { + let written = match Syscall::write_retrying(dest_fd, slice) { Ok(result) => result, Err(err) => { return Err(if !dest.is_empty() { diff --git a/src/runtime/webcore/Blob.rs b/src/runtime/webcore/Blob.rs index 6a6151444011..b99a0a1ad205 100644 --- a/src/runtime/webcore/Blob.rs +++ b/src/runtime/webcore/Blob.rs @@ -1783,6 +1783,19 @@ impl BlobExt for Blob { ); } + // fd 1 / fd 2: every writer on this VM shares the one stdio sink, so + // `Bun.stdout.writer()`, `process.stdout` and `console.log` can never + // reorder or hold separate queues (and never open a second dup / flip + // the description's flags a second time). + if let Some(stdio_fd) = stdio_fd_of_store(global_this, &store) { + // The shared per-thread stdio sink: one object however many times + // it is asked for, so per-call options (`highWaterMark`) can't and + // don't apply. + if let Some(js) = webcore::file_sink::stdio_sink_js(global_this, stdio_fd) { + return Ok(js); + } + } + #[cfg(windows)] { use bun_io::pipe_writer::BaseWindowsPipeWriter as _; @@ -4954,6 +4967,33 @@ pub(crate) fn write_file_with_source_destination( // writeFileInternal / writeFile (Bun.write) // ────────────────────────────────────────────────────────────────────────── +/// `Some(Fd::stdout()|stderr())` when `store` is this VM's stdout/stderr store +/// or any fd-backed store on fd 1/2 — i.e. writes to it belong to the stdio sink. +pub(crate) fn stdio_fd_of_store(global_this: &JSGlobalObject, store: &Store) -> Option { + let store::Data::File(ref file) = store.data else { + return None; + }; + let PathOrFileDescriptor::Fd(fd) = file.pathlike else { + return None; + }; + match fd.stdio_tag() { + Some(bun_core::Stdio::StdOut) => return Some(Fd::stdout()), + Some(bun_core::Stdio::StdErr) => return Some(Fd::stderr()), + _ => {} + } + // SAFETY: bun_vm() never returns null for a Bun-owned global. + let vm = global_this.bun_vm().as_mut(); + let rare = vm.rare_data.as_ref()?; + let store_ptr = core::ptr::from_ref(store).cast::().cast_mut(); + if rare.stdout_store.map(|p| p.as_ptr()) == Some(store_ptr) { + Some(Fd::stdout()) + } else if rare.stderr_store.map(|p| p.as_ptr()) == Some(store_ptr) { + Some(Fd::stderr()) + } else { + None + } +} + /// ## Errors /// - If `path_or_blob` is a detached blob /// ## Panics @@ -5004,6 +5044,62 @@ pub(crate) fn write_file_internal( } } + // Bun.write(Bun.stdout | Bun.stderr, data): through the stdio sink, so it is + // ordered with everything already handed to the sink (console.*, + // process.stdout — though not with chunks process.stdout's Writable is still + // holding: cork(), backpressure buffer) and gets the same EAGAIN handling + // (and never lands on the thread pool, whose LIFO queue reversed + // back-to-back writes to a file-backed stdout). + if let PathOrBlob::Blob(ref b) = *path_or_blob { + if b.offset.get() == 0 && !b.is_s3() { + let stdio_fd = b + .store + .get() + .as_deref() + .and_then(|st| stdio_fd_of_store(global_this, st)); + if let Some(stdio_fd) = stdio_fd { + // SAFETY: bun_vm() is the live VM owning `global_this`. + let vm = global_this.bun_vm().as_mut(); + if let Some(sink) = webcore::file_sink::stdio_sink_for(vm, stdio_fd) { + // An async JS writer, like process.stdout: a pipe may queue + // and resolve later rather than stall the loop. + // SAFETY: canonical live pointer held by RareData. + #[cfg(not(windows))] + unsafe { + (*sink).stdio_go_nonblocking() + }; + // SAFETY: as above. + let wrote = unsafe { (*sink).write_js_value(global_this, data, true, true)? }; + if let Some((result, accepted)) = wrote { + // Resolves with *this* call's byte count: right away if + // the fd took it, otherwise once the sink's queue has + // drained (the loop keeps running meanwhile). + return Ok(match result { + streams::Writable::Err(err) => { + JSPromise::dangerously_create_rejected_promise_value_without_notifying_vm( + global_this, + err.to_js(global_this), + ) + } + // SAFETY: as above. + streams::Writable::Pending(_) => unsafe { + (*sink).add_stdio_waiter(global_this, accepted as f64) + }, + _ => JSPromise::resolved_promise_value( + global_this, + JSValue::js_number(accepted as f64), + ), + }); + } + // A Blob / stream source takes the general path below; at + // least keep it behind anything already queued. + // SAFETY: as above. + let _ = unsafe { webcore::FileSink::drain_sync(sink) }; + } + } + } + } + // If you're doing Bun.write(), try to go fast by writing short input on the main thread. // This is a heuristic, but it's a good one. // diff --git a/src/runtime/webcore/FileSink.rs b/src/runtime/webcore/FileSink.rs index fba7f7cc05c4..6e43ce177cfb 100644 --- a/src/runtime/webcore/FileSink.rs +++ b/src/runtime/webcore/FileSink.rs @@ -55,6 +55,27 @@ pub struct FileSink { pub(crate) is_socket: Cell, pub(crate) fd: Cell, + /// `Fd::stdout()` / `Fd::stderr()` when this is the per-VM stdio sink for + /// that fd (see [`FileSink::create_stdio`]); `Fd::INVALID` otherwise. + pub(crate) stdio: Cell, + /// The one `JSFileSink` wrapper for a stdio sink, shared by + /// `process.stdout/stderr`, `Bun.stdout.writer()` and `Bun.file(1|2).writer()`. + /// Cleared before JSC teardown in `__bun_stdio_sink_deinit`. + pub(crate) stdio_js: JsCell, + /// A stdio sink's terminal write error (EPIPE, EIO, ...). Sticky: the fd + /// is gone, so every later write reports the same error again — which is + /// how Node's stdio streams behave (each write() re-fails) and what lets + /// `'error'` fire per call instead of the sink going quietly inert. + pub(crate) stdio_error: JsCell>, + /// `Bun.write(Bun.stdout, x)` calls waiting for the queue to drain, each + /// with the byte count it is to resolve with (the shared `pending` slot's + /// count belongs to whoever awaits the JS wrapper's promise). + pub(crate) stdio_waiters: JsCell>, + /// This stdio sink is relying on `pwritev2(RWF_NOWAIT)` (Linux ≥ 6.4 + /// pipes) instead of `O_NONBLOCK`; see `refresh_stdio_mode`. + #[cfg(any(target_os = "linux", target_os = "android"))] + pub(crate) stdio_rwf_nowait: Cell, + pub(crate) auto_flusher: JsCell, pub(crate) run_pending_later: FlushPendingTask, @@ -223,73 +244,6 @@ impl FileSink { } } -#[unsafe(no_mangle)] -pub(crate) extern "C" fn Bun__ForceFileSinkToBeSynchronousForProcessObjectStdio( - _global: *mut JSGlobalObject, - jsvalue: JSValue, -) { - let Some(this_ptr) = JSSink::from_js(jsvalue) else { - return; - }; - // SAFETY: `from_js` returned a live `*mut JSSink` (= ThisSink); the - // first field is `sink: FileSink`, so `&(*this_ptr).sink` recovers the - // wrapped `*FileSink`. - let this: &FileSink = unsafe { &(*this_ptr).sink }; - - #[cfg(not(windows))] - { - this.force_sync.set(true); - // SAFETY(JsCell): single-field write; does not call into JS. - this.writer.with_mut(|w| w.force_sync = true); - if this.fd.get() != Fd::INVALID { - let _ = sys::update_nonblocking(this.fd.get(), false); - } - } - #[cfg(windows)] - { - // SAFETY(JsCell): closure does not call into JS — pure libuv FFI. - let did_set_blocking = this.writer.with_mut(|w| { - if let Some(source) = w.source.as_mut() { - match source { - bun_io::Source::Pipe(pipe) => { - // SAFETY: `pipe` is a live `Box` owned by `writer.source`; - // `uv_pipe_t` is `#[repr(C)]` with `uv_stream_t` as its first field - // (libuv handle subtyping), so the pointer cast is valid. - let rc = unsafe { - uv::uv_stream_set_blocking( - (&mut **pipe) as *mut uv::Pipe as *mut uv::uv_stream_t, - 1, - ) - }; - if rc == uv::ReturnCode::ZERO { - return true; - } - } - bun_io::Source::Tty(tty) => { - // SAFETY: `tty` is a live `NonNull` (heap or static stdin tty); - // `uv_tty_t` embeds `uv_stream_t` as its first field, so the cast is the - // libuv handle-subtype downcast. - let rc = unsafe { - uv::uv_stream_set_blocking(tty.as_ptr().cast::(), 1) - }; - if rc == uv::ReturnCode::ZERO { - return true; - } - } - _ => {} - } - } - false - }); - if did_set_blocking { - return; - } - - // Fallback to WriteFile() if it fails. - this.force_sync.set(true); - } -} - impl FileSink { /// `bun.spawn`'s subprocess exited while this `FileSink` was its stdin. /// @@ -370,10 +324,15 @@ impl FileSink { (*this).run_pending_later.has.set(false); let _entered = (*this).event_loop().entered(); + let failure = match (*this).pending.get().result { + streams::Writable::Err(ref err) => Some(err.clone()), + _ => (*this).stdio_error(), + }; // SAFETY(JsCell): `WritablePending::run` resolves a JSPromise which may // re-enter JS, but no other path holds a borrow of `self.pending` for // the duration (host-fns gate on `pending.state != Pending` first). (*this).pending.get_mut().run(); + FileSink::settle_stdio_waiters(this, failure.as_ref()); // Release the JS wrapper reference now that the pending operation is complete. // This was held to prevent GC from collecting the wrapper while the async @@ -408,6 +367,10 @@ impl FileSink { (*this) .writer .with_mut(|w| w.update_ref(evtloop, has_pending_data)); + #[cfg(not(windows))] + if !has_pending_data && (*this).is_stdio() { + (*this).writer.with_mut(|w| w.unregister_poll()); + } if has_pending_data { if let Some(vm) = (*this).js_vm() { @@ -417,10 +380,21 @@ impl FileSink { } } - // if we are not done yet and has pending data we just wait so we do not runPending twice - if status == WriteStatus::Pending && has_pending_data { + // Backed up: whoever is waiting on the pending promise keeps waiting. + // A stdio sink also waits out a small write coalesced behind an + // earlier remainder (its poll / autoflush is guaranteed to drain it), + // so process.stdout's `'drain'` can't fire early. + if has_pending_data + && (status == WriteStatus::Pending + || (cfg!(not(windows)) + && (*this).is_stdio() + && status != WriteStatus::EndOfFile)) + { return; } + if !has_pending_data { + FileSink::settle_stdio_waiters(this, None); + } let was_pending = (*this).pending.get().state == streams::PendingState::Pending; if was_pending { @@ -475,15 +449,25 @@ impl FileSink { // drop the last reference and free `this` before that `close()` runs. // SAFETY: caller contract — `this` is live with write+dealloc provenance. unsafe { + let err = if (*this).is_stdio() { + (*this).stdio_latch_error(err) + } else { + err + }; if (*this).pending.get().state == streams::PendingState::Pending { (*this) .pending .with_mut(|p| p.result = streams::Writable::Err(err)); - if let Some(vm) = (*this).js_vm() { - if vm.is_inside_deferred_task_queue.get() { - (*this).run_pending_later(); - return; - } + // A stdio sink can get here from inside `drain_sync` / + // `write_all_sync` (console.log, exit) with the writer borrowed + // and the stdio lock held: settle on the next tick, never here. + let defer = (*this).is_stdio() + || (*this) + .js_vm() + .is_some_and(|vm| vm.is_inside_deferred_task_queue.get()); + if defer { + (*this).run_pending_later(); + return; } FileSink::run_pending(this); @@ -600,6 +584,535 @@ impl FileSink { this } + // ── stdio sinks ──────────────────────────────────────────────────────── + // + // One `FileSink` per (VM, fd ∈ {1, 2}) is *the* owner of every byte this + // JS thread sends to that fd: `console.*` formats a whole message and hands + // it to `write_all_sync`, `process.stdout`/`stderr`, `Bun.stdout.writer()` + // and `Bun.write(Bun.stdout, ..)` are JS façades over the same object, and + // `process.exit()` / fatal-error printing call `drain_sync` first. That is + // what gives Node's ordering guarantees (console.log is literally + // `process.stdout.write` there) without routing the console through JS. + // + // fd mode is decided once here and nowhere else: + // tty / regular file / anything else → blocking `write(2)`, description + // flags left untouched; + // FIFO → eager (syscall on every write) but non-blocking so a slow + // reader queues + `'drain'`s instead of stalling the loop — via + // `RWF_NOWAIT` where the kernel has it, else `O_NONBLOCK` (restored at + // exit by `bun_restore_stdio`, cleared for children by spawn); + // socket → `send(MSG_DONTWAIT)`, no description flag needed; + // Windows → the existing synchronous `SyncFile` path for everything. + // Every write loop below treats `EAGAIN` as "wait for POLLOUT", so nothing + // here depends on the description actually being in the mode we chose. + + /// Whether this sink is the VM's stdout/stderr sink. + #[inline] + pub fn is_stdio(&self) -> bool { + self.stdio.get() != Fd::INVALID + } + + /// stdio sinks report every fd error as `syscall: 'write'` (Node's stdio + /// streams do; ours may have used `send(2)`/`pwritev2(2)` underneath) and + /// latch the first one — see `stdio_error`. + fn stdio_latch_error(&self, mut err: sys::Error) -> sys::Error { + debug_assert!(self.is_stdio()); + err.syscall = sys::Tag::write; + if self.stdio_error.get().is_none() { + self.stdio_error.with_mut(|e| *e = Some(err.clone())); + } + // SAFETY: `self` is the canonical RareData-held stdio sink; settling + // only rejects promises (reactions run later as microtasks). + unsafe { FileSink::settle_stdio_waiters(core::ptr::from_ref(self).cast_mut(), Some(&err)) }; + err + } + + /// The latched terminal error of a stdio sink, if any. + #[inline] + pub fn stdio_error(&self) -> Option { + let e = self.stdio_error.get(); + if e.is_none() { None } else { e.clone() } + } + + /// The shared JS wrapper for a stdio sink (created on first request, and + /// again if a previous holder `close()`d — which detaches the wrapper but, + /// for stdio, only flushes the sink). + /// + /// Handing out a JS writer is also the point where a FIFO goes + /// non-blocking: `process.stdout.write()` / `FileSink.write()` promise + /// Node's "returns false, emits 'drain'" instead of stalling the loop, and + /// that needs `EAGAIN` from the kernel. Console-only programs never get + /// here and keep a plain blocking fd (nothing shared with a parent shell + /// or sibling process changes under them). + /// + /// # Safety + /// `this` is the canonical live stdio sink pointer held by `RareData`. + pub unsafe fn stdio_js(this: *mut FileSink, global: &JSGlobalObject) -> JSValue { + // SAFETY: caller contract; each access is a scoped reborrow. + unsafe { + debug_assert!((*this).is_stdio()); + if let Some(v) = (*this).stdio_js.get().get() { + if JSSink::from_js(v).is_some() { + return v; + } + } + #[cfg(not(windows))] + (*this).stdio_go_nonblocking(); + let v = (*this).to_js(global); + // SAFETY(JsCell): `Strong::set` is a root-slot write; no JS re-entry. + (*this).stdio_js.with_mut(|s| s.set(global, v)); + v + } + } + + /// Forget the cached wrapper (it stays valid for whoever holds it; the next + /// `stdio_js` makes a new one in the then-current global). + pub fn release_stdio_js(&self) { + self.stdio_js.with_mut(|s| s.deinit()); + self.stdio_waiters.with_mut(|w| w.clear()); + } + + /// `Bun.write(Bun.stdout|stderr, x)` whose bytes had to queue: a promise + /// resolved with `count` once the queue has drained (or rejected with the + /// error that stopped it). + pub fn add_stdio_waiter(&self, global: &JSGlobalObject, count: f64) -> JSValue { + let strong = bun_jsc::js_promise::Strong::init(global); + let value = strong.value(); + self.stdio_waiters.with_mut(|w| w.push((strong, count))); + value + } + + /// # Safety + /// `this` is the canonical live pointer; resolves promises (re-enters JS). + unsafe fn settle_stdio_waiters(this: *mut FileSink, failure: Option<&sys::Error>) { + // SAFETY: caller contract; the Vec is moved out before any JS runs. + let waiters = unsafe { (*this).stdio_waiters.replace(Vec::new()) }; + if waiters.is_empty() { + return; + } + // SAFETY: as above. + let Some(vm) = (unsafe { (*this).js_vm() }) else { + return; + }; + let global = vm.global(); + for (mut promise, count) in waiters { + let _ = match failure { + None => promise.resolve(global, JSValue::js_number(count)), + Some(err) => { + use bun_sys_jsc::ErrorJsc as _; + promise.reject(global, err.clone().to_js(global)) + } + }; + } + } + + /// Poll dispatch is about to run the writable callback for this sink. + /// + /// # Safety + /// `this` is the live FileSink owning the poll. + #[cfg(not(windows))] + #[inline] + pub unsafe fn before_writable(this: *mut FileSink) { + // SAFETY: caller contract; field reads/`Cell` writes only. + unsafe { (*this).refresh_stdio_mode() }; + } + + /// Something (spawn with inherited stdio) put our description back into + /// blocking mode after [`stdio_go_nonblocking`](Self::stdio_go_nonblocking): + /// stop treating the fd as `EAGAIN`-capable so a full pipe is handled by the + /// blocking-pipe strategy (`poll` before `write`) instead of a write that + /// was expected to return early. One relaxed load when nothing happened. + #[inline] + fn refresh_stdio_mode(&self) { + #[cfg(any(target_os = "linux", target_os = "android"))] + if self.stdio_rwf_nowait.get() && !sys::linux::RWFFlagSupport::is_maybe_supported() { + // The RWF_NOWAIT route was refused at runtime; take the portable one + // (unless a spawn has since asked for blocking stdio anyway). + self.stdio_rwf_nowait.set(false); + if !sys::stdio_made_blocking(self.stdio.get()) { + self.stdio_set_o_nonblock(self.writer.get().get_fd()); + } + return; + } + #[cfg(not(windows))] + if self.nonblocking.get() && self.is_stdio() && sys::stdio_made_blocking(self.stdio.get()) { + self.nonblocking.set(false); + if let Some(poll) = self.writer.get().get_poll() { + poll.clear_flag(bun_io::FilePollFlag::Nonblocking); + } + } + } + + /// See [`stdio_js`](Self::stdio_js). FIFO only; sockets get per-call + /// `MSG_DONTWAIT`, Linux ≥ 6.4 pipes honour `RWF_NOWAIT` on a blocking + /// description (torvalds/linux@afed6271f5b0, "pipe: set FMODE_NOWAIT on + /// pipes"), and ttys / files stay blocking as in Node. + #[cfg(not(windows))] + pub(crate) fn stdio_go_nonblocking(&self) { + if self.nonblocking.get() || !self.pollable.get() || self.is_socket.get() { + return; + } + // A spawn handed this description to a child blocking; it stays that + // way (see `refresh_stdio_mode`) — don't flip it back under the child. + if sys::stdio_made_blocking(self.stdio.get()) { + return; + } + #[cfg(any(target_os = "linux", target_os = "android"))] + if self.stdio_rwf_nowait.get() { + return; + } + let fd = self.writer.get().get_fd(); + if fd == Fd::INVALID { + return; + } + #[cfg(any(target_os = "linux", target_os = "android"))] + { + let v = bun_core::linux_kernel_version(); + if (v.major > 6 || (v.major == 6 && v.minor >= 4)) + && sys::linux::RWFFlagSupport::is_maybe_supported() + && sys::is_on_pipefs(fd) + { + // `pwritev2(RWF_NOWAIT)` on a blocking description. Should the + // kernel turn out to refuse it after all (seccomp, gVisor, ...), + // `refresh_stdio_mode` falls back to O_NONBLOCK. + self.stdio_rwf_nowait.set(true); + return; + } + } + self.stdio_set_o_nonblock(fd); + } + + #[cfg(not(windows))] + fn stdio_set_o_nonblock(&self, fd: Fd) { + let already = sys::get_fcntl_flags(fd) + .map(|f| f as i32 & sys::O::NONBLOCK != 0) + .unwrap_or(false); + if already || sys::set_nonblocking(fd).is_ok() { + self.nonblocking.set(true); + if let Some(poll) = self.writer.get().get_poll() { + poll.set_flag(bun_io::FilePollFlag::Nonblocking); + } + } + } + + /// Build the stdio sink for `stdio_fd` (1 or 2). Returns a +1 ref. + #[cfg(not(windows))] + pub fn create_stdio( + event_loop: impl Into, + stdio_fd: Fd, + ) -> sys::Result<*mut FileSink> { + debug_assert!(stdio_fd == Fd::stdout() || stdio_fd == Fd::stderr()); + + // Our own fd number for the same description, so a JS `close()`/GC can + // close *something* without ever closing 1/2, and so the poll has an + // fd it owns. + let fd = sys::dup(stdio_fd)?; + let (pollable, is_socket) = match sys::fstat(fd) { + Ok(st) => { + let mode = st.st_mode as sys::Mode; + ( + sys::S::ISFIFO(mode) || sys::S::ISSOCK(mode), + sys::S::ISSOCK(mode), + ) + } + Err(_) => (false, false), + }; + + let this = Self::create(event_loop, fd); + // SAFETY: `this` was just allocated and is the sole reference. + unsafe { + (*this).stdio.set(stdio_fd); + (*this).pollable.set(pollable); + (*this).is_socket.set(is_socket); + // As for any FileSink: only a TTY writes through immediately; + // files / pipes / sockets coalesce `Bun.stdout.writer().write()`s + // until `flush()` / end of tick. (The console and process.stdout + // paths don't go through the coalescing entry point.) + let force_sync = !pollable && sys::isatty(fd); + (*this).force_sync.set(force_sync); + (*this).writer.with_mut(|w| { + w.force_sync = force_sync; + // Idle stdio sinks keep no poll registered; `AutoFlusher` + // flushes coalesced `Bun.stdout.writer()` writes at end of tick. + w.poll_flushes_buffer = false; + }); + (*this).nonblocking.set( + pollable + && !is_socket + && sys::get_fcntl_flags(fd).is_ok_and(|f| f as i32 & sys::O::NONBLOCK != 0), + ); + + // Registered with the loop only while backed up (see `start_lazy`). + if let Err(err) = (*this).writer.with_mut(|w| w.start_lazy(fd, pollable)) { + // The writer may or may not have adopted `fd`; make teardown the + // single owner of closing it. + (*this).writer.with_mut(|w| { + if w.get_fd() == Fd::INVALID { + w.handle = bun_io::pipes::PollOrFd::Fd(fd); + } + }); + FileSink::deref(this); + return Err(err); + } + if let Some(poll) = (*this).writer.get().get_poll() { + poll.set_flag(if is_socket { + bun_io::FilePollFlag::Socket + } else if (*this).nonblocking.get() { + bun_io::FilePollFlag::Nonblocking + } else { + bun_io::FilePollFlag::Fifo + }); + } + (*this).started.set(true); + } + Ok(this) + } + + #[cfg(windows)] + pub fn create_stdio( + event_loop: impl Into, + stdio_fd: Fd, + ) -> sys::Result<*mut FileSink> { + debug_assert!(stdio_fd == Fd::stdout() || stdio_fd == Fd::stderr()); + let this = Self::init(stdio_fd, event_loop); + // SAFETY: `this` was just allocated and is the sole reference. + unsafe { + (*this).stdio.set(stdio_fd); + (*this).force_sync.set(true); + (*this).writer.with_mut(|w| w.owns_fd = false); + if let Err(err) = (*this).writer.with_mut(|w| w.start_sync(stdio_fd, false)) { + FileSink::deref(this); + return Err(err); + } + let evtloop = (*this).io_evtloop(); + (*this).writer.with_mut(|w| w.update_ref(evtloop, false)); + (*this).started.set(true); + } + Ok(this) + } + + /// Write everything queued in the writer to the fd *now*, blocking (via + /// `poll`) if the description is non-blocking and the reader is slow. Used + /// before console output, before fatal-error printing and at exit, so that + /// bytes `process.stdout.write()` had to queue never come out after (or get + /// dropped in favour of) what follows. + /// + /// # Safety + /// `this` must be the canonical live `*mut FileSink` (see + /// [`on_attached_process_exit`](Self::on_attached_process_exit)); settling + /// a pending write schedules a task but never re-enters JS synchronously. + pub unsafe fn drain_sync(this: *mut FileSink) -> sys::Result<()> { + // SAFETY: caller contract. + unsafe { + if !(*this).writer.get().has_pending_data() { + return Ok(()); + } + (*this).refresh_stdio_mode(); + let _lock = bun_io::StdioLock::acquire((*this).stdio.get()); + let _guard = FileSinkRef::new_ref(this); + + let mut result = Ok(()); + loop { + if !(*this).writer.get().has_pending_data() { + break; + } + // SAFETY(JsCell): `flush` is pure I/O; `drain_buffered_data` + // does not call `on_write`. It may call the writer's + // `on_error` (→ `FileSink::on_error`, which only schedules). + match (*this).writer.with_mut(|w| w.flush()) { + WriteResult::Err(err) => { + let err = (*this).stdio_latch_error(err); + if (*this).pending.get().state == streams::PendingState::Pending { + (*this) + .pending + .with_mut(|p| p.result = streams::Writable::Err(err.clone())); + (*this).run_pending_later(); + } + (*this).writer.with_mut(|w| w.end()); + result = Err(err); + break; + } + WriteResult::Done(n) => { + (*this).written.set((*this).written.get() + n); + break; + } + WriteResult::Wrote(n) | WriteResult::Pending(n) => { + (*this).written.set((*this).written.get() + n); + if (*this).writer.get().has_pending_data() { + #[cfg(unix)] + { + let fd = (*this).writer.get().get_fd(); + if fd == Fd::INVALID || !sys::wait_until_writable(fd) { + break; + } + } + } + } + } + } + + // The queue is empty (or the fd is gone): whatever JS was waiting + // on backpressure is settled on the next tick, never from here. + (*this).update_ref(false); + #[cfg(not(windows))] + (*this).writer.with_mut(|w| w.unregister_poll()); + if result.is_ok() && (*this).pending.get().state == streams::PendingState::Pending { + (*this).run_pending_later(); + } + if result.is_ok() { + FileSink::settle_stdio_waiters(this, None); + } + if (*this).source_pending_pull.replace(false) { + let mut src = *(*this).source.get(); + src.ready(None, None); + } + // `drain_buffered_data` reports a write that failed part-way as the + // bytes it did push (routing the error through `on_error`); the + // latch is what says the rest never made it. + match (result, (*this).stdio_error()) { + (Ok(()), Some(err)) => Err(err), + (result, _) => result, + } + } + } + + /// The console path: one fully formatted message (or a spilled part of + /// one), delivered before this returns. Anything already queued goes out + /// first (ordering), then `bytes` are written straight from the caller's + /// buffer. Holds [`bun_io::StdioLock`] for exactly this write — never while + /// formatting or any other JS runs — so no thread can hold one stdio lock + /// while waiting on the other. + /// + /// # Safety + /// Same contract as [`drain_sync`](Self::drain_sync). + pub unsafe fn write_all_sync(this: *mut FileSink, bytes: &[u8]) -> sys::Result<()> { + // SAFETY: caller contract. + unsafe { + let _lock = bun_io::StdioLock::acquire((*this).stdio.get()); + if (*this).writer.get().has_pending_data() { + FileSink::drain_sync(this)?; + } + if let Some(err) = (*this).stdio_error() { + return Err(err); + } + + #[cfg(windows)] + { + // `SyncFile` writes are already a blocking loop. + match (*this).writer.with_mut(|w| w.write(bytes)) { + WriteResult::Err(err) => Err((*this).stdio_latch_error(err)), + WriteResult::Done(n) if n < bytes.len() => { + // The handle went away part-way: say so rather than + // report the tail as written. + Err((*this).stdio_latch_error(sys::Error::from_code( + sys::E::EPIPE, + sys::Tag::write, + ))) + } + _ => { + (*this).written.set((*this).written.get() + bytes.len()); + Ok(()) + } + } + } + + #[cfg(not(windows))] + { + let mut bytes = bytes; + let fd = (*this).writer.get().get_fd(); + if fd == Fd::INVALID { + return Ok(()); + } + while !bytes.is_empty() { + match sys::write_retrying(fd, bytes) { + Ok(0) => { + // No progress on a non-empty buffer: report it + // rather than pretend the tail went out. + let e = (*this).stdio_latch_error(sys::Error::from_code( + sys::E::EIO, + sys::Tag::write, + )); + (*this).writer.with_mut(|w| w.fail(e.clone())); + return Err(e); + } + Ok(n) => { + bytes = &bytes[n..]; + (*this).written.set((*this).written.get() + n); + } + Err(e) => { + // Through the writer's error path, so the sink ends + // up exactly where a failed queued write would leave + // it (fd closed, error latched via `on_error`). + let e = (*this).stdio_latch_error(e); + (*this).writer.with_mut(|w| w.fail(e.clone())); + return Err(e); + } + } + } + Ok(()) + } + } + } + + /// `write()` for a JS `data` value that is a string / ArrayBuffer(View); + /// `Ok(None)` for anything else so the caller can take its general path. + /// `now`: attempt the syscall immediately (`IOWriter::write_now`) rather + /// than coalescing small chunks until end of tick. `count`: also return + /// this call's UTF-8 byte count (a pass over the string; only `Bun.write` + /// wants it) — otherwise the second element is unspecified. + pub fn write_js_value( + &self, + global: &JSGlobalObject, + data: JSValue, + now: bool, + count: bool, + ) -> JsResult> { + if let Some(buffer) = data.as_array_buffer(global) { + let _keep = bun_jsc::EnsureStillAlive(data); + let bytes = buffer.slice(); + if bytes.is_empty() { + return Ok(Some((streams::Writable::Owned(0), 0))); + } + return Ok(Some(self.write_with(Some(bytes.len() as u64), |w| { + if now { + w.write_now(bytes) + } else { + w.write(bytes) + } + }))); + } + if !data.is_string() { + return Ok(None); + } + let str_ = data.to_js_string(global)?; + let view = str_.view(global); + if view.is_empty() { + return Ok(Some((streams::Writable::Owned(0), 0))); + } + let _keep = bun_jsc::EnsureStillAlive(str_.to_js()); + if view.is_16bit() { + let utf16 = view.utf16_slice_aligned(); + let len = + count.then(|| bun_core::strings::element_length_utf16_into_utf8(utf16) as u64); + return Ok(Some(self.write_with(len, |w| { + if now { + w.write_utf16_now(utf16) + } else { + w.write_utf16(utf16) + } + }))); + } + let latin1 = view.slice(); + let len = count.then(|| bun_core::strings::element_length_latin1_into_utf8(latin1) as u64); + Ok(Some(self.write_with(len, |w| { + if now { + w.write_latin1_now(latin1) + } else { + w.write_latin1(latin1) + } + }))) + } + pub(crate) fn setup(&self, options: &Options) -> sys::Result<()> { // SAFETY: JsCell — `Strong::has` is a read-only GC-root probe; no JS re-entry. if unsafe { self.readable_stream.get_mut() }.has() { @@ -819,6 +1332,7 @@ impl FileSink { (*this).auto_flusher.with_mut(|a| a.registered.set(false)); return false; } + (*this).refresh_stdio_mode(); let _guard = FileSinkRef::new_ref(this); @@ -834,14 +1348,30 @@ impl FileSink { // `Owned(consumed)` result `to_result` seeded and // `run_pending_later()` alone would resolve it as if every // buffered byte had reached the reader. Latch the error and - // move the sink to its terminal state (mirrors `end_from_js`). - (*this).done.set(true); + // move the sink to its terminal state (mirrors `end_from_js`); + // a stdio sink stays "open" and re-fails per call instead. + let err = if (*this).is_stdio() { + (*this).stdio_latch_error(err) + } else { + (*this).done.set(true); + err + }; if (*this).pending.get().state == streams::PendingState::Pending { (*this) .pending - .with_mut(|p| p.result = streams::Writable::Err(err)); + .with_mut(|p| p.result = streams::Writable::Err(err.clone())); + } + #[cfg(not(windows))] + if (*this).is_stdio() { + (*this).writer.with_mut(|w| w.fail(err)); + } else { + (*this).writer.with_mut(|w| w.end()); + } + #[cfg(windows)] + { + let _ = err; + (*this).writer.with_mut(|w| w.end()); } - (*this).writer.with_mut(|w| w.end()); (*this).run_pending_later(); (*this).auto_flusher.with_mut(|a| a.registered.set(false)); return false; @@ -895,6 +1425,7 @@ impl FileSink { return sys::Result::Ok(JSValue::UNDEFINED); } + self.refresh_stdio_mode(); // SAFETY(JsCell): `IOWriter::flush` is pure I/O; no JS re-entry while // the `&mut IOWriter` is held. let rc = self.writer.with_mut(|w| w.flush()); @@ -905,6 +1436,9 @@ impl FileSink { self.written.set(self.written.get() + written as usize); // @truncate written as u64 // @truncate } + WriteResult::Err(err) if self.is_stdio() => { + return sys::Result::Err(self.stdio_latch_error(err)); + } WriteResult::Err(err) => { return sys::Result::Err(err); } @@ -1010,36 +1544,46 @@ impl FileSink { } pub fn write(&self, data: &streams::Result) -> streams::Writable { - if self.done.get() { - return streams::Writable::Done; - } - let buffered_before = self.writer.get().buffered_len(); - // SAFETY(JsCell): `IOWriter::write` buffers/writes to fd; does not call JS. - let rc = self.writer.with_mut(|w| w.write(data.slice())); - let accepted = self.bytes_accepted(buffered_before, &rc); - self.to_result(rc, accepted) + self.write_with(None, |w| w.write(data.slice())).0 } pub(crate) fn write_latin1(&self, data: &streams::Result) -> streams::Writable { - if self.done.get() { - return streams::Writable::Done; - } - let buffered_before = self.writer.get().buffered_len(); - // SAFETY(JsCell): `IOWriter::write_latin1` buffers/writes; no JS. - let rc = self.writer.with_mut(|w| w.write_latin1(data.slice())); - let accepted = self.bytes_accepted(buffered_before, &rc); - self.to_result(rc, accepted) + self.write_with(None, |w| w.write_latin1(data.slice())).0 } pub(crate) fn write_utf16(&self, data: &streams::Result) -> streams::Writable { + self.write_with(None, |w| w.write_utf16(data.slice16())).0 + } + + /// The result, plus how many UTF-8 bytes *this call* handed the writer: + /// exact when the caller supplied `encoded_len` (the writer accepts all of + /// its input or errors), else only meaningful for `Pending`. + #[inline] + fn write_with( + &self, + encoded_len: Option, + f: impl FnOnce(&mut IOWriter) -> WriteResult, + ) -> (streams::Writable, u64) { + if let Some(err) = self.stdio_error() { + return (streams::Writable::Err(err), 0); + } + self.refresh_stdio_mode(); if self.done.get() { - return streams::Writable::Done; + return (streams::Writable::Done, 0); } let buffered_before = self.writer.get().buffered_len(); - // SAFETY(JsCell): `IOWriter::write_utf16` buffers/writes; no JS. - let rc = self.writer.with_mut(|w| w.write_utf16(data.slice16())); - let accepted = self.bytes_accepted(buffered_before, &rc); - self.to_result(rc, accepted) + // SAFETY(JsCell): `IOWriter::write*` buffers/writes to fd; does not call JS. + let rc = self.writer.with_mut(f); + // What `to_result` credits a pending operation with. + let pending_credit = self.bytes_accepted(buffered_before, &rc); + let accepted = match rc { + WriteResult::Err(_) => 0, + // `n` may include bytes coalesced by earlier calls and flushed now, + // or be a partial write with the rest queued: not this call's count. + WriteResult::Wrote(n) | WriteResult::Done(n) => encoded_len.unwrap_or(n as u64), + WriteResult::Pending(_) => encoded_len.unwrap_or(pending_credit), + }; + (self.to_result(rc, pending_credit), accepted) } /// Native-path terminator called from `SinkHandle::end`. On upstream error @@ -1073,6 +1617,13 @@ impl FileSink { if self.done.get() { return sys::Result::Ok(()); } + if self.is_stdio() { + // The stdio sink outlives any one JS handle to it: ending + // `Bun.stdout.writer()` flushes, it does not take stdout away from + // `console.log` / `process.stdout`. + // SAFETY: `self` is the canonical RareData-held stdio sink. + return unsafe { FileSink::drain_sync(core::ptr::from_ref(self).cast_mut()) }; + } // A backpressured `write()` may have left its promise in `self.pending`; // `writer.end()` only re-enters `on_close`, which never touches it, so @@ -1156,6 +1707,12 @@ impl FileSink { } pub(crate) fn end_from_js(&self, global_this: &JSGlobalObject) -> sys::Result { + if self.is_stdio() { + // See `end()`: flush, report, stay open. + // SAFETY: `self` is the canonical RareData-held stdio sink. + unsafe { FileSink::drain_sync(core::ptr::from_ref(self).cast_mut()) }?; + return sys::Result::Ok(JSValue::js_number(self.written.get() as f64)); + } if self.done.get() { if self.pending.get().state == streams::PendingState::Pending { if let streams::WritableFuture::Promise { strong, .. } = &self.pending.get().future @@ -1389,7 +1946,12 @@ impl FileSink { } streams::Writable::Temporary(amt as u64) } - WriteResult::Err(err) => streams::Writable::Err(err), + WriteResult::Err(err) => { + if self.is_stdio() { + return streams::Writable::Err(self.stdio_latch_error(err)); + } + streams::Writable::Err(err) + } WriteResult::Pending(_) => { if !self.must_be_kept_alive_until_eof.get() { self.must_be_kept_alive_until_eof.set(true); @@ -1442,6 +2004,12 @@ impl FileSink { force_sync: Cell::new(false), is_socket: Cell::new(false), fd: Cell::new(Fd::INVALID), + stdio: Cell::new(Fd::INVALID), + stdio_js: JsCell::new(bun_jsc::strong::Optional::empty()), + stdio_error: JsCell::new(None), + stdio_waiters: JsCell::new(Vec::new()), + #[cfg(any(target_os = "linux", target_os = "android"))] + stdio_rwf_nowait: Cell::new(false), auto_flusher: JsCell::new(AutoFlusher::default()), run_pending_later: FlushPendingTask::default(), readable_stream: JsCell::new(readable_stream::Strong::default()), @@ -1690,3 +2258,253 @@ bun_jsc::jsc_host_abi! { } } } + +// ─────────────────────────────────────────────────────────────────────────── +// Per-VM stdio sinks: accessor + the link-time externs the lower tiers call. +// ─────────────────────────────────────────────────────────────────────────── + +#[inline] +fn stdio_slot(fd: Fd) -> usize { + debug_assert!(fd == Fd::stdout() || fd == Fd::stderr()); + (fd == Fd::stderr()) as usize +} + +/// The stdio sink for `fd` (1 or 2) on this VM, created on first use. `None` +/// only if the sink could not be created (e.g. `dup` failed because fd 1/2 is +/// closed), in which case callers write to the fd directly. +pub fn stdio_sink_for(vm: &mut bun_jsc::VirtualMachineRef, fd: Fd) -> Option<*mut FileSink> { + if let Some(existing) = existing_stdio_sink(vm, fd) { + return Some(existing); + } + let event_loop = EventLoopHandle::init(vm.event_loop().cast::<()>()); + match FileSink::create_stdio(event_loop, fd) { + Ok(sink) => { + vm.rare_data().stdio_sinks[stdio_slot(fd)] = core::ptr::NonNull::new(sink.cast()); + Some(sink) + } + Err(err) => { + bun_core::scoped_log!(FileSink, "create_stdio({}) failed: {:?}", fd, err); + None + } + } +} + +/// The stdio sink for `fd` if it already exists on this VM (never creates). +pub fn existing_stdio_sink(vm: &mut bun_jsc::VirtualMachineRef, fd: Fd) -> Option<*mut FileSink> { + let rare = vm.rare_data.as_deref_mut()?; + rare.stdio_sinks[stdio_slot(fd)].map(|p| p.as_ptr().cast()) +} + +/// `$newRustFunction("runtime/webcore/FileSink.rs", "writeNow", 2)` — `(sink, chunk)`: the +/// stdio streams' `_write`. Same contract and return values as +/// `FileSink.prototype.write`, except the syscall is attempted immediately +/// instead of coalescing small chunks until end of tick (Node's +/// `process.stdout.write` is a `write(2)` per call, and a child spawned right +/// after must find the bytes already there). +#[bun_jsc::host_fn] +pub(crate) fn write_now(global: &JSGlobalObject, frame: &CallFrame) -> JsResult { + let [sink_value, data] = frame.arguments_as_array::<2>(); + let Some(this) = JSSink::from_js(sink_value) else { + return Err(global.throw(format_args!("This FileSink has already been closed."))); + }; + // SAFETY: `from_js` returned the live `m_ctx` of a `JSFileSink` wrapper. + // (FileSink has no `get_pending_error`, unlike the socket sinks.) + let sink: &FileSink = unsafe { &(*this).sink }; + let _keep = bun_jsc::EnsureStillAlive(data); + match sink.write_js_value(global, data, true, false)? { + Some((result, _)) => Ok(result.to_js(global)), + // Same errors as `FileSink.prototype.write` (Sink.rs `js_write`). + None => Err(global.throw_value(global.to_type_error( + if data.is_empty_or_undefined_or_null() { + bun_jsc::ErrorCode::STREAM_NULL_VALUES + } else { + bun_jsc::ErrorCode::INVALID_ARG_TYPE + }, + format_args!("write() expects a string, ArrayBufferView, or ArrayBuffer"), + ))), + } +} + +/// `JSSink.cpp` `FileSink__doClose`: is this the shared per-thread stdio sink? +#[unsafe(no_mangle)] +extern "C" fn FileSink__isStdio(ptr: *const FileSink) -> bool { + // SAFETY: `ptr` is the live `m_ctx` of a `JSFileSink` wrapper. + unsafe { (*ptr).is_stdio() } +} + +/// `bun_jsc::rare_data::__bun_stdio_sink_deinit` body: release `RareData`'s ref. +#[unsafe(no_mangle)] +unsafe fn __bun_stdio_sink_deinit(ptr: *mut ()) { + if ptr.is_null() { + return; + } + let this = ptr.cast::(); + // SAFETY: `ptr` is the exact +1 `*mut FileSink` `stdio_sink_for` stored; + // JSC is still alive when `release_stdio_sinks` runs, so dropping the + // wrapper root here is sound (the wrapper's own +1 is released by its + // finalizer). + unsafe { + (*this).release_stdio_js(); + // A stdio sink never reaches EOF/close, so a backpressure episode's + // keep-alive ref (`to_result` → `must_be_kept_alive_until_eof`) is + // still held; drop it with RareData's. + FileSink::clear_keep_alive_ref(this); + // User code that closes fds by number behind our back (and anything + // that then reuses and closes that number) can leave our dup already + // closed; tearing down must not trip close()'s use-after-close check. + #[cfg(not(windows))] + { + let fd = (*this).writer.get().get_fd(); + if fd != Fd::INVALID && sys::get_fcntl_flags(fd).is_err() { + (*this).writer.with_mut(|w| { + w.handle + .close_impl(None, None::, false) + }); + (*this).fd.set(Fd::INVALID); + } + } + FileSink::deref(this); + } +} + +/// `bun_jsc::virtual_machine::__bun_stdio_sink_release_js` body: a new global +/// is taking over this VM (`bun test` isolation); the old global's wrapper must +/// not be what the new one's `process.stdout` is built over, nor keep the old +/// realm alive from a VM-lifetime root. +/// +/// # Safety +/// `vm` is the live per-thread VM. +#[unsafe(no_mangle)] +unsafe fn __bun_stdio_sink_release_js(vm: *mut bun_jsc::VirtualMachineRef) { + // SAFETY: caller contract. + let vm = unsafe { &mut *vm }; + for fd in [Fd::stdout(), Fd::stderr()] { + if let Some(sink) = existing_stdio_sink(vm, fd) { + // SAFETY: canonical live pointer held by RareData. + unsafe { (*sink).release_stdio_js() }; + } + } +} + +/// `Bun.file(1|2).writer()` / `Bun.stdout.writer()` / `process.stdout`'s sink: +/// the shared wrapper over this VM's stdio sink, or `None` to fall back to an +/// ordinary FileSink when the stdio sink can't be created. +pub fn stdio_sink_js(global: &JSGlobalObject, fd: Fd) -> Option { + // SAFETY: `bun_vm()` is the live VM owning `global`. + let vm = global.bun_vm().as_mut(); + let sink = stdio_sink_for(vm, fd)?; + // SAFETY: canonical live pointer held by RareData. + Some(unsafe { FileSink::stdio_js(sink, global) }) +} + +/// `bun_jsc::console_object::__bun_stdio_sink_write` body — the console fast +/// path. Delivers `bytes` to fd `fd` through this VM's stdio sink before +/// returning (see [`FileSink::write_all_sync`]). +/// +/// # Safety +/// `vm` is the live per-thread VM. +#[unsafe(no_mangle)] +unsafe fn __bun_stdio_sink_write( + vm: *mut bun_jsc::VirtualMachineRef, + fd: Fd, + bytes: &[u8], +) -> Result<(), sys::Error> { + // SAFETY: caller contract. + let vm = unsafe { &mut *vm }; + match stdio_sink_for(vm, fd) { + // SAFETY: `sink` is the canonical live pointer held by RareData. + Some(sink) => match unsafe { FileSink::write_all_sync(sink, bytes) } { + Ok(()) => Ok(()), + // (The lock is released by now: reporting may print to the other fd.) + Err(err) => { + // Node: a console write that fails surfaces as 'error' on + // process.stdout/stderr *if someone is listening* (the console + // itself swallows it). Same here; never an uncaught exception. + report_stdio_error(vm.global(), fd, &err); + Err(err) + } + }, + None => { + // No sink (fd 1/2 could not be dup'd): best effort straight to the + // fd; there is no stream to report a failure on. + let _lock = bun_io::StdioLock::acquire(fd); + let _ = sys::write_all_retrying(fd, bytes); + Ok(()) + } + } +} + +unsafe extern "C" { + /// `BunProcess.cpp` — `stream.destroy(err)` on Bun's `process.stdout`/ + /// `stderr` object for `fd` iff it exists and has an `'error'` listener. + fn Bun__Process__reportStdioSinkError(global: &JSGlobalObject, fd: i32, err: JSValue); +} + +/// See `__bun_stdio_sink_write`. +fn report_stdio_error(global: &JSGlobalObject, fd: Fd, err: &sys::Error) { + use bun_sys_jsc::ErrorJsc as _; + let Ok(js_err) = err.clone().to_js(global) else { + return; + }; + let n = if fd == Fd::stdout() { 1 } else { 2 }; + // SAFETY: `js_err` is a fresh error object; the C++ side runs a builtin + // under a top-level exception scope and reports (never propagates) a throw. + unsafe { Bun__Process__reportStdioSinkError(global, n, js_err) }; +} + +/// [`bun_sys::set_stdio_write_hook`] target; installed once per process from +/// `init_runtime_state`. Runs on whatever thread `Output` is writing from, so +/// it only ever looks at *that* thread's VM. +pub fn before_output_write(fd: Fd) { + // The crash reporter / a panic prints through `Output` too; it must not + // take the stdio lock or wait on a reader (or touch a writer that may be + // mid-flush on this very stack). + if bun_core::is_panicking() { + return; + } + let Some(vm) = bun_jsc::VirtualMachineRef::get_or_null() else { + return; + }; + // SAFETY: the thread-local VM pointer is live for the thread's lifetime; + // `existing_stdio_sink` only reads `rare_data`. + let vm = unsafe { &mut *vm }; + if let Some(sink) = existing_stdio_sink(vm, fd) { + // SAFETY: canonical live pointer held by RareData; `drain_sync` is a + // no-op unless something is queued. + let _ = unsafe { FileSink::drain_sync(sink) }; + } +} + +/// See [`__bun_stdio_sink_drain`]; one fd. +/// +/// # Safety +/// `vm` is the live per-thread VM. +#[unsafe(no_mangle)] +unsafe fn __bun_stdio_sink_drain_fd(vm: *mut bun_jsc::VirtualMachineRef, fd: Fd) { + // SAFETY: caller contract. + let vm = unsafe { &mut *vm }; + if let Some(sink) = existing_stdio_sink(vm, fd) { + // SAFETY: canonical live pointer held by RareData. + let _ = unsafe { FileSink::drain_sync(sink) }; + } +} + +/// `bun_jsc::virtual_machine::__bun_stdio_sink_drain` body: synchronously drain +/// whatever `process.stdout`/`stderr` writes are still queued on this VM, so +/// what the caller prints next (a fatal error, the exit) cannot overtake or +/// discard them. No-op — not even an allocation — when the sinks were never +/// created. +/// +/// # Safety +/// `vm` is the live per-thread VM. +#[unsafe(no_mangle)] +unsafe fn __bun_stdio_sink_drain(vm: *mut bun_jsc::VirtualMachineRef) { + // SAFETY: caller contract. + let vm = unsafe { &mut *vm }; + for fd in [Fd::stdout(), Fd::stderr()] { + if let Some(sink) = existing_stdio_sink(vm, fd) { + // SAFETY: canonical live pointer held by RareData. + let _ = unsafe { FileSink::drain_sync(sink) }; + } + } +} diff --git a/src/runtime/webcore/blob/copy_file.rs b/src/runtime/webcore/blob/copy_file.rs index 90cf853a9b2e..c9b5983b16e9 100644 --- a/src/runtime/webcore/blob/copy_file.rs +++ b/src/runtime/webcore/blob/copy_file.rs @@ -420,10 +420,18 @@ impl CopyFile { match bun_sys::get_errno(written) { bun_sys::E::SUCCESS => {} + bun_sys::E::EINTR => continue, + // XDEV: cross-device copy not supported // NOSYS: syscall not available // OPNOTSUPP: filesystem doesn't support this operation - bun_sys::E::ENOSYS | bun_sys::E::EXDEV | bun_sys::E::ENOTSUP => { + // AGAIN: either end is a pipe whose description someone made + // O_NONBLOCK (a stdio pipe, typically); the read/write + // loop waits each side out properly. + bun_sys::E::ENOSYS + | bun_sys::E::EXDEV + | bun_sys::E::ENOTSUP + | bun_sys::E::EAGAIN => { // TODO: this should use non-blocking I/O. match read_write_fallback( src_fd, @@ -1009,14 +1017,14 @@ fn read_write_loop_capped( let mut remaining = cap; while remaining > 0 { let want = (buf.len() as SizeType).min(remaining) as usize; - let amt = bun_sys::read(src_fd, &mut buf[..want])?; + let amt = bun_sys::read_retrying(src_fd, &mut buf[..want])?; if amt == 0 { break; } remaining -= amt as SizeType; let mut slice = &buf[..amt]; while !slice.is_empty() { - match bun_sys::write(dest_fd, slice)? { + match bun_sys::write_retrying(dest_fd, slice)? { 0 => return Ok(()), n => { *total += n as u64; diff --git a/src/spawn_sys/posix_spawn.rs b/src/spawn_sys/posix_spawn.rs index 67935bfc0252..8f565c65a858 100644 --- a/src/spawn_sys/posix_spawn.rs +++ b/src/spawn_sys/posix_spawn.rs @@ -615,6 +615,22 @@ pub mod posix_spawn { let uid = attr.and_then(|a| a.uid); let gid = attr.and_then(|a| a.gid); + // A child that inherits one of our stdio fds shares its open file + // description, including an O_NONBLOCK bit our stdio sink may have set + // on a pipe. Hand it over blocking, like libuv does (state is shared, + // so this flips it for us too; `make_stdio_blocking` records that so + // the sinks stop expecting EAGAIN): + // https://github.com/libuv/libuv/blob/v1.51.0/src/unix/process.c#L629-L631 + if let Some(act) = actions { + for action in act.actions.iter() { + if action.kind == bun_spawn::FileActionType::Dup2 + && (0..=2).contains(&action.fds[0]) + { + sys::make_stdio_blocking(Fd::from_native(action.fds[0])); + } + } + } + // Use posix_spawn_bun when: // - Linux: always (uses vfork which is fast and safe) // - macOS: for PTY spawns (pty_slave_fd >= 0) because PTY setup requires diff --git a/src/sys/lib.rs b/src/sys/lib.rs index cf908fe8fec6..b9993772413a 100644 --- a/src/sys/lib.rs +++ b/src/sys/lib.rs @@ -3571,7 +3571,8 @@ pub mod sys_uv; #[cfg(not(windows))] pub mod sys_uv { pub use super::{ - close, fstat, lstat, mkdir, open, pread, pwrite, read, rename, stat, unlink, write, + close, fstat, lstat, mkdir, open, pread, pwrite, read, read_retrying, rename, stat, unlink, + write, write_retrying, }; } @@ -7430,6 +7431,75 @@ pub fn get_fcntl_flags(_fd: Fd) -> Maybe { pub fn set_nonblocking(fd: Fd) -> Maybe<()> { update_nonblocking(fd, true) } +/// Bit `fd` (0–2) is set once something in this process has deliberately put +/// that stdio description back into blocking mode behind the stdio sinks' back +/// (spawn handing it to a child). Sinks that had gone non-blocking check it and +/// stop assuming `EAGAIN` semantics — see `FileSink::refresh_stdio_mode`. +pub static STDIO_MADE_BLOCKING: core::sync::atomic::AtomicU8 = core::sync::atomic::AtomicU8::new(0); + +#[cfg(unix)] +#[inline] +fn stdio_bit(fd: Fd) -> u8 { + match fd.native() { + n @ 0..=2 => 1u8 << n, + _ => 0, + } +} + +/// Clear `O_NONBLOCK` on one of our stdio fds and record it in +/// [`STDIO_MADE_BLOCKING`]. Best effort, like libuv's equivalent: a child is +/// still better off spawned with a non-blocking stdio than not spawned. +#[cfg(unix)] +pub fn make_stdio_blocking(fd: Fd) { + debug_assert!(stdio_bit(fd) != 0); + if update_nonblocking(fd, false).is_ok() { + // AcqRel: the outline-atomics helper for it is already on the aarch64 + // baseline allowlist (scripts/verify-baseline-static). + STDIO_MADE_BLOCKING.fetch_or(stdio_bit(fd), core::sync::atomic::Ordering::AcqRel); + } +} + +/// Whether `fd` is an anonymous pipe (lives on pipefs) rather than a named +/// FIFO opened from a real filesystem. Only the former get `FMODE_NOWAIT` +/// (torvalds/linux@afed6271f5b0), so only they honour `RWF_NOWAIT`; a FIFO +/// answers `EOPNOTSUPP`, which would also switch `RWFFlagSupport` off for the +/// whole process. +#[cfg(any(target_os = "linux", target_os = "android"))] +pub fn is_on_pipefs(fd: Fd) -> bool { + const PIPEFS_MAGIC: u32 = 0x5049_5045; + // SAFETY: all-zero is a valid `statfs`; fstatfs writes it fully on success. + let mut st: libc::statfs = unsafe { core::mem::zeroed() }; + loop { + // SAFETY: `fd` is a plain int; `st` is a live out-param. + let rc = unsafe { libc::fstatfs(fd.native(), &raw mut st) }; + if rc == 0 { + return st.f_type as u32 == PIPEFS_MAGIC; + } + if last_errno() != libc::EINTR { + return false; + } + } +} + +/// `c-bindings.cpp` `bun_restore_stdio_nonblock`: it just put `fd` back to +/// blocking (exit / signal / pre-execve restore); record it like +/// [`make_stdio_blocking`] so a process that survives (failed execve) has its +/// sinks downgrade. +#[cfg(unix)] +#[unsafe(no_mangle)] +pub extern "C" fn Bun__stdioMadeBlocking(fd: core::ffi::c_int) { + if let n @ 0..=2 = fd { + STDIO_MADE_BLOCKING.fetch_or(1u8 << n, core::sync::atomic::Ordering::AcqRel); + } +} + +/// See [`STDIO_MADE_BLOCKING`]. +#[cfg(unix)] +#[inline] +pub fn stdio_made_blocking(fd: Fd) -> bool { + STDIO_MADE_BLOCKING.load(core::sync::atomic::Ordering::Acquire) & stdio_bit(fd) != 0 +} + /// GETFL → toggle O_NONBLOCK → SETFL (only if changed). pub fn update_nonblocking(fd: Fd, nonblocking: bool) -> Maybe<()> { #[cfg(unix)] @@ -9497,19 +9567,126 @@ fn qw_set_fd(qw: &mut bun_core::output::QuietWriter, fd: Fd) { } } +/// Runs before this thread's `Output` bytes go to fd 1 / fd 2. The runtime +/// points it at "flush what this JS thread's `process.stdout`/`stderr` still +/// has queued for that fd" (`bun_runtime::webcore::file_sink`), which is what +/// keeps everything Bun itself prints — errors, the test reporter, prompts — +/// behind output the program already handed to its stdio streams. +static STDIO_WRITE_HOOK: core::sync::atomic::AtomicPtr<()> = + core::sync::atomic::AtomicPtr::new(core::ptr::null_mut()); + +pub fn set_stdio_write_hook(hook: fn(Fd)) { + STDIO_WRITE_HOOK.store(hook as *mut (), core::sync::atomic::Ordering::Release); +} + +#[inline] +fn run_stdio_write_hook(fd: Fd) { + if fd != Fd::stdout() && fd != Fd::stderr() { + return; + } + // Debug logging can fire from inside the sink's own I/O callbacks; never + // re-enter the sink from there. + if bun_core::output::is_inside_scoped_log() { + return; + } + let p = STDIO_WRITE_HOOK.load(core::sync::atomic::Ordering::Acquire); + if !p.is_null() { + // SAFETY: only ever stored from a `fn(Fd)` in `set_stdio_write_hook`. + let hook: fn(Fd) = unsafe { core::mem::transmute::<*mut (), fn(Fd)>(p) }; + hook(fd); + } +} + /// Best-effort write-all loop. Returns `false` on I/O error / zero-write so /// `ScopedLogger::log` can disable the scope; "quiet" callers discard the bool. +/// +/// `EAGAIN` is not an error here: `O_NONBLOCK` lives on the open file +/// description, so anything sharing fd 1/2 with us (a parent shell, a child, +/// libuv in a sibling process, another thread's stdio sink) can flip it at any +/// time. Wait for `POLLOUT` and keep going, which is exactly what a blocking +/// `write(2)` would have done. fn fd_write_all_quiet(fd: Fd, mut bytes: &[u8]) -> bool { + run_stdio_write_hook(fd); while !bytes.is_empty() { match write(fd, bytes) { Ok(0) => return false, // short write → give up Ok(n) => bytes = &bytes[n..], + #[cfg(unix)] + Err(e) if e.get_errno() == E::EINTR => continue, + #[cfg(unix)] + Err(e) if e.is_retry() => { + if !wait_until_writable(fd) { + return false; + } + } Err(_) => return false, } } true } +/// `write(2)` all of `bytes`, waiting out `EAGAIN`/`EINTR`; `false` on a real +/// error. Does not take ownership of (or close) `fd`. +#[inline] +pub fn write_all_retrying(fd: Fd, bytes: &[u8]) -> bool { + fd_write_all_quiet(fd, bytes) +} + +/// One `write(2)` that behaves as if `fd` were blocking regardless of the +/// description's `O_NONBLOCK` bit: `EAGAIN` waits for `POLLOUT`, `EINTR` +/// retries. For copy loops that run off the JS thread and may be handed a +/// stdio pipe someone else made non-blocking. +pub fn write_retrying(fd: Fd, bytes: &[u8]) -> Maybe { + loop { + match write(fd, bytes) { + #[cfg(unix)] + Err(e) if e.get_errno() == E::EINTR => continue, + #[cfg(unix)] + Err(e) if e.is_retry() => { + if !wait_until_writable(fd) { + return Err(e); + } + } + other => return other, + } + } +} + +/// `read(2)` counterpart of [`write_retrying`]. +pub fn read_retrying(fd: Fd, buf: &mut [u8]) -> Maybe { + loop { + match read(fd, buf) { + #[cfg(unix)] + Err(e) if e.get_errno() == E::EINTR => continue, + #[cfg(unix)] + Err(e) if e.is_retry() => { + if !wait_until(fd, posix::POLL_IN) { + return Err(e); + } + } + other => return other, + } + } +} + +/// Block until `fd` reports `POLLOUT` (or `POLLERR`/`POLLHUP`, which the next +/// `write` will turn into a real errno). `false` only if `poll` itself failed. +#[cfg(unix)] +#[inline] +pub fn wait_until_writable(fd: Fd) -> bool { + wait_until(fd, posix::POLL_OUT) +} + +#[cfg(unix)] +fn wait_until(fd: Fd, events: i16) -> bool { + let mut pfd = [posix::PollFd { + fd: fd.native(), + events, + revents: 0, + }]; + posix::poll(&mut pfd, -1).is_ok() +} + /// Concrete repr behind the opaque `bun_core::output::QuietWriterAdapter` /// (`[u8; 64]`). First field MUST be `io::Writer` so `new_interface()`'s /// pointer-cast is sound. Layout asserted below. diff --git a/src/sys/sys_uv.rs b/src/sys/sys_uv.rs index 5044e4abea6b..f4530e709a24 100644 --- a/src/sys/sys_uv.rs +++ b/src/sys/sys_uv.rs @@ -823,6 +823,18 @@ pub fn pwrite(fd: Fd, buf: &[u8], position: i64) -> Result { Result::Ok(total_written) } +/// libuv fs writes are synchronous/blocking here; same as `write`. +#[inline] +pub fn write_retrying(fd: Fd, buf: &[u8]) -> Result { + write(fd, buf) +} + +/// Same as `read` on this backend. +#[inline] +pub fn read_retrying(fd: Fd, buf: &mut [u8]) -> Result { + read(fd, buf) +} + pub fn write(fd: Fd, buf: &[u8]) -> Result { // If buffer fits in a single uv_buf_t, use the simple path if buf.len() <= MAX_BUF_LEN { diff --git a/test/js/node/console/console.test.ts b/test/js/node/console/console.test.ts index 2913817f23c8..d8277fe69e53 100644 --- a/test/js/node/console/console.test.ts +++ b/test/js/node/console/console.test.ts @@ -1,4 +1,5 @@ -import { describe, expect, test } from "bun:test"; +import { describe, expect, spyOn, test } from "bun:test"; +import { bunEnv, bunExe } from "harness"; import { Console } from "node:console"; import { Writable } from "node:stream"; @@ -65,26 +66,275 @@ describe("console.Console", () => { }); }); -test("console._stdout", () => { +// The global console binds its streams lazily through a get/set accessor pair +// (kBindStreamsLazy), so `_stdout` / `_stderr` are accessors, not data +// properties, and assigning them redirects the console: +// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L205-L234 +test.each(["_stdout", "_stderr"] as const)("console.%s", key => { + const stream = key === "_stdout" ? process.stdout : process.stderr; // @ts-ignore - expect(console._stdout).toBe(process.stdout); + expect(console[key]).toBe(stream); - expect(Object.getOwnPropertyDescriptor(console, "_stdout")).toEqual({ - value: process.stdout, - writable: true, - enumerable: false, - configurable: true, - }); + const desc = Object.getOwnPropertyDescriptor(console, key)!; + expect(desc.enumerable).toBe(false); + expect(desc.configurable).toBe(true); + expect(typeof desc.get).toBe("function"); + expect(typeof desc.set).toBe("function"); + expect("value" in desc).toBe(false); }); -test("console._stderr", () => { - // @ts-ignore - expect(console._stderr).toBe(process.stderr); +// ───────────────────────────────────────────────────────────────────────────── +// The global console writes through process.stdout / process.stderr the way +// Node's does (`this._stdout.write(chunk)`), so anything that observes those +// streams observes the console — while, unobserved, it never builds a JS string +// or enters JS at all. Each case runs in a fresh process so stream state does +// not leak between them. +// ───────────────────────────────────────────────────────────────────────────── +async function run(src: string) { + await using proc = Bun.spawn({ + cmd: [bunExe(), "-e", src], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + return { stdout, stderr, exitCode }; +} + +describe.concurrent("global console -> process.stdout / process.stderr", () => { + test("a replaced process.stdout.write / process.stderr.write sees every console method, one write() per call", async () => { + const { stdout, stderr, exitCode } = await run(` + const seen = { out: [], err: [] }; + const { write: ow } = process.stdout, { write: ew } = process.stderr; + process.stdout.write = function (chunk, ...rest) { seen.out.push(String(chunk)); return true; }; + process.stderr.write = function (chunk, ...rest) { seen.err.push(String(chunk)); return true; }; + console.log("log %d", 1); + console.info("info"); + console.debug("debug"); + console.dir({ dir: 1 }); + console.dirxml("dirxml"); + console.table([{ a: 1 }]); + console.count("cnt"); console.count("cnt"); + console.group("grp"); console.log("in group"); console.groupEnd(); + console.time("t"); console.timeLog("t", "extra"); console.timeEnd("t"); + console.warn("warn"); + console.error("error", { e: 1 }); + console.assert(false, "assert %s", "msg"); + console.assert(false); + console.trace("trace"); + process.stdout.write = ow; process.stderr.write = ew; + // Restoring puts the native path back: this arrives, and is not seen. + console.log("restored"); + process.stderr.write(JSON.stringify(seen)); + `); + expect(stdout).toBe("restored\n"); + const seen = JSON.parse(stderr); + // Elapsed times vary; the stack in trace() has a path. + seen.out = seen.out.map((s: string) => s.replace(/: [\d.]+m?s/, ": ")); + seen.err = seen.err.map((s: string) => (s.startsWith("trace\n") ? "trace\n" : s)); + expect(seen).toEqual({ + out: [ + "log 1\n", + "info\n", + "debug\n", + "{\n dir: 1,\n}\n", + "dirxml\n", + "┌───┬───┐\n│ │ a │\n├───┼───┤\n│ 0 │ 1 │\n└───┴───┘\n", + "cnt: 1\n", + "cnt: 2\n", + "grp\n", + " in group\n", + "t: extra\n", + "t: \n", + ], + err: [ + "warn\n", + "error {\n e: 1,\n}\n", + "Assertion failed: assert msg\n", + "Assertion failed\n", + "trace\n", + ], + }); + expect(exitCode).toBe(0); + }); + + test("console._stdout / console._stderr assignment redirects; assigning process.std* back restores", async () => { + const { stdout, stderr, exitCode } = await run(` + const { Writable } = require("node:stream"); + const chunks = []; + const sink = new Writable({ write(c, e, cb) { chunks.push(String(c)); cb(); } }); + console._stdout = sink; + console._stderr = sink; + console.log("to sink"); + console.error("err to sink"); + console._stdout = process.stdout; + console._stderr = process.stderr; + console.log("back"); + console.error(JSON.stringify(chunks)); + `); + expect(stdout).toBe("back\n"); + expect(stderr).toBe('["to sink\\n","err to sink\\n"]\n'); + expect(exitCode).toBe(0); + }); + + test("like Node, the console binds process.stdout on first use: replacing it before that is honoured, after that is not", async () => { + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L205-L234 + const before = await run(` + const { Writable } = require("node:stream"); + const chunks = []; + Object.defineProperty(process, "stdout", { value: new Writable({ write(c, e, cb) { chunks.push(String(c)); cb(); } }), configurable: true, writable: true }); + console.log("first use"); + process.stderr.write(JSON.stringify(chunks)); + `); + expect(before).toEqual({ stdout: "", stderr: '["first use\\n"]', exitCode: 0 }); + + const after = await run(` + const { Writable } = require("node:stream"); + const chunks = []; + console.log("first use"); + Object.defineProperty(process, "stdout", { value: new Writable({ write(c, e, cb) { chunks.push(String(c)); cb(); } }), configurable: true, writable: true }); + console.log("second use"); + process.stderr.write(JSON.stringify(chunks)); + `); + expect(after).toEqual({ stdout: "first use\nsecond use\n", stderr: "[]", exitCode: 0 }); + + // An accessor (what spyOn(process, "stdout", "get") installs) is read + // through its getter once, at bind time; a throwing one surfaces from that + // first console call and binding is retried on the next. + const accessor = await run(` + const { Writable } = require("node:stream"); + const chunks = []; + const sink = new Writable({ write(c, e, cb) { chunks.push(String(c)); cb(); } }); + let calls = 0, armed = true; + Object.defineProperty(process, "stdout", { get() { calls++; if (armed) { armed = false; throw new Error("getter boom"); } return sink; }, configurable: true }); + let first; + try { console.log("lost"); } catch (e) { first = e.message; } + console.log("one"); console.info("two"); + process.stderr.write(JSON.stringify({ first, calls, chunks, same: console._stdout === sink })); + `); + expect(accessor.stdout).toBe(""); + expect(JSON.parse(accessor.stderr)).toEqual({ + first: "getter boom", + calls: 2, + chunks: ["one\n", "two\n"], + same: true, + }); + expect(accessor.exitCode).toBe(0); + }); + + test("cork() holds console output with the stream's other writes until uncork()", async () => { + const { stdout, stderr, exitCode } = await run(` + process.stdout.cork(); + console.log("1 (corked)"); + process.stdout.write("2 (corked)\\n"); + process.stderr.write("[stderr while stdout corked]"); + process.stdout.uncork(); + console.log("3"); + `); + expect(stderr).toBe("[stderr while stdout corked]"); + expect(stdout).toBe("1 (corked)\n2 (corked)\n3\n"); + expect(exitCode).toBe(0); + }); - expect(Object.getOwnPropertyDescriptor(console, "_stderr")).toEqual({ - value: process.stderr, - writable: true, - enumerable: false, - configurable: true, + test("a write() that throws is swallowed; a stack overflow is not (Node kWriteToConsole)", async () => { + // A real runaway recursion takes minutes to overflow in debug/ASAN builds; + // what the console keys on is the engine's stack-overflow RangeError. + const { stdout, stderr, exitCode } = await run(` + process.stdout.write = () => { throw new Error("nope"); }; + console.log("swallowed"); + let threw; + process.stdout.write = () => { throw new RangeError("Maximum call stack size exceeded."); }; + try { console.log("overflow"); } catch (e) { threw = e.constructor.name; } + process.stderr.write(String(threw)); + `); + expect(stdout).toBe(""); + expect(stderr).toBe("RangeError"); + expect(exitCode).toBe(0); }); + + test("adding unrelated own properties to process.stdout keeps the native path (structure re-cached), patching write leaves it", async () => { + // Observable only indirectly: a patched write counts calls; an unpatched + // stream with extra props must still print and must not be 'seen'. + const { stdout, stderr, exitCode } = await run(` + process.stdout._tag = 1; // structure transition, no own write + process.stdout.isTTY = false; + console.log("a"); + let n = 0; + const w = process.stdout.write; + process.stdout.write = function () { n++; return w.apply(this, arguments); }; + console.log("b"); + delete process.stdout.write; // back to the prototype's + console.log("c"); + process.stderr.write(String(n)); + `); + expect(stdout).toBe("a\nb\nc\n"); + expect(stderr).toBe("1"); + expect(exitCode).toBe(0); + }); + + test("console._ignoreErrors is true and console.clear() writes the escape through _stdout when it isTTY", async () => { + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L487-L501 + const { stdout, stderr, exitCode } = await run(` + let buf = ""; + const w = process.stdout.write; + process.stdout.isTTY = true; + process.stdout.write = s => ((buf += s), true); + console.clear(); + process.stdout.isTTY = false; + console.clear(); + process.stdout.write = w; + process.stderr.write(JSON.stringify({ buf, ignore: console._ignoreErrors })); + `); + expect(JSON.parse(stderr)).toEqual({ buf: "\x1b[1;1H\x1b[0J", ignore: true }); + expect(stdout).toBe(""); + expect(exitCode).toBe(0); + }); + + test("diagnostics_channel console.* channels publish the argument list before formatting, only while subscribed", async () => { + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L409-L443 + const { stdout, stderr, exitCode } = await run(` + const dc = require("node:diagnostics_channel"); + const seen = []; + const subs = {}; + for (const name of ["console.log", "console.info", "console.debug", "console.warn", "console.error"]) { + dc.subscribe(name, (subs[name] = args => { seen.push([name, [...args]]); args[0] = "[" + args[0] + "]"; })); + } + console.log("l", 1); console.info("i"); console.debug("d"); console.warn("w"); console.error("e"); + console.dir("not published"); console.table(["nor this"]); + for (const name in subs) dc.unsubscribe(name, subs[name]); + console.log("unsubscribed"); + process.stderr.write("\\n" + JSON.stringify(seen)); + `); + expect(stdout).toBe( + "[l] 1\n[i]\n[d]\nnot published\n" + + "┌───┬──────────┐\n│ │ Values │\n├───┼──────────┤\n│ 0 │ nor this │\n└───┴──────────┘\n" + + "unsubscribed\n", + ); + const nl = stderr.indexOf("\n[["); + expect(stderr.slice(0, nl)).toBe("[w]\n[e]\n"); + expect(JSON.parse(stderr.slice(nl + 1))).toEqual([ + ["console.log", ["l", 1]], + ["console.info", ["i"]], + ["console.debug", ["d"]], + ["console.warn", ["w"]], + ["console.error", ["e"]], + ]); + expect(exitCode).toBe(0); + }); +}); + +// In-process (serial, it patches this process's stdout): exactly what test +// suites (oclif, ink, ...) do. +test("bun:test spyOn(process.stdout, 'write') captures console.log", () => { + const spy = spyOn(process.stdout, "write").mockImplementation(() => true); + let calls: string[]; + try { + console.log("captured %s", "yes"); + console.info({ k: "v" }); + // The runner's own stdout may be a colour TTY; the capture is what matters. + calls = spy.mock.calls.map((c: unknown[]) => Bun.stripANSI(String(c[0]))); + } finally { + spy.mockRestore(); + } + expect(calls).toEqual(["captured yes\n", '{\n k: "v",\n}\n']); }); diff --git a/test/js/node/process/process-stdio.test.ts b/test/js/node/process/process-stdio.test.ts index ba35bc4f0484..0a975f617e7e 100644 --- a/test/js/node/process/process-stdio.test.ts +++ b/test/js/node/process/process-stdio.test.ts @@ -1,6 +1,7 @@ import { spawn, spawnSync } from "bun"; import { describe, expect, test } from "bun:test"; -import { bunEnv, bunExe } from "harness"; +import { bunEnv, bunExe, isASAN, isPosix, tempDirWithFiles } from "harness"; +import { closeSync, constants as fsConstants, openSync, readSync } from "node:fs"; import path from "path"; import { isatty } from "tty"; describe.concurrent("process-stdio", () => { @@ -159,3 +160,514 @@ describe.concurrent("process-stdio", () => { ); }); }); + +// ───────────────────────────────────────────────────────────────────────────── +// One sink per fd: console.*, process.stdout/stderr, Bun.stdout.writer(), +// console.write and Bun.write(Bun.stdout) all go through the same per-VM stdio +// sink, so they can never reorder against each other, never drop bytes when +// the description is O_NONBLOCK, and are fully written before the process +// exits — however the reader paces itself. +// ───────────────────────────────────────────────────────────────────────────── +describe.skipIf(!isPosix).concurrent("stdio sink", () => { + // The describe body runs at collection time even when skipped. + if (!isPosix) return; + // Children that need to read/flip O_NONBLOCK on an fd get these helpers. + // fcntl(2) is variadic; Apple's arm64 ABI passes variadic args on the stack, + // so a fixed-arity dlopen binding gets F_SETFL wrong there — compile tiny + // non-variadic wrappers instead. `cc()` is unavailable under ASAN, so tests + // that use the prelude skip there. + const dir = tempDirWithFiles("stdio-sink", { + "fdutil.c": ` +#include +#include +int fd_is_nonblock(int fd) { int fl = fcntl(fd, F_GETFL); return fl >= 0 && (fl & O_NONBLOCK) != 0; } +int fd_set_nonblock(int fd, int on) { int fl = fcntl(fd, F_GETFL); if (fl < 0) return fl; return fcntl(fd, F_SETFL, on ? (fl | O_NONBLOCK) : (fl & ~O_NONBLOCK)); } +`, + }); + const prelude = ` +const { fd_is_nonblock, fd_set_nonblock } = require("bun:ffi").cc({ + source: ${JSON.stringify(path.join(dir, "fdutil.c"))}, + symbols: { + fd_is_nonblock: { args: ["int"], returns: "int" }, + fd_set_nonblock: { args: ["int", "int"], returns: "int" }, + }, +}).symbols; +const nonblock = fd => fd_is_nonblock(fd) !== 0; +`; + const needsPrelude = { skip: isASAN }; + let fifoCounter = 0; + + /** + * Run `src` in a child whose stdout is the write end of a FIFO that only + * this function reads, a small slice at a time, so a child writing more than + * the pipe holds is queued behind us for most of its life. (Tests that need + * proof of backpressure assert on `write()`'s return value.) + * `Bun.spawn({ stdout: "pipe" })` can't do this: it drains the child eagerly + * into memory. Returns everything the child wrote to fd 1, its stderr, and + * its exit code. + */ + async function runWithSlowStdout(src: string, opts: { env?: Record } = {}) { + const fifo = path.join(dir, `stdout-${fifoCounter++}.fifo`); + expect(spawnSync({ cmd: ["mkfifo", fifo] }).exitCode).toBe(0); + // Reader first (a non-blocking open of the read side never waits for a + // writer), then the writer end for the child, which now opens instantly. + const r = openSync(fifo, fsConstants.O_RDONLY | fsConstants.O_NONBLOCK); + let w = -1; + try { + w = openSync(fifo, "w"); + await using proc = spawn({ + cmd: [bunExe(), "-e", src], + env: { ...bunEnv, ...opts.env }, + stdio: ["ignore", w, "pipe"], + }); + closeSync(w); + w = -1; + let exited = false; + const exitedP = proc.exited.then(code => ((exited = true), code)); + const stderrP = proc.stderr.text(); + + const chunks: Buffer[] = []; + const slice = Buffer.alloc(16 * 1024); + // Poll until EOF (bounded by the test timeout). Correctness never depends + // on this pacing — only how much backpressure the child sees does. + for (;;) { + let n = 0; + try { + n = readSync(r, slice, 0, slice.length, null); + } catch (e: any) { + if (e?.code !== "EAGAIN") throw e; + if (exited) { + // Child is gone; anything left is already in the pipe. + try { + n = readSync(r, slice, 0, slice.length, null); + } catch { + break; + } + if (n === 0) break; + chunks.push(Buffer.from(slice.subarray(0, n))); + continue; + } + await Bun.sleep(2); + continue; + } + if (n === 0) break; + chunks.push(Buffer.from(slice.subarray(0, n))); + await Bun.sleep(1); + } + const [stderr, exitCode] = await Promise.all([stderrP, exitedP]); + return { stdout: Buffer.concat(chunks), stderr, exitCode }; + } finally { + if (w !== -1) closeSync(w); + closeSync(r); + } + } + + /** Collapse runs of a filler byte so mismatches print legibly. */ + const squash = (buf: Buffer) => buf.toString("latin1").replace(/([xyz])\1{15,}/g, (m, c) => `<${c}*${m.length}>`); + + const K256 = 256 * 1024; + + test("process.stdout.write / console.log interleaving keeps call order under pipe backpressure", async () => { + const { stdout, stderr, exitCode } = await runWithSlowStdout(` + const a = process.stdout.write(Buffer.alloc(${K256}, "x")); + console.log("\\nMARK1"); + const b = process.stdout.write(Buffer.alloc(${K256}, "y")); + console.log("\\nMARK2"); + process.stderr.write(JSON.stringify({ a, b, len: process.stdout.writableLength })); + `); + // write() reported backpressure (and writableLength counted the queued + // bytes) — i.e. the sink really was backed up while console.log ran. + expect(JSON.parse(stderr)).toEqual({ a: false, b: false, len: expect.any(Number) }); + expect(JSON.parse(stderr).len).toBeGreaterThan(0); + expect(squash(stdout)).toBe(`\nMARK1\n\nMARK2\n`); + expect(exitCode).toBe(0); + }); + + test("every stdout writer shares one queue: order is call order", async () => { + // console.*, Bun.stdout.writer(), Bun.write(Bun.stdout) and console.write + // hand their bytes to the sink directly; process.stdout.write() does too, + // except for what its Writable is still holding after a write() returned + // false — those chunks are behind the in-flight one *inside the stream*, + // and console.* (being a write() on that stream, as in Node) queues behind + // them. So: everything below is call-ordered, and the two console lines + // issued while `y` is queued come out after `y`. + const { stdout, stderr, exitCode } = await runWithSlowStdout(` + const big = (c) => Buffer.alloc(${K256}, c); + console.log("[console.log]"); + Bun.stdout.writer().write("[Bun.stdout.writer]\\n"); + await Bun.write(Bun.stdout, "[Bun.write]\\n"); + console.write("[console.write]\\n"); + process.stdout.write(big("x")); // fills the pipe, rest queues in the sink + console.log("\\n[after x]"); // drains the sink first, then writes + process.stdout.write(big("y")); // sink backed up -> held in the Writable + console.error("(stderr is separate)"); + console.info("\\n[console.info]"); // a write() on the stream: behind y + process.stdout.write("[end]\\n"); + `); + expect(stderr).toBe("(stderr is separate)\n"); + expect(squash(stdout)).toBe( + `[console.log]\n[Bun.stdout.writer]\n[Bun.write]\n[console.write]\n\n[after x]\n\n[console.info]\n[end]\n`, + ); + expect(exitCode).toBe(0); + }); + + test.each(["process.exit(0)", "throw new Error('boom')", "/* natural */"])( + "queued stdout is fully written before exit via %s", + async how => { + const { stdout, exitCode } = await runWithSlowStdout(` + process.stdout.write(Buffer.alloc(${K256}, "x")); + process.stdout.write(Buffer.alloc(${K256}, "y")); // buffered in the Writable behind the first + console.log("\\nlast console line"); + process.stdout.write("last stream line\\n"); + ${how}; + `); + expect(squash(stdout)).toBe(`\nlast console line\nlast stream line\n`); + expect(exitCode).toBe(how.startsWith("throw") ? 1 : 0); + }, + ); + + test("an uncaught exception is printed after already-written stdout/stderr", async () => { + const { stdout, stderr, exitCode } = await runWithSlowStdout(` + process.stdout.write(Buffer.alloc(${K256}, "x")); + process.stderr.write("before\\n"); + throw new Error("boom"); + `); + expect(squash(stdout)).toBe(``); + expect(stderr.startsWith("before\n")).toBe(true); + expect(stderr).toContain("error: boom"); + expect(exitCode).toBe(1); + }); + + test.skipIf(needsPrelude.skip)( + "materialising process.stdout / process.stderr does not touch fd flags of a tty/file, and stdio-inheriting children get blocking fds", + async () => { + // stdout here is a pipe: Bun may make *its* description non-blocking + // (that is how a slow reader queues instead of stalling the loop), but a + // child handed the fd must see it blocking, and stderr (a file below) + // must never be touched. + const errPath = path.join(tempDirWithFiles("stdio-sink-err", { "err.txt": "" }), "err.txt"); + const { stdout, exitCode } = await runWithSlowStdout( + prelude + + ` + const fs = require("node:fs"); + const errfd = fs.openSync(${JSON.stringify(errPath)}, "w"); + const before = { out: nonblock(1), file: nonblock(errfd) }; + void process.stdout; void process.stderr; + process.stdout.write("x"); + const after = { file: nonblock(errfd) }; + // A child that inherits fd 1 must find it blocking regardless. + const child = Bun.spawnSync([process.execPath, "-e", ${JSON.stringify(prelude + `process.stderr.write(String(nonblock(1)))`)}], { stdio: ["ignore", "inherit", "pipe"], env: process.env }); + // ...and once handed over blocking it stays that way: a later async + // writer must not flip O_NONBLOCK back on under a (possibly still + // running) child. + await Bun.write(Bun.stdout, "y"); + Bun.stdout.writer(); + const stillBlocking = !nonblock(1); + console.log(JSON.stringify({ before, after, childSeesNonblock: child.stderr.toString(), stillBlocking })); + `, + ); + const line = stdout.toString().trim().split("\n").pop()!; + expect(JSON.parse(line.replace(/^xy/, ""))).toEqual({ + before: { out: false, file: false }, + after: { file: false }, + childSeesNonblock: "false", + stillBlocking: true, + }); + expect(exitCode).toBe(0); + }, + ); + + test.skipIf(needsPrelude.skip)( + "console.log delivers every byte when something else made fd 1 O_NONBLOCK and the pipe is full", + async () => { + const { stdout, stderr, exitCode } = await runWithSlowStdout( + prelude + + ` + const fs = require("node:fs"); + fd_set_nonblock(1, 1); + // Fill the pipe until the kernel refuses. + const fill = Buffer.alloc(4096, "x"); + let filled = 0; + for (;;) { try { filled += fs.writeSync(1, fill); } catch { break; } } + process.stderr.write(String(filled)); + for (let i = 0; i < 10; i++) console.log("marker " + i); + `, + ); + const filled = Number(stderr); + expect(filled).toBeGreaterThan(0); + expect(stdout.subarray(0, filled).equals(Buffer.alloc(filled, "x"))).toBe(true); + expect(stdout.subarray(filled).toString()).toBe(Array.from({ length: 10 }, (_, i) => `marker ${i}\n`).join("")); + expect(exitCode).toBe(0); + }, + ); + + test.skipIf(needsPrelude.skip)( + "an idle Worker / worker_threads.Worker does not perturb the parent's stdio", + async () => { + const { stdout, stderr, exitCode } = await runWithSlowStdout( + prelude + + ` + const { Worker } = require("node:worker_threads"); + const before = [nonblock(1), nonblock(2)]; + const w = new Worker("setTimeout(() => {}, 10)", { eval: true }); + await new Promise(r => w.on("online", r)); + const during = [nonblock(1), nonblock(2)]; + await new Promise(r => w.on("exit", r)); + // and the parent's console still delivers everything afterwards + const filler = Buffer.alloc(4000, "p").toString(); + for (let i = 0; i < 40; i++) console.log("line " + i + " " + filler); + process.stderr.write(JSON.stringify({ before, during })); + `, + ); + expect(JSON.parse(stderr)).toEqual({ before: [false, false], during: [false, false] }); + expect(stdout.toString().split("\n").filter(Boolean).length).toBe(40); + expect(exitCode).toBe(0); + }, + ); + + test("Bun.stdout.writer() is the shared sink: same object every time; end()/close() only flush; writes coalesce until flushed", async () => { + await using proc = spawn({ + cmd: [ + bunExe(), + "-e", + ` + const { spawnSync } = require("child_process"); + // A child inheriting fd 1 shows what has actually reached the fd. + const probe = tag => spawnSync(process.execPath, ["-e", "process.stdout.write('<' + process.env.TAG + '>')"], { stdio: "inherit", env: { ...process.env, TAG: tag } }); + const a = Bun.stdout.writer(), b = Bun.stdout.writer(), c = Bun.file(1).writer(); + a.write("1 "); + probe("before-flush"); // "1 " is still in the writer's buffer + await a.end(); + console.log("2"); + a.close(); // must not take stdout away from anyone + process.stdout.write("3 "); // process.stdout.write is a syscall now... + probe("after-write"); // ...so the child lands after it + b.write("4\\n"); + await b.flush(); + console.write("5\\n"); + process.stderr.write(JSON.stringify([a === b, a === c, Bun.stdout.writer() === a])); + `, + ], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe("[true,true,true]"); + expect(stdout).toBe("1 2\n3 4\n5\n"); + expect(exitCode).toBe(0); + }); + + test("FileSink.flush() / end-of-tick autoflush on a full pipe waits for the reader instead of spinning or stalling", async () => { + const { stdout, stderr, exitCode } = await runWithSlowStdout(` + process.stdout.write(Buffer.alloc(${K256}, "x")); // pipe is now full, remainder queued + const w = Bun.stdout.writer(); + w.write("\\n[coalesced]"); // small: sits in the sink's buffer + const flushed = await w.flush(); // must arm the poll and wait + w.write("\\n[autoflushed]\\n"); // left for the end-of-tick flush + await new Promise(r => setImmediate(r)); + process.stderr.write(JSON.stringify({ flushed: typeof flushed })); + `); + expect(JSON.parse(stderr)).toEqual({ flushed: "number" }); + expect(squash(stdout)).toBe(`\n[coalesced]\n[autoflushed]\n`); + expect(exitCode).toBe(0); + }); + + test("Bun.write(Bun.stdout, x) resolves with its own byte count once written, in order, even while process.stdout is backed up", async () => { + const { stdout, stderr, exitCode } = await runWithSlowStdout(` + const backedUp = !process.stdout.write(Buffer.alloc(${K256}, "x")); + const n = await Bun.write(Bun.stdout, "abc"); + const m = await Bun.write(Bun.stdout, new TextEncoder().encode("\\ndef!\\n")); + Bun.stdout.writer().write("[coalesced]"); // still in the writer's buffer... + const k = await Bun.write(Bun.stdout, "h\\u00e9!\\n"); // ...flushed by this, but not counted in it + console.log("after"); + process.stderr.write(JSON.stringify({ backedUp, n, m, k })); + `); + expect(JSON.parse(stderr)).toEqual({ backedUp: true, n: 3, m: 6, k: 5 }); + expect(squash(stdout)).toBe(`abc\ndef!\n[coalesced]h\u00c3\u00a9!\nafter\n`); + expect(exitCode).toBe(0); + }); + + test("writableLength / writableNeedDrain / cork() account for queued bytes, and 'drain' fires", async () => { + const { stdout, stderr, exitCode } = await runWithSlowStdout(` + const so = process.stdout; + const facts = { hwm: so.writableHighWaterMark }; + facts.writeRet = so.write(Buffer.alloc(${K256}, "x")); + facts.writableLength = so.writableLength; + facts.writableNeedDrain = so.writableNeedDrain; + so.cork(); + so.write(Buffer.alloc(1000, "y")); + console.log("\\n(held by cork)"); + facts.corkedLength = so.writableLength; + facts.writableCorked = so.writableCorked; + so.uncork(); + so.once("drain", () => { + facts.drained = { writableLength: so.writableLength, writableNeedDrain: so.writableNeedDrain }; + process.stderr.write(JSON.stringify(facts)); + }); + `); + expect(JSON.parse(stderr)).toEqual({ + hwm: 65536, + writeRet: false, + writableLength: K256, + writableNeedDrain: true, + // 1000 corked bytes + "\\n(held by cork)\\n" (16) queued *behind* them + corkedLength: K256 + 1000 + 16, + writableCorked: 1, + drained: { writableLength: 0, writableNeedDrain: false }, + }); + expect(squash(stdout)).toBe(`\n(held by cork)\n`); + expect(exitCode).toBe(0); + }); + + test("process.stdout.write() is inherited from the prototype (no own write), decodes its encoding argument", async () => { + await using proc = spawn({ + cmd: [ + bunExe(), + "-e", + ` + process.stdout.write("48490a", "hex"); + process.stdout.write("QUJD", "base64"); + process.stdout.setDefaultEncoding("hex"); + process.stdout.write("21"); + process.stderr.write(JSON.stringify({ + own: Object.prototype.hasOwnProperty.call(process.stdout, "write"), + proto: process.stdout.write === Object.getPrototypeOf(process.stdout).write, + })); + `, + ], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(JSON.parse(stderr)).toEqual({ own: false, proto: true }); + expect(stdout).toBe("HI\nABC!"); + expect(exitCode).toBe(0); + }); + + test("process.stdout/stderr.write() still accept a bare ArrayBuffer / SharedArrayBuffer (Bun has always allowed it), with no extra prototype or own write", async () => { + await using proc = spawn({ + cmd: [ + bunExe(), + "-e", + ` + const ab = new TextEncoder().encode("array ").buffer; + const sab = new SharedArrayBuffer(7); + new Uint8Array(sab).set(new TextEncoder().encode("shared\\n")); + process.stdout.write(ab); + process.stdout.write(sab); + process.stderr.write(ab); + const tty = require("node:tty"), fs = require("node:fs"), { Writable } = require("node:stream"); + const proto = Object.getPrototypeOf(process.stdout); + process.stderr.write(String([ + Object.prototype.hasOwnProperty.call(process.stdout, "write"), + proto === tty.WriteStream.prototype || proto === fs.WriteStream.prototype, + process.stdout.write === Writable.prototype.write, + ])); + `, + ], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stdout).toBe("array shared\n"); + expect(stderr).toBe("array false,true,true"); + expect(exitCode).toBe(0); + }); + + test("write after end(): the sync write is ERR_STREAM_WRITE_AFTER_END; after finish the stream is undestroyed and writable again (Node file-stdio semantics)", async () => { + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/bootstrap/switches/is_main_thread.js#L114-L128 + // (dummyDestroy -> _undestroy). Over a pipe Node additionally shuts the + // socket down so later writes EPIPE; Bun keeps fd 1 open (pre-existing, + // deliberate) so it behaves like Node's file case everywhere. + await using proc = spawn({ + cmd: [ + bunExe(), + "-e", + ` + process.stdout.on("error", e => process.stderr.write("[" + e.code + "]")); + process.stdout.write("A"); + process.stdout.end("B"); + process.stdout.write("C"); // still ending -> ERR_STREAM_WRITE_AFTER_END ... + console.log("D"); // ... whose errorOrDestroy -> _destroy -> _undestroy() already made it writable again + setImmediate(() => { + process.stdout.write("E"); + console.log("F"); + process.stderr.write("[done]"); + }); + `, + ], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe("[ERR_STREAM_WRITE_AFTER_END][done]"); + expect(stdout).toBe("ABD\nEF\n"); + expect(exitCode).toBe(0); + }); + + describe("EPIPE", () => { + // stdout's reader goes away before we write. Node: each failed write emits + // 'error' on process.stdout (code EPIPE, syscall write) when listened to; + // console.* never throws. Without a listener a failing process.stdout.write + // is an uncaught 'error'; a failing console.log stays silent (Bun keeps the + // process alive on uncaught errors, so it must not print one per call). + async function run(which: "console.log" | "process.stdout.write", listen: boolean) { + await using proc = spawn({ + cmd: [ + bunExe(), + "-e", + ` + ${listen ? `process.stdout.on("error", e => process.stderr.write("[" + e.code + "/" + e.syscall + "]"));` : ""} + process.on("exit", c => process.stderr.write("[exit " + c + "]")); + // Wait until the parent has closed our stdout. + const buf = Buffer.alloc(1); + require("node:fs").readSync(0, buf, 0, 1, null); + // One write per event-loop turn: an 'error' is delivered per turn + // (destroy -> nextTick emit -> _undestroy), in Node and here alike; + // several failing writes inside one tick coalesce into one 'error'. + for (let i = 0; i < 3; i++) { + ${which}("x" + i + "\\n"); + await new Promise(r => setImmediate(r)); + } + `, + ], + env: bunEnv, + stdin: "pipe", + stdout: "pipe", + stderr: "pipe", + }); + // Drop the read end, then let the child go. + await proc.stdout.cancel(); + proc.stdin.write("g"); + await proc.stdin.end(); + const [stderr, exitCode] = await Promise.all([proc.stderr.text(), proc.exited]); + return { stderr, exitCode }; + } + + test("console.log with an 'error' listener: one 'error' per call, exit 0", async () => { + expect(await run("console.log", true)).toEqual({ + stderr: "[EPIPE/write][EPIPE/write][EPIPE/write][exit 0]", + exitCode: 0, + }); + }); + test("process.stdout.write with an 'error' listener: one 'error' per call, exit 0", async () => { + expect(await run("process.stdout.write", true)).toEqual({ + stderr: "[EPIPE/write][EPIPE/write][EPIPE/write][exit 0]", + exitCode: 0, + }); + }); + test("console.log without a listener is silent", async () => { + expect(await run("console.log", false)).toEqual({ stderr: "[exit 0]", exitCode: 0 }); + }); + test("process.stdout.write without a listener: one uncaught EPIPE, exit 1", async () => { + const { stderr, exitCode } = await run("process.stdout.write", false); + expect(stderr.match(/EPIPE: broken pipe, write/g)?.length).toBe(1); + expect(stderr).toContain("[exit 1]"); + expect(exitCode).toBe(1); + }); + }); +}); diff --git a/test/js/node/process/process-stdout-write-after-end.test.ts b/test/js/node/process/process-stdout-write-after-end.test.ts index 32ceb8f1cc7c..3a51589a5c59 100644 --- a/test/js/node/process/process-stdout-write-after-end.test.ts +++ b/test/js/node/process/process-stdout-write-after-end.test.ts @@ -24,9 +24,15 @@ test.concurrent.each(["stdout", "stderr"] as const)( const lines = reportPipe.trim().split("\n"); const report = JSON.parse(lines[lines.length - 1]); + // The synchronous write() right after end() is rejected (still ending). + // By report time the stream has gone finish -> destroy -> _undestroy (Node + // installs `dummyDestroy` on every stdio stream, pipes included: + // https://github.com/nodejs/node/blob/v24.0.0/lib/internal/bootstrap/switches/is_main_thread.js#L114-L128), + // so it reads as writable again — the same facts `node` (v22–v25) prints + // for this fixture. expect(report).toEqual({ - writableEnded: true, - writable: false, + writableEnded: false, + writable: true, ret: false, cbErr: "ERR_STREAM_WRITE_AFTER_END", ev: ["err:ERR_STREAM_WRITE_AFTER_END"], diff --git a/test/js/node/test/parallel/test-console-clear.js b/test/js/node/test/parallel/test-console-clear.js new file mode 100644 index 000000000000..8ded51595f65 --- /dev/null +++ b/test/js/node/test/parallel/test-console-clear.js @@ -0,0 +1,24 @@ +'use strict'; + +require('../common'); +const assert = require('assert'); + +const stdoutWrite = process.stdout.write; + +// The sequence for moving the cursor to 0,0 and clearing screen down +const check = '\u001b[1;1H\u001b[0J'; + +function doTest(isTTY, check) { + let buf = ''; + process.stdout.isTTY = isTTY; + process.stdout.write = (string) => buf += string; + console.clear(); + process.stdout.write = stdoutWrite; + assert.strictEqual(buf, check); +} + +// Fake TTY +if (process.env.TERM !== 'dumb') { + doTest(true, check); +} +doTest(false, ''); diff --git a/test/js/node/test/parallel/test-console-count.js b/test/js/node/test/parallel/test-console-count.js new file mode 100644 index 000000000000..5c7b26aaa20d --- /dev/null +++ b/test/js/node/test/parallel/test-console-count.js @@ -0,0 +1,65 @@ +'use strict'; + +require('../common'); +const assert = require('assert'); + +const stdoutWrite = process.stdout.write; + +let buf = ''; + +process.stdout.write = (string) => buf = string; + +console.count(); +assert.strictEqual(buf, 'default: 1\n'); + +// 'default' and undefined are equivalent +console.count('default'); +assert.strictEqual(buf, 'default: 2\n'); + +console.count('a'); +assert.strictEqual(buf, 'a: 1\n'); + +console.count('b'); +assert.strictEqual(buf, 'b: 1\n'); + +console.count('a'); +assert.strictEqual(buf, 'a: 2\n'); + +console.count(); +assert.strictEqual(buf, 'default: 3\n'); + +console.count({}); +assert.strictEqual(buf, '[object Object]: 1\n'); + +console.count(1); +assert.strictEqual(buf, '1: 1\n'); + +console.count(null); +assert.strictEqual(buf, 'null: 1\n'); + +console.count('null'); +assert.strictEqual(buf, 'null: 2\n'); + +console.countReset(); +console.count(); +assert.strictEqual(buf, 'default: 1\n'); + +console.countReset('a'); +console.count('a'); +assert.strictEqual(buf, 'a: 1\n'); + +// countReset('a') only reset the a counter +console.count(); +assert.strictEqual(buf, 'default: 2\n'); + +process.stdout.write = stdoutWrite; + +// Symbol labels do not work. Only check that the `Error` is a `TypeError`. Do +// not check the message because it is different depending on the JavaScript +// engine. +assert.throws( + () => console.count(Symbol('test')), + TypeError); +assert.throws( + () => console.countReset(Symbol('test')), + TypeError); diff --git a/test/js/node/test/parallel/test-console-stdio-setters.js b/test/js/node/test/parallel/test-console-stdio-setters.js new file mode 100644 index 000000000000..5a4f511ee97b --- /dev/null +++ b/test/js/node/test/parallel/test-console-stdio-setters.js @@ -0,0 +1,18 @@ +'use strict'; + +// Test that monkeypatching console._stdout and console._stderr works. +const common = require('../common'); + +const { Writable } = require('stream'); + +const streamToNowhere = new Writable({ write: common.mustCall() }); +const anotherStreamToNowhere = new Writable({ write: common.mustCall() }); + +// Overriding the lazy-loaded _stdout and _stderr properties this way is what we +// are testing. Don't change this to be a Console instance from calling a +// constructor. It has to be the global `console` object. +console._stdout = streamToNowhere; +console._stderr = anotherStreamToNowhere; + +console.log('fhqwhgads'); +console.error('fhqwhgads'); diff --git a/test/js/node/worker_threads/worker_threads.test.ts b/test/js/node/worker_threads/worker_threads.test.ts index 543786efcd11..a2660f7f8d34 100644 --- a/test/js/node/worker_threads/worker_threads.test.ts +++ b/test/js/node/worker_threads/worker_threads.test.ts @@ -1817,6 +1817,67 @@ test("the SHARE_ENV founding thread's process.env stays live after the swap", as expect(exitCode).toBe(0); }); +// A worker's console goes through its process.stdout/stderr (port-backed +// Writables that post to the parent, as in Node) — by rebinding the *native* +// console's sink, not by swapping globalThis.console for a JS Console. So the +// worker keeps Bun's console (formatting, console.write, inspector) while its +// output still lands in worker.stdout / the parent's process.stdout. +describe.concurrent("worker console", () => { + test("keeps Bun's console surface and formatting; {stdout,stderr: true} captures it", async () => { + const worker = new Worker( + ` + const util = require("node:util"); + console.log(typeof console.write, typeof console[Symbol.asyncIterator]); + console.log(new Map([["k", "v"]])); // Bun: multi-line, JSON-ish keys + console.log(Bun.inspect(new Map([["k", "v"]])) === util.inspect(new Map([["k", "v"]])) ? "util-fmt" : "bun-fmt"); + console.error("to stderr"); + console.write("raw "); // Bun API, still through worker stdout + process.stdout.write("write\\n"); + `, + { eval: true, stdout: true, stderr: true }, + ); + let out = "", + err = ""; + worker.stdout.setEncoding("utf8").on("data", c => (out += c)); + worker.stderr.setEncoding("utf8").on("data", c => (err += c)); + await Promise.all([once(worker, "exit"), once(worker.stdout, "end"), once(worker.stderr, "end")]); + // Colour follows the parent's real stdout (possibly a TTY under the runner). + out = Bun.stripANSI(out); + err = Bun.stripANSI(err); + expect({ out, err }).toEqual({ + out: 'function function\nMap(1) {\n "k": "v",\n}\nbun-fmt\nraw write\n', + err: "to stderr\n", + }); + }); + + test("without {stdout: true} it flows into the parent's process.stdout, so patching that captures it", async () => { + await using proc = Bun.spawn({ + cmd: [ + bunExe(), + "-e", + ` + const { Worker } = require("node:worker_threads"); + const seen = []; + const w0 = process.stdout.write; + process.stdout.write = function (c) { seen.push(String(c)); return true; }; + const w = new Worker('console.log("from worker"); process.stdout.write("write from worker\\\\n");', { eval: true }); + w.on("exit", () => { + process.stdout.write = w0; + console.log(JSON.stringify(seen)); + }); + `, + ], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe(""); + expect(stdout).toBe('["from worker\\n","write from worker\\n"]\n'); + expect(exitCode).toBe(0); + }); +}); + test("terminating a worker stops the workers it spawned", async () => { // The leaf heartbeats to the main thread over a MessagePort routed through the // middle worker. Terminating the middle worker must stop the leaf, which the main diff --git a/test/js/web/console/console-timeLog.expected.txt b/test/js/web/console/console-timeLog.expected.txt index 464475e83a60..9f61852a6bd0 100644 --- a/test/js/web/console/console-timeLog.expected.txt +++ b/test/js/web/console/console-timeLog.expected.txt @@ -1,18 +1,18 @@ -[0.00ms] label -[0.06ms] label Hello World! -[0.09ms] label a %s b c d -[0.11ms] label 0 -0 123 -123 123.567 -123.567 Infinity -Infinity -[0.14ms] label true false -[0.15ms] label null undefined -[0.17ms] label Symbol(Symbol Description) -[0.22ms] label 2000-06-27T02:24:34.304Z -[0.29ms] label [ 123, 456, 789 ] -[0.34ms] label { +label: 0.006ms +label: 0.06ms Hello World! +label: 0.09ms a %s b c d +label: 0.11ms 0 -0 123 -123 123.567 -123.567 Infinity -Infinity +label: 0.14ms true false +label: 0.15ms null undefined +label: 0.17ms Symbol(Symbol Description) +label: 0.22ms 2000-06-27T02:24:34.304Z +label: 0.29ms [ 123, 456, 789 ] +label: 0.34ms { name: "foo", } -[0.37ms] label { +label: 0.37ms { a: 123, b: 456, c: 789, } -[0.39ms] label +label: 0.39ms diff --git a/test/js/web/console/console-timeLog.test.ts b/test/js/web/console/console-timeLog.test.ts index bf7ddc485e5b..f255c227539d 100644 --- a/test/js/web/console/console-timeLog.test.ts +++ b/test/js/web/console/console-timeLog.test.ts @@ -3,6 +3,12 @@ import { expect, it } from "bun:test"; import { bunEnv, bunExe } from "harness"; import { join } from "node:path"; +// console.timeLog / console.timeEnd print `${label}: ${formatTime(ms)}` through +// console.log, i.e. to stdout: +// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/console/constructor.js#L401-L407 +// https://github.com/nodejs/node/blob/v24.0.0/lib/internal/util/debuglog.js#L155-L187 +const elapsed = /^(.*?): \d+(?:\.\d{1,3})?(?:ms|s)/gm; + it.concurrent("console.timeEnd with empty label emits exactly one trailing newline", async () => { await using proc = Bun.spawn({ cmd: [bunExe(), "-e", `console.time(""); console.timeEnd("");`], @@ -11,8 +17,8 @@ it.concurrent("console.timeEnd with empty label emits exactly one trailing newli stderr: "pipe", }); const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - expect(stdout).toBe(""); - expect(stderr).toMatch(/^\[[\d.]+[mnµ]?s\]\n$/); + expect(stderr).toBe(""); + expect(stdout).toMatch(/^: \d+(\.\d{1,3})?ms\n$/); expect(exitCode).toBe(0); }); @@ -24,25 +30,48 @@ it.concurrent("console.timeEnd with non-empty label emits exactly one trailing n stderr: "pipe", }); const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); - expect(stdout).toBe(""); - expect(stderr).toMatch(/^\[[\d.]+[mnµ]?s\] abc\n$/); + expect(stderr).toBe(""); + expect(stdout).toMatch(/^abc: \d+(\.\d{1,3})?ms\n$/); + expect(exitCode).toBe(0); +}); + +it.concurrent("console.timeEnd / timeLog for a missing label warn instead of printing", async () => { + await using proc = Bun.spawn({ + cmd: [ + bunExe(), + "--no-warnings", // only our listener prints + "-e", + `process.on("warning", w => process.stderr.write("warning: " + w.message + "\\n")); console.timeEnd("nope"); console.timeLog("nope"); console.time("dup"); console.time("dup"); console.timeEnd("dup");`, + ], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect(stderr).toBe( + "warning: No such label 'nope' for console.timeEnd()\n" + + "warning: No such label 'nope' for console.timeLog()\n" + + "warning: Label 'dup' already exists for console.time()\n", + ); + expect(stdout).toMatch(/^dup: \d+(\.\d{1,3})?ms\n$/); expect(exitCode).toBe(0); }); it("should log to console correctly", async () => { - const { stderr, exited } = spawn({ + await using proc = spawn({ cmd: [bunExe(), join(import.meta.dir, "console-timeLog.js")], stdin: null, stdout: "pipe", stderr: "pipe", env: bunEnv, }); - expect(await exited).toBe(0); - const outText = await stderr.text(); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); const expectedText = (await file(join(import.meta.dir, "console-timeLog.expected.txt")).text()).replaceAll( "\r\n", "\n", ); - expect(outText.replace(/^\[.+?s\] /gm, "")).toBe(expectedText.replace(/^\[.+?s\] /gm, "")); + expect(stderr).toBe(""); + expect(stdout.replace(elapsed, "$1: [time]")).toBe(expectedText.replace(elapsed, "$1: [time]")); + expect(exitCode).toBe(0); }); diff --git a/test/napi/napi-app/test_experimental_with_timeout.js b/test/napi/napi-app/test_experimental_with_timeout.js index 8bd34862370e..a0ad8cea0513 100644 --- a/test/napi/napi-app/test_experimental_with_timeout.js +++ b/test/napi/napi-app/test_experimental_with_timeout.js @@ -8,10 +8,17 @@ const modulePath = path.join(__dirname, 'build/Debug/test_reference_unref_in_fin const proc = spawn(process.argv[0], ['--expose-gc', '-e', ` const m = require("${modulePath}"); console.log('Loading experimental module...'); -let arr = m.test_reference_unref_in_finalizer_experimental(); -console.log('Test function returned'); -arr = null; -global.gc ? global.gc() : (process.isBun && Bun.gc ? Bun.gc(true) : null); +// Allocate in a callee frame and scrub the stack afterwards so a conservative +// scan of this frame can't keep the wrapped objects alive past gc() (which is +// what decides whether their finalizers run *during* GC, i.e. whether this +// crashes as it must). +(function () { + m.test_reference_unref_in_finalizer_experimental(); + console.log('Test function returned'); +})(); +(function scrub(n) { return n > 0 ? scrub(n - 1) + 1 : 0; })(128); +const gc = () => (global.gc ? global.gc() : (process.isBun && Bun.gc ? Bun.gc(true) : null)); +gc(); gc(); console.log('GC triggered - should crash now'); console.log('ERROR: Did not crash! Test failed!'); process.exit(1);