diff --git a/src/event_loop/EventLoopTimer.rs b/src/event_loop/EventLoopTimer.rs index b482dec5855f..2e49d3b8ce93 100644 --- a/src/event_loop/EventLoopTimer.rs +++ b/src/event_loop/EventLoopTimer.rs @@ -205,18 +205,17 @@ pub enum Tag { } impl Tag { + /// Whether `jest.useFakeTimers()` captures this timer. Only timers a + /// program schedules itself are faked; runtime-internal timeouts stay on + /// the real clock, as in Jest. A fakeable owner arms with + /// `AllowMockedTime` and has a release arm in `FakeTimers::clear`; every + /// other owner arms with `ForceRealTime`, the clock the real heap is + /// drained against. pub fn allow_fake_timers(self) -> bool { - match self { - Tag::WTFTimer // internal - | Tag::BunTest // for test timeouts - | Tag::EventLoopDelayMonitor // probably important - | Tag::StatWatcherScheduler - | Tag::GcRepeating // internal GC pacing - | Tag::QuicEndpoint - | Tag::DnsSdConnection // internal lookup pacing - => false, - _ => true, - } + matches!( + self, + Tag::TimeoutObject | Tag::AbortSignalTimeout | Tag::CronJob + ) } } diff --git a/src/event_loop/SpawnSyncEventLoop.rs b/src/event_loop/SpawnSyncEventLoop.rs index 336a7da930dd..d91f9c8b7913 100644 --- a/src/event_loop/SpawnSyncEventLoop.rs +++ b/src/event_loop/SpawnSyncEventLoop.rs @@ -380,12 +380,14 @@ impl SpawnSyncEventLoop { /// Tick the isolated event loop with an optional timeout /// This is similar to the main event loop's tick but completely isolated + /// + /// `timeout` is an absolute deadline on the real (never mocked) clock. pub fn tick_with_timeout(&mut self, timeout: Option<&Timespec>) -> TickState { let duration_storage: Option; let duration: Option<&Timespec> = match timeout { Some(ts) => { duration_storage = - Some(ts.duration(&Timespec::now(TimespecMockMode::AllowMockedTime))); + Some(ts.duration(&Timespec::now(TimespecMockMode::ForceRealTime))); duration_storage.as_ref() } None => None, @@ -454,7 +456,7 @@ impl SpawnSyncEventLoop { #[cfg(not(windows))] { self.did_timeout.set( - Timespec::now(TimespecMockMode::AllowMockedTime).order(ts) + Timespec::now(TimespecMockMode::ForceRealTime).order(ts) != core::cmp::Ordering::Less, ); } diff --git a/src/runtime/api/bun/js_bun_spawn_bindings.rs b/src/runtime/api/bun/js_bun_spawn_bindings.rs index 5397137e80f4..698ea5405803 100644 --- a/src/runtime/api/bun/js_bun_spawn_bindings.rs +++ b/src/runtime/api/bun/js_bun_spawn_bindings.rs @@ -1657,8 +1657,7 @@ fn spawn_maybe_sync( // This must go before other things happen so that the exit handler is // registered before onProcessExit can potentially be called. if let Some(timeout_val) = timeout { - let ts = - Timespec::ms_from_now(TimespecMockMode::AllowMockedTime, i64::from(timeout_val)); + let ts = Timespec::ms_from_now(TimespecMockMode::ForceRealTime, i64::from(timeout_val)); // Note: `EventLoopTimer.next` is a local-stub Timespec until // `bun_event_loop` switches to `bun_core::Timespec`; copy fieldwise. subprocess.event_loop_timer.with_mut(|t| { @@ -1875,7 +1874,7 @@ fn spawn_maybe_sync( // This ensures JavaScript timers don't fire and stdin/stdout from the main process aren't affected { let mut absolute_timespec = Timespec::EPOCH; - let mut now = Timespec::now(TimespecMockMode::AllowMockedTime); + let mut now = Timespec::now(TimespecMockMode::ForceRealTime); let mut user_timespec: Timespec = if let Some(timeout_ms) = timeout { now.add_ms(i64::from(timeout_ms)) } else { @@ -1889,8 +1888,14 @@ fn spawn_maybe_sync( if let Some(abort_signal_timeout) = signal.get_timeout() { // Note: `AbortSignal::Timeout.event_loop_timer` uses the // bun_event_loop-local `Timespec` stub; convert fieldwise. + // + // A fake-heap deadline is on the mocked clock, which cannot + // advance while this call blocks; only a real-heap one is + // comparable with `now`. if abort_signal_timeout.event_loop_timer.state == crate::timer::EventLoopTimerState::ACTIVE + && abort_signal_timeout.event_loop_timer.in_heap + == crate::timer::InHeap::Regular { let next = &abort_signal_timeout.event_loop_timer.next; let next_ts = Timespec { @@ -1959,7 +1964,7 @@ fn spawn_maybe_sync( }) { TickState::Completed => {} TickState::Timeout => { - now = Timespec::now(TimespecMockMode::AllowMockedTime); + now = Timespec::now(TimespecMockMode::ForceRealTime); let did_user_timeout = has_user_timespec && (absolute_timespec.eql(&user_timespec) || user_timespec.order(&now) == core::cmp::Ordering::Less); diff --git a/src/runtime/api/cron.rs b/src/runtime/api/cron.rs index 21a816afe646..b492f929e32a 100644 --- a/src/runtime/api/cron.rs +++ b/src/runtime/api/cron.rs @@ -1640,6 +1640,17 @@ impl CronJob { Self::remove_from_list(this, vm); } + /// The fake heap dropped this job's timer (`useRealTimers()` / + /// `clearAllTimers()`): stop the job as `stop()` would, so it does not + /// keep the event loop alive for a timer that can no longer fire. + /// + /// # Safety + /// `this` was recovered from a node just popped off the fake heap and no + /// JS has run since; a scheduled job's wrapper keeps it alive. + pub(crate) unsafe fn stop_dropped_from_fake_heap(this: *mut Self) { + Self::self_stop(this, VirtualMachine::get()); + } + fn self_stop(this: *mut Self, vm: &VirtualMachine) { let this_ref = Self::from_ctx_ptr(this); // While the callback is on the stack or its promise is pending, defer diff --git a/src/runtime/bake/dev_server/hmr_socket.rs b/src/runtime/bake/dev_server/hmr_socket.rs index 1d69aeb581b2..38ef17a2be0a 100644 --- a/src/runtime/bake/dev_server/hmr_socket.rs +++ b/src/runtime/bake/dev_server/hmr_socket.rs @@ -129,7 +129,7 @@ impl HmrSocket { // lives in `RuntimeState` (see jsc_hooks.rs). let state = crate::jsc_hooks::runtime_state(); let next = bun_core::Timespec::ms_from_now( - bun_core::TimespecMockMode::AllowMockedTime, + bun_core::TimespecMockMode::ForceRealTime, 1000, ); // SAFETY: `runtime_state()` is non-null after diff --git a/src/runtime/bake/dev_server/source_map_store.rs b/src/runtime/bake/dev_server/source_map_store.rs index feb1f2866de6..56cae44f9b25 100644 --- a/src/runtime/bake/dev_server/source_map_store.rs +++ b/src/runtime/bake/dev_server/source_map_store.rs @@ -541,7 +541,7 @@ impl SourceMapStore { } let expire = Timespec::ms_from_now( - TimespecMockMode::AllowMockedTime, + TimespecMockMode::ForceRealTime, WEAK_REF_EXPIRY_SECONDS * 1000, ); self.weak_refs diff --git a/src/runtime/dns_jsc/dns.rs b/src/runtime/dns_jsc/dns.rs index d6a9b5e20c41..cb77f288f2af 100644 --- a/src/runtime/dns_jsc/dns.rs +++ b/src/runtime/dns_jsc/dns.rs @@ -4132,7 +4132,7 @@ impl Resolver { self.ref_(); let now_ts = now .copied() - .unwrap_or_else(|| bun::timespec::now(bun::TimespecMockMode::AllowMockedTime)); + .unwrap_or_else(|| bun::timespec::now(bun::TimespecMockMode::ForceRealTime)); let next = now_ts.add_ms(1000); // `EventLoopTimer.next` uses the event-loop crate's local // `Timespec` (distinct from `bun_core::Timespec`); convert by field. diff --git a/src/runtime/socket/UpgradedDuplex.rs b/src/runtime/socket/UpgradedDuplex.rs index af9472e45196..a89d8ea54af2 100644 --- a/src/runtime/socket/UpgradedDuplex.rs +++ b/src/runtime/socket/UpgradedDuplex.rs @@ -607,7 +607,7 @@ impl UpgradedDuplex { // Note: `EventLoopTimer.next` is the lower-tier `ElTimespec` stub; // bridge from `bun_core::Timespec` until the lower tier switches. let next = - bun_core::Timespec::ms_from_now(bun_core::TimespecMockMode::AllowMockedTime, ms as i64); + bun_core::Timespec::ms_from_now(bun_core::TimespecMockMode::ForceRealTime, ms as i64); self.event_loop_timer.with_mut(|t| { t.next = ElTimespec { sec: next.sec, diff --git a/src/runtime/socket/WindowsNamedPipe.rs b/src/runtime/socket/WindowsNamedPipe.rs index 0db18e4cdbdf..1d76a2f5af40 100644 --- a/src/runtime/socket/WindowsNamedPipe.rs +++ b/src/runtime/socket/WindowsNamedPipe.rs @@ -1023,7 +1023,7 @@ impl WindowsNamedPipe { // reschedule the timer // `EventLoopTimer.next` is the lower-tier `ElTimespec` stub; // bridge from `bun_core::Timespec` until the lower tier switches. - let next = timespec::ms_from_now(bun_core::TimespecMockMode::AllowMockedTime, ms as i64); + let next = timespec::ms_from_now(bun_core::TimespecMockMode::ForceRealTime, ms as i64); self.event_loop_timer.with_mut(|t| { t.next = ElTimespec { sec: next.sec, diff --git a/src/runtime/test_runner/timers/FakeTimers.rs b/src/runtime/test_runner/timers/FakeTimers.rs index d26c141a2998..dc350cc4f0bd 100644 --- a/src/runtime/test_runner/timers/FakeTimers.rs +++ b/src/runtime/test_runner/timers/FakeTimers.rs @@ -5,6 +5,7 @@ use bun_threading::RwLock; use bun_core::Environment; use bun_core::Timespec; use bun_jsc::{CallFrame, JSFunction, JSGlobalObject, JSHostFn, JSValue, JsResult}; +use crate::api::cron::CronJob; use crate::jsc::virtual_machine::VirtualMachine; use crate::timer::{ AbortSignalTimeout, ElTimespec, EventLoopTimer, EventLoopTimerState, EventLoopTimerTag, @@ -116,7 +117,7 @@ fn from_el_timespec(t: &ElTimespec) -> Timespec { } /// Owners of the nodes [`FakeTimers::clear`] popped, still to be told their -/// timer is gone. Released only once the `FakeTimers` borrow has ended: both +/// timer is gone. Released only once the `FakeTimers` borrow has ended: these /// paths re-enter `timer::All` (`TimerObjectInternals::cancel` → `All::remove`, /// `Timeout` deinit → `timer_remove`). #[derive(Default)] @@ -132,6 +133,8 @@ struct ClearedTimers { /// pins an observed signal's wrapper for as long as that is set. Only the /// signal's `cancelTimer()` clears it (and frees the box). signal_timeouts: Vec<*mut AbortSignalTimeout>, + /// A `Bun.cron()` job keeps the event loop alive until it is stopped. + cron_jobs: Vec<*mut CronJob>, } impl ClearedTimers { @@ -145,6 +148,13 @@ impl ClearedTimers { // ended before this call. `t` is freed by the call. unsafe { AbortSignalTimeout::discard(t) }; } + for job in self.cron_jobs { + // SAFETY: `clear` popped `job`'s node from the fake heap, so the + // job was scheduled and its JS wrapper (strong while scheduled) + // keeps it alive; no JS has run since; the `FakeTimers` borrow + // ended before this call. + unsafe { CronJob::stop_dropped_from_fake_heap(job) }; + } } } @@ -197,7 +207,14 @@ impl FakeTimers { .signal_timeouts .push(AbortSignalTimeout::from_timer_ptr(timer)); } - _ => {} + EventLoopTimerTag::CronJob => { + cleared.cron_jobs.push(CronJob::from_timer_ptr(timer)); + } + tag => debug_assert!( + false, + "{} timer in the fake heap has no release path", + <&'static str>::from(tag), + ), } } } diff --git a/src/runtime/timer/Timer.rs b/src/runtime/timer/Timer.rs index 99d3b90ed1a1..73eae0ce9d4a 100644 --- a/src/runtime/timer/Timer.rs +++ b/src/runtime/timer/Timer.rs @@ -60,7 +60,7 @@ impl All { vm, // Be careful to avoid adding extra calls to bun.timespec.now() // when it's not needed. - &Timespec::now(TimespecMockMode::AllowMockedTime), + &Timespec::now(TimespecMockMode::ForceRealTime), ); } } diff --git a/src/runtime/timer/mod.rs b/src/runtime/timer/mod.rs index ba0908556a01..61f9e37dcb67 100644 --- a/src/runtime/timer/mod.rs +++ b/src/runtime/timer/mod.rs @@ -400,7 +400,7 @@ impl DateHeaderTimer { // separate allocation from `RuntimeState.timer` so no aliasing with // `&mut self`). let loop_ = vm.uws_loop_mut(); - let now = Timespec::now(TimespecMockMode::AllowMockedTime); + let now = Timespec::now(TimespecMockMode::ForceRealTime); // Record when we last ran it. self.event_loop_timer.next = ElTimespec { diff --git a/src/runtime/valkey_jsc/js_valkey.rs b/src/runtime/valkey_jsc/js_valkey.rs index b2a479cb66e2..473ff53d7155 100644 --- a/src/runtime/valkey_jsc/js_valkey.rs +++ b/src/runtime/valkey_jsc/js_valkey.rs @@ -410,7 +410,7 @@ impl RefCountedTimer { return; } let now = bun_core::Timespec::ms_from_now( - bun_core::TimespecMockMode::AllowMockedTime, + bun_core::TimespecMockMode::ForceRealTime, i64::from(ms), ); self.event_loop_timer.with_mut(|t| { diff --git a/src/sql_jsc/mysql/JSMySQLConnection.rs b/src/sql_jsc/mysql/JSMySQLConnection.rs index bae2128d7a08..76247277935f 100644 --- a/src/sql_jsc/mysql/JSMySQLConnection.rs +++ b/src/sql_jsc/mysql/JSMySQLConnection.rs @@ -257,7 +257,7 @@ impl JSMySQLConnection { } self.timer.with_mut(|t| { - t.next = timespec::ms_from_now(TimespecMockMode::AllowMockedTime, interval.into()); + t.next = timespec::ms_from_now(TimespecMockMode::ForceRealTime, interval.into()); }); // whole-struct provenance: the fire path recovers the container from this pointer. let t = core::ptr::addr_of!(self.timer) @@ -339,7 +339,7 @@ impl JSMySQLConnection { self.max_lifetime_timer.with_mut(|t| { t.next = timespec::ms_from_now( - TimespecMockMode::AllowMockedTime, + TimespecMockMode::ForceRealTime, self.max_lifetime_interval_ms.into(), ); }); diff --git a/src/sql_jsc/postgres/PostgresSQLConnection.rs b/src/sql_jsc/postgres/PostgresSQLConnection.rs index c6cfa4f5db77..8aa1246304ed 100644 --- a/src/sql_jsc/postgres/PostgresSQLConnection.rs +++ b/src/sql_jsc/postgres/PostgresSQLConnection.rs @@ -390,7 +390,7 @@ impl PostgresSQLConnection { return; } t.next = bun_core::Timespec::ms_from_now( - bun_core::TimespecMockMode::AllowMockedTime, + bun_core::TimespecMockMode::ForceRealTime, i64::from(interval), ); }); @@ -500,7 +500,7 @@ impl PostgresSQLConnection { } self.max_lifetime_timer.with_mut(|t| { t.next = bun_core::Timespec::ms_from_now( - bun_core::TimespecMockMode::AllowMockedTime, + bun_core::TimespecMockMode::ForceRealTime, i64::from(self.max_lifetime_interval_ms), ); }); diff --git a/test/js/bun/test/fake-timers/fake-timers.test.ts b/test/js/bun/test/fake-timers/fake-timers.test.ts index e1385766c70c..9b78720b9c1c 100644 --- a/test/js/bun/test/fake-timers/fake-timers.test.ts +++ b/test/js/bun/test/fake-timers/fake-timers.test.ts @@ -1,4 +1,7 @@ +import { RedisClient, SQL } from "bun"; import { heapStats } from "bun:jsc"; +import { bunEnv, bunExe } from "harness"; +import { spawnSync as childProcessSpawnSync } from "node:child_process"; import { afterEach, describe, expect, test, vi } from "vitest"; afterEach(() => vi.useRealTimers()); @@ -273,6 +276,163 @@ describe("AbortSignal.timeout", () => { expect({ aborted: signal.aborted, reasons }).toEqual({ aborted: true, reasons: ["TimeoutError"] }); }); }); +// Only the timers a test schedules itself are faked. Timeouts the runtime arms +// for its own purposes keep running on the real clock: getTimerCount() does not +// count them, they fire while fake timers are active, and useRealTimers(), which +// drops every fake timer, does not disarm them. +describe("runtime timeouts are not fake timers", () => { + // Outlives the 50ms timeout by a wide margin but still exits on its own, so a + // timeout that never fires shows up as a normal exit instead of a hang. + const sleepArgs = ["-e", "await Bun.sleep(3000)"]; + const sleepingChild = () => ({ + cmd: [bunExe(), ...sleepArgs], + env: bunEnv, + stdout: "ignore" as const, + stderr: "ignore" as const, + timeout: 50, + killSignal: "SIGKILL" as const, + }); + + test("Bun.spawn({ timeout }) kills the child while fake timers are active", async () => { + vi.useFakeTimers(); + await using proc = Bun.spawn(sleepingChild()); + expect(vi.getTimerCount()).toBe(0); + await proc.exited; + expect({ exitCode: proc.exitCode, signalCode: proc.signalCode }).toEqual({ exitCode: null, signalCode: "SIGKILL" }); + }); + + test("Bun.spawn({ timeout }) armed under fake timers survives useRealTimers()", async () => { + vi.useFakeTimers(); + await using proc = Bun.spawn(sleepingChild()); + vi.useRealTimers(); + await proc.exited; + expect({ exitCode: proc.exitCode, signalCode: proc.signalCode }).toEqual({ exitCode: null, signalCode: "SIGKILL" }); + }); + + test("Bun.spawnSync({ timeout }) times out while fake timers are active", () => { + vi.useFakeTimers(); + const result = Bun.spawnSync(sleepingChild()); + expect({ exitedDueToTimeout: result.exitedDueToTimeout, signalCode: result.signalCode }).toEqual({ + exitedDueToTimeout: true, + signalCode: "SIGKILL", + }); + }); + + // node:child_process's sync functions hand their timeout to Bun.spawnSync. + test("child_process.spawnSync({ timeout }) times out while fake timers are active", () => { + vi.useFakeTimers(); + const result = childProcessSpawnSync(bunExe(), sleepArgs, { + env: bunEnv, + stdio: "ignore", + timeout: 50, + killSignal: "SIGKILL", + }); + expect({ signal: result.signal, code: result.error?.code }).toEqual({ signal: "SIGKILL", code: "ETIMEDOUT" }); + }); + + // Accepts connections and never answers, so only the client's own connection + // timeout can end a connection attempt. + function silentServer() { + const accepted = Promise.withResolvers(); + const listener = Bun.listen({ + hostname: "127.0.0.1", + port: 0, + socket: { + open() { + accepted.resolve(); + }, + data() {}, + close() {}, + error() {}, + }, + }); + return { + port: listener.port, + accepted: accepted.promise, + [Symbol.dispose]() { + listener.stop(true); + }, + }; + } + + test.each([ + ["postgres", "ERR_POSTGRES_CONNECTION_TIMEOUT"], + ["mysql", "ERR_MYSQL_CONNECTION_TIMEOUT"], + ])("%s connectionTimeout armed under fake timers survives useRealTimers()", async (protocol, code) => { + using server = silentServer(); + vi.useFakeTimers(); + const db = new SQL({ url: `${protocol}://user:pass@127.0.0.1:${server.port}/db`, connectionTimeout: 0.1, max: 1 }); + try { + const connecting = db.connect().then( + () => "connected", + error => error.code, + ); + await server.accepted; + const fakeTimers = vi.getTimerCount(); + vi.useRealTimers(); + expect(fakeTimers).toBe(0); + expect(await connecting).toBe(code); + } finally { + await db.close({ timeout: 0 }); + } + }); + + test("RedisClient connectionTimeout armed under fake timers survives useRealTimers()", async () => { + using server = silentServer(); + vi.useFakeTimers(); + const client = new RedisClient(`redis://127.0.0.1:${server.port}`, { + connectionTimeout: 100, + autoReconnect: false, + }); + try { + const command = client.get("key").then( + () => "replied", + error => error.code, + ); + await server.accepted; + const fakeTimers = vi.getTimerCount(); + vi.useRealTimers(); + expect(fakeTimers).toBe(0); + expect(await command).toBe("ERR_REDIS_CONNECTION_TIMEOUT"); + } finally { + client.close(); + } + }); +}); +// Bun.cron() is mockable, so a job created under fake timers lives in the fake +// heap, and useRealTimers() / clearAllTimers() drop it with the rest. Like a +// dropped setInterval it has to end up stopped, rather than holding the process +// open for a timer that can never fire. +describe("Bun.cron() job dropped from the fake heap", () => { + test.each(["jest.useRealTimers()", "jest.clearAllTimers(); jest.useRealTimers()"])( + "does not keep the process alive after %s", + async drop => { + await using proc = Bun.spawn({ + cmd: [ + bunExe(), + "-e", + `const { jest } = Bun.jest(); + jest.useFakeTimers(); + Bun.cron("* * * * *", () => {}); + ${drop}; + console.log("exiting");`, + ], + env: bunEnv, + stdout: "pipe", + stderr: "pipe", + // A child that hangs (the bug) is killed rather than left behind. + timeout: 10_000, + }); + const [stdout, stderr, exitCode] = await Promise.all([proc.stdout.text(), proc.stderr.text(), proc.exited]); + expect({ stdout, stderr, exitCode, signalCode: proc.signalCode }).toEqual({ + stdout: "exiting\n", + stderr: "", + exitCode: 0, + signalCode: null, + }); + }, + ); +}); describe("isFakeTimers", () => { test("returns true when fake timers are active", () => { expect(vi.isFakeTimers()).toBe(false);