diff --git a/changelog.d/10538-timer-ref-state-eviction.md b/changelog.d/10538-timer-ref-state-eviction.md new file mode 100644 index 0000000000..06f1f5a848 --- /dev/null +++ b/changelog.d/10538-timer-ref-state-eviction.md @@ -0,0 +1,20 @@ +Fixed `timer.unref()` being forgotten after 65,536 later timers (#10447). + +**What broke.** #6084 bounded the id→ref-state registry at 65,536 entries. It evicted by insertion order and never checked whether an id was still scheduled. A live, long-delay `unref()`'d timer was evicted once 65,536 newer timers had been created. The lookup then read the missing id as ref'd, so the process stayed alive until that timer fired and ran a callback the program had detached. rate-limiter-flexible, which creates one timer per key, lingered 12–15 s after a 1M-operation run. The evicted id also dropped out of `is_known_timer_id`, so `.hasRef()`, `.ref()`, `.unref()`, `.constructor` and `+t` stopped resolving on the handle. The id→kind table (`Timeout`/`Immediate`) had the same cap. Once full, it scanned all 65,536 keys for the minimum on every `setTimeout`, so 200k `clearTimeout(setTimeout(f, 1000))` cost 126 billion instructions. + +**Fix.** `crates/perry-runtime/src/timer/ref_states.rs`: +- One registry now holds `has_ref`, `kind` and a `scheduled` flag per id. +- Scheduling returns a `ScheduledTimerId` token that lives in the queue entry itself (`CallbackTimer`, `IntervalTimer`, and the mock-timer entries). Dropping the entry retires the id. Every removal path drops the entry: firing, `clearTimeout`/`clearInterval`/`clearImmediate`, agent purge, and mock clear/reset. +- Only retired ids are eviction candidates, so the map holds at most live timers + 65,536 entries. +- Scheduling does one registry insert, and there is no per-insert scan. +- The whole-queue liveness scans (`ownership.rs`) take the registry lock once per scan instead of once per entry. +- The `timer.rs` filters test `allow_unref` before looking up `has_ref`. +- The registry reports a `timer.ref_states` row in `PERRY_GC_CENSUS`. +- The stale `TIMER_HANDLE_KINDS` entry is removed from `scripts/gc_runtime_root_holders.json`. + +**Validation.** +- The gap test `test_gap_10447_timer_ref_state_eviction` matches Node byte for byte. On the baseline, every handle loses its methods and four unref'd callbacks fire. +- New unit tests in `ref_states.rs` cover: scheduled ids surviving churn, live timers beyond the cap, 1M set+clear cycles staying at 65,536 entries, and an end-to-end churn through the real queues. +- Gap suite: 814/820 pass; the 6 failures are the baseline's known ones. +- Instructions: 200k set+clear −99.3 %, 100k chained `setImmediate` −95.1 %. Below-cap schedule/fire/clear workloads are 4–8 % faster, and `asyncpipe` is flat (+0.1 %). +- Registry size is 65,536 entries after both 1M and 3M set+clear cycles. diff --git a/crates/perry-runtime/src/timer.rs b/crates/perry-runtime/src/timer.rs index e99d6bb8c0..11e5d374b4 100644 --- a/crates/perry-runtime/src/timer.rs +++ b/crates/perry-runtime/src/timer.rs @@ -12,10 +12,9 @@ mod async_lifecycle; use crate::promise::{js_promise_new, js_promise_resolve, Promise}; use async_lifecycle::{enqueue_destroy_ids, IntervalCallback}; use std::any::Any; -use std::collections::HashMap; use std::sync::{ atomic::{AtomicBool, AtomicU64, Ordering}, - LazyLock, Mutex, + Mutex, }; use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH}; @@ -121,15 +120,6 @@ fn schedule_promise_timer(delay_ms: f64, value: f64, has_ref: bool) -> *mut Prom promise } -fn timer_has_ref_state(id: i64) -> bool { - TIMER_REF_STATES - .lock() - .unwrap() - .as_ref() - .and_then(|s| s.states.get(&id).copied()) - .unwrap_or(true) -} - fn other_event_sources_keep_loop_alive() -> bool { has_refed_callback_timer() || has_refed_interval_timer() @@ -337,6 +327,8 @@ struct CallbackTimer { /// in. Only that agent — or a pump acting for it, e.g. Android's UI thread /// for the primary agent — may fire it. owner: crate::agent::AgentId, + /// #10447: pins `id`'s ref state while queued; dropping it retires the id. + _scheduled: ScheduledTimerId, } // SAFETY: the closure POINTER targets global compiled code, but the closure @@ -353,7 +345,6 @@ pub const MOCK_TIMERS_ALL_APIS: u32 = MOCK_TIMERS_API_DATE | MOCK_TIMERS_API_SET_INTERVAL | MOCK_TIMERS_API_SET_IMMEDIATE; -#[derive(Clone)] struct MockCallbackTimer { id: i64, kind: CallbackTimerKind, @@ -362,11 +353,11 @@ struct MockCallbackTimer { args: Vec, context: crate::async_context::AsyncContextSnapshot, cleared: bool, + _scheduled: ScheduledTimerId, } unsafe impl Send for MockCallbackTimer {} -#[derive(Clone)] struct MockIntervalTimer { id: i64, callback: i64, @@ -375,6 +366,7 @@ struct MockIntervalTimer { args: Vec, context: crate::async_context::AsyncContextSnapshot, cleared: bool, + _scheduled: ScheduledTimerId, } unsafe impl Send for MockIntervalTimer {} @@ -416,11 +408,11 @@ use ownership::{has_refed_callback_timer, has_refed_interval_timer, has_refed_pr pub(crate) use ownership::{purge_agent_timers, timer_phase_work_pending}; pub(crate) use gc_scan::{new_timer_root_scan_state, scan_timer_roots_mut_step}; -use ref_states::{TimerRefStates, TIMER_REF_STATES_CAP}; +use ref_states::{ + register_scheduled_timer, set_timer_ref_state, timer_handle_kind, timer_has_ref_state, + ScheduledTimerId, +}; -static TIMER_REF_STATES: Mutex> = Mutex::new(None); -static TIMER_HANDLE_KINDS: LazyLock>> = - LazyLock::new(|| Mutex::new(HashMap::new())); static WARNED_NEGATIVE_TIMER_DELAY: AtomicBool = AtomicBool::new(false); static WARNED_NAN_TIMER_DELAY: AtomicBool = AtomicBool::new(false); @@ -607,29 +599,12 @@ fn normalize_timer_delay(delay_value: f64) -> u64 { } } -fn set_timer_ref_state(id: i64, has_ref: bool) { - ref_states::TIMER_IDS_NONEMPTY.arm(); - let mut slot = TIMER_REF_STATES.lock().unwrap(); - slot.get_or_insert_with(TimerRefStates::default) - .insert_bounded(id, has_ref, TIMER_REF_STATES_CAP); -} - -fn record_timer_handle_kind(id: i64, kind: CallbackTimerKind) { - let mut kinds = TIMER_HANDLE_KINDS.lock().unwrap(); - if kinds.len() >= TIMER_REF_STATES_CAP && !kinds.contains_key(&id) { - if let Some(oldest) = kinds.keys().copied().min() { - kinds.remove(&oldest); - } - } - kinds.insert(id, kind); -} - /// Synthetic constructor object for `Timeout`/`Immediate` native handles. -/// Timer ids outlive queue removal, so the kind table retains recent entries +/// Timer ids outlive queue removal, so the registry retains recent entries /// after clear/fire just as Node retains the wrapper's prototype. The bounded /// inventory avoids unbounded growth in long-running processes. pub(crate) fn timer_constructor_value(id: i64) -> Option { - let kind = TIMER_HANDLE_KINDS.lock().unwrap().get(&id).copied()?; + let kind = timer_handle_kind(id)?; let name = match kind { CallbackTimerKind::Timeout => b"Timeout".as_slice(), CallbackTimerKind::Immediate => b"Immediate".as_slice(), @@ -764,7 +739,7 @@ fn schedule_mock_callback_timer( let arg_handles = scope.root_nanbox_f64_slice(&args); let delay = normalize_timer_delay(delay_ms); let id = next_timer_id(); - record_timer_handle_kind(id, kind); + let scheduled = register_scheduled_timer(id, kind); let due_ms = state.current_ms + delay as f64; state.callbacks.push(MockCallbackTimer { id, @@ -774,8 +749,8 @@ fn schedule_mock_callback_timer( args: crate::gc::RuntimeHandleScope::refreshed_nanbox_f64_slice(&arg_handles), context: crate::async_context::capture_context(), cleared: false, + _scheduled: scheduled, }); - set_timer_ref_state(id, true); Some(id) } @@ -790,7 +765,7 @@ fn schedule_mock_interval_timer(callback: i64, interval_ms: f64, args: Vec) let arg_handles = scope.root_nanbox_f64_slice(&args); let interval = normalize_timer_delay(interval_ms); let id = next_timer_id(); - record_timer_handle_kind(id, CallbackTimerKind::Timeout); + let scheduled = register_scheduled_timer(id, CallbackTimerKind::Timeout); let next_ms = state.current_ms + interval as f64; state.intervals.push(MockIntervalTimer { id, @@ -800,8 +775,8 @@ fn schedule_mock_interval_timer(callback: i64, interval_ms: f64, args: Vec) args: crate::gc::RuntimeHandleScope::refreshed_nanbox_f64_slice(&arg_handles), context: crate::async_context::capture_context(), cleared: false, + _scheduled: scheduled, }); - set_timer_ref_state(id, true); Some(id) } @@ -840,10 +815,14 @@ fn mock_timers_advance_to(target_ms: f64) { }; state.current_ms = due_ms; if is_interval { - let timer = state.intervals[idx].clone(); - let interval = timer.interval_ms.max(1) as f64; - state.intervals[idx].next_ms = due_ms + interval; - Some((timer.id, timer.callback, timer.args, timer.context)) + let timer = &mut state.intervals[idx]; + timer.next_ms = due_ms + timer.interval_ms.max(1) as f64; + Some(( + timer.id, + timer.callback, + timer.args.clone(), + timer.context.clone(), + )) } else { let timer = state.callbacks.remove(idx); Some((timer.id, timer.callback, timer.args, timer.context)) @@ -904,12 +883,7 @@ pub extern "C" fn js_timer_has_ref(timer_id: i64) -> i32 { // user explicitly called `.unref()` on the handle. Default `true` for // any non-timer id is harmless since the dispatcher gates on // `is_known_timer_id` first. - TIMER_REF_STATES - .lock() - .unwrap() - .as_ref() - .and_then(|s| s.states.get(&timer_id).copied()) - .unwrap_or(true) as i32 + timer_has_ref_state(timer_id) as i32 } #[no_mangle] @@ -1087,7 +1061,7 @@ fn schedule_callback_timer( let deadline = Instant::now() + Duration::from_millis(delay_ms); let id = next_timer_id(); - record_timer_handle_kind(id, kind); + let scheduled = register_scheduled_timer(id, kind); let mut context = crate::async_context::capture_context(); let context_roots = crate::async_context::root_snapshot(&scope, &context); @@ -1118,8 +1092,8 @@ fn schedule_callback_timer( cleared: false, // #6185: the scheduling agent owns the callback closure + args. owner: crate::agent::current_agent(), + _scheduled: scheduled, }); - set_timer_ref_state(id, true); id } @@ -1263,7 +1237,7 @@ pub extern "C" fn js_callback_timer_tick() -> i32 { |timer| { crate::agent::owns(timer.owner) && timer.deadline <= now - && (timer_has_ref_state(timer.id) || allow_unref) + && (allow_unref || timer_has_ref_state(timer.id)) }, ) }; @@ -1444,7 +1418,7 @@ pub extern "C" fn js_callback_timer_next_deadline() -> f64 { .unwrap() .iter() .filter(|t| { - !t.cleared && crate::agent::owns(t.owner) && (timer_has_ref_state(t.id) || allow_unref) + !t.cleared && crate::agent::owns(t.owner) && (allow_unref || timer_has_ref_state(t.id)) }) .map(|t| { if t.deadline <= now { @@ -1573,6 +1547,8 @@ struct IntervalTimer { cleared: bool, /// #6185: agent that owns `callback` / `args`. See `CallbackTimer::owner`. owner: crate::agent::AgentId, + /// #10447: see `CallbackTimer::_scheduled`. + _scheduled: ScheduledTimerId, } // SAFETY: see `CallbackTimer` — the owner tag plus owner-filtered ticking is @@ -1604,7 +1580,7 @@ fn schedule_interval_timer(callback: i64, interval_ms: f64, args: Vec) -> i let next_deadline = Instant::now() + Duration::from_millis(interval); let id = next_timer_id(); - record_timer_handle_kind(id, CallbackTimerKind::Timeout); + let scheduled = register_scheduled_timer(id, CallbackTimerKind::Timeout); let mut context = crate::async_context::capture_context(); let context_roots = crate::async_context::root_snapshot(&scope, &context); @@ -1623,8 +1599,8 @@ fn schedule_interval_timer(callback: i64, interval_ms: f64, args: Vec) -> i cleared: false, // #6185: the scheduling agent owns the callback closure + args. owner: crate::agent::current_agent(), + _scheduled: scheduled, }); - set_timer_ref_state(id, true); id } @@ -1700,7 +1676,7 @@ pub extern "C" fn js_interval_timer_tick() -> i32 { if !timer.cleared && crate::agent::owns(timer.owner) && timer.next_deadline <= now - && (timer_has_ref_state(timer.id) || allow_unref) + && (allow_unref || timer_has_ref_state(timer.id)) { callbacks.push(( timer.id, @@ -1788,7 +1764,7 @@ pub extern "C" fn js_interval_timer_next_deadline() -> f64 { .unwrap() .iter() .filter(|t| { - !t.cleared && crate::agent::owns(t.owner) && (timer_has_ref_state(t.id) || allow_unref) + !t.cleared && crate::agent::owns(t.owner) && (allow_unref || timer_has_ref_state(t.id)) }) .map(|t| { if t.next_deadline <= now { @@ -1933,7 +1909,7 @@ mod tests_inline; #[cfg(test)] pub(crate) use tests_inline::*; -/// `PERRY_GC_CENSUS`: the three timer queues. +/// `PERRY_GC_CENSUS`: the three timer queues and the id registry. pub(crate) fn timer_tables_census() -> Vec { use crate::gc::census::vec_bytes; let mut rows = Vec::new(); @@ -1948,5 +1924,6 @@ pub(crate) fn timer_tables_census() -> Vec { let inner: usize = v.iter().map(|t| vec_bytes(&t.args)).sum(); rows.push(("timer.interval_timers", v.len(), vec_bytes(&v) + inner)); } + rows.push(ref_states::ref_states_census()); rows } diff --git a/crates/perry-runtime/src/timer/ownership.rs b/crates/perry-runtime/src/timer/ownership.rs index 21918a9ca7..6bb64a28dc 100644 --- a/crates/perry-runtime/src/timer/ownership.rs +++ b/crates/perry-runtime/src/timer/ownership.rs @@ -8,7 +8,8 @@ //! ownership: per-agent event-loop liveness, and what happens to an agent's //! timers when the agent itself goes away. -use super::{timer_has_ref_state, CALLBACK_TIMERS, INTERVAL_TIMERS, TIMER_QUEUE}; +use super::ref_states::with_ref_states; +use super::{CALLBACK_TIMERS, INTERVAL_TIMERS, TIMER_QUEUE}; /// Any entry needs the ordinary timer phase, including unref timers and /// cleared entries whose cleanup has not run. Foreign entries conservatively @@ -38,16 +39,27 @@ pub(super) fn has_refed_promise_timer() -> bool { .any(|timer| timer.has_ref && crate::agent::owns(timer.owner)) } +// The ref state lives in the id registry (`ref_states.rs`); a scan reads it +// under one registry lock rather than one per entry. + pub(super) fn has_refed_callback_timer() -> bool { - CALLBACK_TIMERS.lock().unwrap().iter().any(|timer| { - !timer.cleared && crate::agent::owns(timer.owner) && timer_has_ref_state(timer.id) - }) + let timers = CALLBACK_TIMERS.lock().unwrap(); + !timers.is_empty() + && with_ref_states(|states| { + timers.iter().any(|timer| { + !timer.cleared && crate::agent::owns(timer.owner) && states.has_ref(timer.id) + }) + }) } pub(super) fn has_refed_interval_timer() -> bool { - INTERVAL_TIMERS.lock().unwrap().iter().any(|timer| { - !timer.cleared && crate::agent::owns(timer.owner) && timer_has_ref_state(timer.id) - }) + let timers = INTERVAL_TIMERS.lock().unwrap(); + !timers.is_empty() + && with_ref_states(|states| { + timers.iter().any(|timer| { + !timer.cleared && crate::agent::owns(timer.owner) && states.has_ref(timer.id) + }) + }) } /// Drop every timer owned by `agent`. Called from `crate::agent::retire_agent` diff --git a/crates/perry-runtime/src/timer/ref_states.rs b/crates/perry-runtime/src/timer/ref_states.rs index e82b54dcf7..f8302edec2 100644 --- a/crates/perry-runtime/src/timer/ref_states.rs +++ b/crates/perry-runtime/src/timer/ref_states.rs @@ -1,76 +1,403 @@ -//! #6084: bounded id→ref-state registry for scheduled timers, extracted from -//! `timer.rs` to keep that file under the 2000-line lint cap. +//! #6084 / #10447: bounded id→handle-state registry for scheduled timers (ref +//! state and `Timeout`/`Immediate` kind), extracted from `timer.rs` to keep that +//! file under the 2000-line lint cap. +use super::CallbackTimerKind; use std::collections::{HashMap, VecDeque}; +use std::sync::{Mutex, MutexGuard, PoisonError}; -/// id → ref-state registry for scheduled timers. Entries are kept after -/// `clearTimeout`/`clearInterval` so post-clear `.hasRef()`/`.unref()`/`+timer` +/// What the registry knows about one timer id. +#[derive(Clone, Copy)] +struct TimerHandleState { + has_ref: bool, + /// `Timeout`/`Immediate` for `.constructor`; `None` for an id that only + /// ever reached `ref()`/`unref()`. + kind: Option, + /// Still has a queue entry: not fired, not cleared. Never evicted. + scheduled: bool, +} + +/// id → handle-state registry for timers. Entries are kept after the timer is +/// cleared or fires so post-clear `.hasRef()`/`.unref()`/`+timer`/`.constructor` /// still route through timer dispatch (Node keeps the Timeout object alive). /// They used to be inserted and *never* removed — a permanent per-id leak for a /// process that creates unboundedly many timers (e.g. a `setTimeout` per -/// request). The insertion-ordered eviction queue bounds the map: the cap is -/// large enough that a realistic "hold the handle, call `.hasRef()` after -/// clear" pattern never sees eviction, but a long-running process no longer -/// grows it without limit. Timer ids are monotonic (never reused), so an -/// evicted id is never re-queried in practice. +/// request, #6084). The bound that fixed it evicted the oldest ids whether or +/// not they were still scheduled, so 65,536 later timers silently undid a live +/// long-delay timer's `unref()` (a missing id reads as ref'd, and the process +/// stayed alive until the timer fired) and dropped it from `is_known_timer_id` +/// (#10447). Only RETIRED ids — fired or cleared, queued in `retired` — are +/// eviction candidates now; a scheduled id is pinned by its queue entry's +/// [`ScheduledTimerId`]. The map is bounded by live timers + `cap`. #[derive(Default)] pub(super) struct TimerRefStates { - pub(super) states: HashMap, - order: VecDeque, + states: HashMap, + /// Retired ids, oldest first — the only eviction candidates. + retired: VecDeque, } pub(super) const TIMER_REF_STATES_CAP: usize = 65_536; impl TimerRefStates { - /// Insert/overwrite `id`'s ref state, bounding the registry to `cap` entries - /// by evicting the oldest ids. Only a new id extends the eviction queue; a - /// ref/unref change on an existing id just overwrites its value. - pub(super) fn insert_bounded(&mut self, id: i64, has_ref: bool, cap: usize) { - if self.states.insert(id, has_ref).is_none() { - self.order.push_back(id); - while self.order.len() > cap { - if let Some(old) = self.order.pop_front() { - self.states.remove(&old); - } + /// A newly scheduled timer: ref'd, pinned until [`Self::retire`]. + fn schedule(&mut self, id: i64, kind: CallbackTimerKind) { + let state = TimerHandleState { + has_ref: true, + kind: Some(kind), + scheduled: true, + }; + self.states.insert(id, state); + } + + /// `ref()`/`unref()`. An id the registry does not hold (never scheduled, or + /// retired and since evicted) is recorded as retired, so it stays bounded. + fn set_ref(&mut self, id: i64, has_ref: bool, cap: usize) { + if let Some(state) = self.states.get_mut(&id) { + state.has_ref = has_ref; + return; + } + let state = TimerHandleState { + has_ref, + kind: None, + scheduled: false, + }; + self.states.insert(id, state); + self.push_retired(id, cap); + } + + /// The timer's queue entry is gone: keep its state for post-clear dispatch, + /// but make it evictable. Idempotent, and a no-op for an unknown id. + fn retire(&mut self, id: i64, cap: usize) { + if let Some(state) = self.states.get_mut(&id) { + if state.scheduled { + state.scheduled = false; + self.push_retired(id, cap); + } + } + } + + fn push_retired(&mut self, id: i64, cap: usize) { + self.retired.push_back(id); + while self.retired.len() > cap { + let Some(old) = self.retired.pop_front() else { + break; + }; + // Timer ids are monotonic, so a retired id is not rescheduled in + // practice; the check still never lets eviction drop a live entry. + if self.states.get(&old).is_some_and(|state| !state.scheduled) { + self.states.remove(&old); } } } + + fn get(&self, id: i64) -> Option { + self.states.get(&id).copied() + } +} + +static TIMER_REF_STATES: Mutex> = Mutex::new(None); + +/// Poison-tolerant: [`ScheduledTimerId`]'s drop takes this lock during unwinds. +fn lock_states() -> MutexGuard<'static, Option> { + TIMER_REF_STATES + .lock() + .unwrap_or_else(PoisonError::into_inner) +} + +/// A scheduled timer's pin on its registry entry. It lives IN the queue entry +/// (`CallbackTimer`, `IntervalTimer`, the mock-timer entries), so every path +/// that removes one — firing, `clearTimeout`/`clearInterval`/`clearImmediate`, +/// `purge_agent_timers`, a mock-timers reset — retires the id by dropping it, +/// and no removal site can forget to. Deliberately not `Clone`: a dropped copy +/// would retire a timer that is still queued. +/// +/// Dropping takes the registry lock, so never drop a timer entry while holding +/// it (the only nesting is queue lock → registry lock). +pub(super) struct ScheduledTimerId(i64); + +impl Drop for ScheduledTimerId { + fn drop(&mut self) { + if let Some(states) = lock_states().as_mut() { + states.retire(self.0, TIMER_REF_STATES_CAP); + } + } +} + +#[cfg(test)] +impl ScheduledTimerId { + /// For test scaffolding entries whose ids were never registered. + pub(super) fn unregistered() -> Self { + Self(i64::MIN) + } +} + +/// Register a timer id as scheduled (ref'd, with its handle kind). Runs before +/// the id is observable — the async_hooks `init` hook already sees the handle. +pub(super) fn register_scheduled_timer(id: i64, kind: CallbackTimerKind) -> ScheduledTimerId { + TIMER_IDS_NONEMPTY.arm(); + lock_states() + .get_or_insert_with(TimerRefStates::default) + .schedule(id, kind); + ScheduledTimerId(id) +} + +pub(super) fn set_timer_ref_state(id: i64, has_ref: bool) { + TIMER_IDS_NONEMPTY.arm(); + lock_states() + .get_or_insert_with(TimerRefStates::default) + .set_ref(id, has_ref, TIMER_REF_STATES_CAP); +} + +fn timer_handle_state(id: i64) -> Option { + lock_states().as_ref().and_then(|states| states.get(id)) +} + +/// Node's `hasRef()` default is `true`, so an id the registry does not hold +/// reads as ref'd. A scheduled timer's id is always held (#10447). +pub(super) fn timer_has_ref_state(id: i64) -> bool { + timer_handle_state(id).map_or(true, |state| state.has_ref) +} + +pub(super) fn timer_handle_kind(id: i64) -> Option { + timer_handle_state(id).and_then(|state| state.kind) +} + +/// Read-only view for a whole-queue liveness scan, under ONE registry lock +/// instead of one per entry. +pub(super) struct RefStatesView<'a>(Option<&'a TimerRefStates>); + +impl RefStatesView<'_> { + pub(super) fn has_ref(&self, id: i64) -> bool { + self.0 + .and_then(|states| states.get(id)) + .map_or(true, |state| state.has_ref) + } +} + +/// `f` must not drop a timer entry (see [`ScheduledTimerId`]). +pub(super) fn with_ref_states(f: impl FnOnce(&RefStatesView<'_>) -> R) -> R { + let guard = lock_states(); + f(&RefStatesView(guard.as_ref())) +} + +/// `PERRY_GC_CENSUS` row for the registry. +pub(super) fn ref_states_census() -> crate::gc::census::SideTableRow { + let guard = lock_states(); + let (len, bytes) = guard.as_ref().map_or((0, 0), |states| { + let deque = states.retired.capacity() * std::mem::size_of::(); + let map = crate::gc::census::map_bytes(&states.states); + (states.states.len(), map + deque) + }); + ("timer.ref_states", len, bytes) +} + +#[cfg(test)] +pub(crate) fn test_ref_state_counts() -> (usize, usize) { + lock_states().as_ref().map_or((0, 0), |states| { + let scheduled = states.states.values().filter(|s| s.scheduled).count(); + (states.states.len(), scheduled) + }) } #[cfg(test)] mod tests { - use super::TimerRefStates; + use super::{CallbackTimerKind, TimerRefStates, TIMER_REF_STATES_CAP}; + + fn scheduled_then_retired( + s: &mut TimerRefStates, + ids: std::ops::RangeInclusive, + cap: usize, + ) { + for id in ids { + s.schedule(id, CallbackTimerKind::Timeout); + s.retire(id, cap); + } + } - /// #6084: the ref-state registry must stay bounded, evicting the oldest ids - /// while retaining recent ones (so post-clear `.hasRef()` keeps working for - /// a handle held for any realistic duration). + /// #6084: retired ids stay bounded, evicting the oldest while retaining + /// recent ones (so post-clear `.hasRef()` keeps working for a handle held + /// for any realistic duration). #[test] - fn insert_bounded_evicts_oldest_and_caps_size() { + fn retired_ids_evict_oldest_and_cap_size() { let mut s = TimerRefStates::default(); let cap = 4; for id in 1..=10i64 { - s.insert_bounded(id, id % 2 == 0, cap); + s.schedule(id, CallbackTimerKind::Timeout); + s.set_ref(id, id % 2 == 0, cap); + s.retire(id, cap); } assert_eq!(s.states.len(), cap); - assert_eq!(s.order.len(), cap); + assert_eq!(s.retired.len(), cap); for id in 1..=6i64 { - assert!(!s.states.contains_key(&id), "id {id} should be evicted"); + assert!(s.get(id).is_none(), "id {id} should be evicted"); } for id in 7..=10i64 { - assert_eq!(s.states.get(&id).copied(), Some(id % 2 == 0)); + assert_eq!(s.get(id).map(|st| st.has_ref), Some(id % 2 == 0)); + } + } + + /// #10447: a still-scheduled id is never an eviction candidate, however + /// many later timers come and go — its `unref()` and its kind survive. + #[test] + fn a_scheduled_id_survives_any_number_of_later_timers() { + let mut s = TimerRefStates::default(); + let cap = 16; + s.schedule(1, CallbackTimerKind::Timeout); + s.set_ref(1, false, cap); + s.schedule(2, CallbackTimerKind::Immediate); + scheduled_then_retired(&mut s, 3..=10_000, cap); + let keep = s.get(1).expect("scheduled id 1 was evicted"); + assert!(!keep.has_ref, "id 1's unref() was forgotten"); + assert!(matches!(keep.kind, Some(CallbackTimerKind::Timeout))); + assert!(matches!( + s.get(2).and_then(|st| st.kind), + Some(CallbackTimerKind::Immediate) + )); + assert_eq!(s.states.len(), cap + 2); + // Once it retires it is an ordinary eviction candidate again. + s.retire(1, cap); + s.retire(2, cap); + scheduled_then_retired(&mut s, 10_001..=10_000 + cap as i64, cap); + assert!(s.get(1).is_none() && s.get(2).is_none()); + assert_eq!(s.states.len(), cap); + } + + /// More live timers than the cap: all of them stay, and churn around them + /// still only keeps `cap` retired ids. + #[test] + fn live_timers_beyond_the_cap_are_all_kept() { + let mut s = TimerRefStates::default(); + let cap = 8; + for id in 1..=100i64 { + s.schedule(id, CallbackTimerKind::Timeout); + } + scheduled_then_retired(&mut s, 101..=1_000, cap); + assert!((1..=100i64).all(|id| s.get(id).is_some())); + assert_eq!(s.states.len(), 100 + cap); + assert_eq!(s.retired.len(), cap); + } + + /// #6084's leak must stay fixed: a million set+clear cycles at the real + /// cap leave the registry at the cap, not at a million entries. + #[test] + fn a_million_set_clear_cycles_stay_bounded() { + let mut s = TimerRefStates::default(); + let cap = TIMER_REF_STATES_CAP; + scheduled_then_retired(&mut s, 1..=1_000_000, cap); + assert_eq!(s.states.len(), cap); + assert_eq!(s.retired.len(), cap); + // `ref()`/`unref()` on ids the registry never held is bounded too. + for id in 2_000_000..2_000_000 + 3 * cap as i64 { + s.set_ref(id, false, cap); } + assert_eq!(s.states.len(), cap); + assert_eq!(s.retired.len(), cap); } #[test] - fn ref_unref_of_existing_id_does_not_grow_queue() { + fn ref_unref_and_repeated_retire_do_not_grow_the_queue() { let mut s = TimerRefStates::default(); let cap = 100; - s.insert_bounded(42, true, cap); - s.insert_bounded(42, false, cap); - s.insert_bounded(42, true, cap); - assert_eq!(s.order.len(), 1); + s.schedule(42, CallbackTimerKind::Timeout); + s.set_ref(42, false, cap); + s.set_ref(42, true, cap); + assert_eq!( + s.retired.len(), + 0, + "a scheduled id is not queued for eviction" + ); + s.retire(42, cap); + s.retire(42, cap); + s.set_ref(42, false, cap); + assert_eq!(s.retired.len(), 1); assert_eq!(s.states.len(), 1); - assert_eq!(s.states.get(&42).copied(), Some(true)); + assert_eq!(s.get(42).map(|st| st.has_ref), Some(false)); + s.retire(7, cap); + assert_eq!(s.states.len(), 1, "retiring an unknown id is a no-op"); + } + + /// End to end through the real queues: a live unref'd `setTimeout`, an + /// unref'd `setInterval` and a `setImmediate` keep their state across more + /// than `TIMER_REF_STATES_CAP` later set+clear cycles, and do not keep the + /// event loop alive. Before #10447 all three ids were evicted, so the + /// loop saw two ref'd timers and `is_known_timer_id` rejected all three. + #[test] + fn live_timers_keep_ref_state_across_timer_churn() { + use crate::timer::*; + let _serial = crate::gc::global_side_table_test_lock(); + test_clear_all_timer_scanner_roots(); + let timeout = js_set_timeout_callback(0, 50_000.0); + js_timer_unref(timeout); + let interval = setInterval(0, 50_000.0); + js_timer_unref(interval); + let immediate = js_set_immediate_callback(0); + let recent = js_set_timeout_callback(0, 50_000.0); + js_timer_unref(recent); + + for _ in 0..TIMER_REF_STATES_CAP + 1_000 { + clearTimeout(js_set_timeout_callback(0, 1_000.0)); + } + clearTimeout(recent); + for _ in 0..1_000 { + clearTimeout(js_set_timeout_callback(0, 1_000.0)); + } + + for id in [timeout, interval, immediate, recent] { + assert!( + is_known_timer_id(id), + "timer {id} dropped from the registry" + ); + } + assert_eq!(js_timer_has_ref(timeout), 0); + assert_eq!(js_timer_has_ref(interval), 0); + assert_eq!(js_timer_has_ref(immediate), 1); + assert_eq!( + js_timer_has_ref(recent), + 0, + "post-clear hasRef of a recent handle" + ); + assert!(matches!( + super::timer_handle_kind(timeout), + Some(CallbackTimerKind::Timeout) + )); + assert!(matches!( + super::timer_handle_kind(interval), + Some(CallbackTimerKind::Timeout) + )); + assert!(matches!( + super::timer_handle_kind(immediate), + Some(CallbackTimerKind::Immediate) + )); + assert_eq!( + js_interval_timer_has_pending(), + 0, + "unref'd interval kept the loop alive" + ); + + // Only the ref'd immediate keeps the loop alive; once it is gone, + // nothing does — and re-`ref()`ing the timeout re-arms it. + clearImmediate(immediate); + assert_eq!( + js_callback_timer_has_pending(), + 0, + "unref'd timeout kept the loop alive" + ); + js_timer_ref(timeout); + assert_eq!( + js_callback_timer_has_pending(), + 1, + "ref() after churn did not re-arm" + ); + + // The registry stayed bounded: every entry beyond the cap is scheduled. + let (len, scheduled) = super::test_ref_state_counts(); + assert!( + len <= TIMER_REF_STATES_CAP + scheduled, + "{len} entries, {scheduled} scheduled" + ); + + clearTimeout(timeout); + clearInterval(interval); } } @@ -82,8 +409,8 @@ mod tests { /// measured it as `pthread_mutex_lock` under `dispatch_primitive` on a pure /// class-hierarchy benchmark that schedules no timers at all. /// -/// Armed by `set_timer_ref_state`, which runs before any id becomes -/// observable, per `registry_latch`'s ordering rule. +/// Armed by `register_scheduled_timer` / `set_timer_ref_state`, which run +/// before any id becomes observable, per `registry_latch`'s ordering rule. pub(crate) static TIMER_IDS_NONEMPTY: crate::registry_latch::RegistryLatch = crate::registry_latch::RegistryLatch::new(); @@ -94,11 +421,11 @@ pub(crate) static TIMER_IDS_NONEMPTY: crate::registry_latch::RegistryLatch = /// this gate, any small handle (UI widget, drizzle, etc.) would accidentally /// route through timer dispatch. /// -/// Entries in `TIMER_REF_STATES` are inserted at schedule time and never -/// removed — clearing a timer marks it cleared in the queue but keeps the -/// id registered as "this was a timer" so post-clear `.hasRef()` / `+timer` -/// / `.unref()` still route through timer dispatch (Node keeps the -/// Timeout object alive after `clearTimeout` and methods still work). +/// A scheduled timer's id is always registered. After `clearTimeout` or +/// firing it stays registered — so post-clear `.hasRef()` / `+timer` / +/// `.unref()` still route through timer dispatch (Node keeps the Timeout +/// object alive and its methods still work) — until 65,536 later timers have +/// also retired. #[inline] pub fn is_known_timer_id(id: i64) -> bool { if id <= 0 || TIMER_IDS_NONEMPTY.is_idle() { @@ -109,12 +436,9 @@ pub fn is_known_timer_id(id: i64) -> bool { #[inline(never)] fn is_known_timer_id_slow(id: i64) -> bool { - super::TIMER_REF_STATES - .lock() - .unwrap() + lock_states() .as_ref() - .map(|s| s.states.contains_key(&id)) - .unwrap_or(false) + .is_some_and(|states| states.states.contains_key(&id)) } #[cfg(test)] diff --git a/crates/perry-runtime/src/timer/tests_inline.rs b/crates/perry-runtime/src/timer/tests_inline.rs index eb527440dd..f365981d55 100644 --- a/crates/perry-runtime/src/timer/tests_inline.rs +++ b/crates/perry-runtime/src/timer/tests_inline.rs @@ -56,6 +56,7 @@ pub(crate) fn test_seed_timer_scanner_roots( async_id: 0, trigger_async_id: 0, cleared: false, + _scheduled: ref_states::ScheduledTimerId::unregistered(), }); INTERVAL_TIMERS.lock().unwrap().push(IntervalTimer { // #6185: test scaffolding runs on the primary agent. @@ -69,6 +70,7 @@ pub(crate) fn test_seed_timer_scanner_roots( async_id: 0, trigger_async_id: 0, cleared: false, + _scheduled: ref_states::ScheduledTimerId::unregistered(), }); } @@ -184,6 +186,7 @@ mod expired_batch_order_tests { async_id: 0, trigger_async_id: 0, cleared: false, + _scheduled: crate::timer::ref_states::ScheduledTimerId::unregistered(), } } diff --git a/scripts/gc_runtime_root_holders.json b/scripts/gc_runtime_root_holders.json index c2c7b7d504..c98497632a 100644 --- a/scripts/gc_runtime_root_holders.json +++ b/scripts/gc_runtime_root_holders.json @@ -1099,12 +1099,6 @@ "verdict": "not_a_gc_pointer", "why": "In-flight job counter for perry/thread." }, - { - "file": "crates/perry-runtime/src/timer.rs", - "name": "TIMER_HANDLE_KINDS", - "verdict": "not_a_gc_pointer", - "why": "Maps scalar timer handle IDs to the CallbackTimerKind enum so clearTimeout/clearInterval can destroy the matching async_hooks resource. Neither the i64 keys nor the enum values contain a JS heap address." - }, { "file": "crates/perry-runtime/src/weakref/test_support.rs", "name": "DELIVERED", diff --git a/test-files/test_gap_10447_timer_ref_state_eviction.ts b/test-files/test_gap_10447_timer_ref_state_eviction.ts new file mode 100644 index 0000000000..a8b7f07c8c --- /dev/null +++ b/test-files/test_gap_10447_timer_ref_state_eviction.ts @@ -0,0 +1,77 @@ +// #10447: a SCHEDULED timer's ref state and handle kind must survive any +// number of later timers. The id -> ref-state registry is bounded (#6084), but +// it evicted the oldest 65,536+ ids whether or not they were still scheduled. +// After that many later timers a live `unref()`'d timer read as ref'd again — +// the process stayed alive until it fired and ran the callback the program had +// detached — and `.hasRef()` / `.ref()` / `.unref()` / `.constructor` / `+t` +// stopped resolving on the handle at all. +// +// Every "BUG" callback below belongs to an unref'd timer: once the last ref'd +// timer has fired nothing keeps the loop alive, so none of them may run (and +// the process exits promptly instead of waiting 1-1.5 s for them). + +const CHURN = 70000; // > 65,536 + +function churn(n: number): void { + for (let i = 0; i < n; i++) clearTimeout(setTimeout(() => {}, 1000)); +} + +function show(label: string, t: any): void { + const hasRef = typeof t.hasRef === "function" ? t.hasRef() : "missing"; + const ctor = t.constructor ? t.constructor.name : "missing"; + let line = `${label}: hasRef=${hasRef} ctor=${ctor}`; + // A Timeout coerces to its numeric id (an Immediate does not). + if (ctor !== "Immediate") line += ` primitive=${!Number.isNaN(+t)}`; + console.log(line); +} + +process.on("exit", () => console.log("exit")); + +// --- below-cap control: unaffected before and after the fix --- +const control = setTimeout(() => console.log("BUG: control unref'd timeout fired"), 1500); +control.unref(); +churn(1000); +show("control after 1000 timers", control); + +// --- subjects scheduled BEFORE more than 65,536 later timers --- +const unrefTimeout = setTimeout(() => console.log("BUG: unref'd timeout fired"), 1500); +unrefTimeout.unref(); + +const unrefInterval = setInterval(() => { + console.log("BUG: unref'd interval fired"); + clearInterval(unrefInterval); +}, 1000); +unrefInterval.unref(); + +const unrefLater = setTimeout(() => console.log("BUG: timeout unref'd after churn fired"), 1500); + +const reRef = setTimeout(() => console.log("re-ref'd timeout fired"), 1); +reRef.unref(); + +const immediate = setImmediate(() => {}); + +const refd = setTimeout(() => console.log("last ref'd timeout fired"), 20); + +churn(CHURN); +console.log(`churned ${CHURN} timers`); + +show("unref'd timeout", unrefTimeout); +show("unref'd interval", unrefInterval); +show("immediate", immediate); +show("ref'd timeout", refd); + +// unref() / ref() on a live handle that has 70k later timers behind it. +show("timeout before unref()", unrefLater); +unrefLater.unref(); +show("timeout after unref()", unrefLater); +show("timeout before ref()", reRef); +reRef.ref(); +show("timeout after ref()", reRef); + +// post-clear state on a recent handle is kept (the bounded part of #6084) +const recent = setTimeout(() => console.log("BUG: cleared timeout fired"), 1); +recent.unref(); +clearTimeout(recent); +show("recent cleared timeout", recent); + +console.log("main done");