diff --git a/.isu/issues.json b/.isu/issues.json index 0d6412e..b36204e 100644 --- a/.isu/issues.json +++ b/.isu/issues.json @@ -1,5 +1,5 @@ { - "next_id": 376, + "next_id": 377, "issues": [ { "id": 1, @@ -4593,6 +4593,21 @@ "author": "piefev", "state": "open", "created_at": "2026-06-05T14:28:43Z" + }, + { + "id": 376, + "repo": "we", + "title": "Timer drain drops not-yet-fired callbacks when an earlier callback triggers GC", + "body": "Found while working isu issue 280 / 374 / 375 (Bing hydration). The Bing real-web run printed repeated `[timer] callback error: TypeError: not a function` during hydration, and the modules_wrapper carousel never populated.\n\nRoot cause: a GC-safety bug in the timer event-loop drain.\n\n`Vm::drain_due_timers` calls `timers::take_due_timers()`, which *removes* all due one-shot timers from the pending registry and returns them in a local `Vec`. The VM then runs each callback in turn, draining microtasks between them. `timer_gc_roots()` only roots timers still in the pending registry, so once `take_due_timers` hands the batch to the VM, the not-yet-fired callbacks in that batch are no longer GC roots. If an earlier callback (or a microtask drained between callbacks) triggers a collection — Bing's hydration timers allocate heavily — the remaining unfired callbacks are collected and their GC slots are reused by freshly allocated closure cells. The drain loop then calls a `GcRef` that now points at a `HeapObject::Cell` instead of a `HeapObject::Function`, surfacing as `TypeError: not a function` and silently dropping every remaining timer in the batch.\n\nDiagnosis: temporarily tagging the bare \"not a function\" sites showed the failing path was `call_function` with `heap=Cell` — i.e. a timer callback ref whose slot had been reused by a closure cell.\n\nFix: mirror the existing in-flight-microtask rooting. Add an `IN_FLIGHT_TIMERS` thread-local published by `drain_due_timers` for the duration of the batch and include it in `timer_gc_roots()`, so every due callback stays rooted until it has run.\n\nRepro (engine level): crates/js/src/timers.rs::tests::test_due_timer_batch_survives_gc_during_drain — schedules 24 `setTimeout(fn,0)` callbacks where the first allocates a flood of closures to force a mid-drain GC. Before the fix only `fired 0` logs (the rest throw `not a function`); after, all 24 fire.\n\nRepro (real-web): cargo run -p we-e2e -- --scenario crates/e2e/scenarios/real-web/bing.com.we --out-dir crates/e2e/artifacts — the `[timer] callback error` lines are gone after the fix. The Chromium visual-parity gap (issue 280) and full carousel population (374/375) remain open.", + "labels": [ + "real-web", + "js", + "sev-broken" + ], + "assigned": [], + "author": "piefev", + "state": "closed", + "created_at": "2026-06-19T10:15:48Z" } ] } diff --git a/crates/js/src/timers.rs b/crates/js/src/timers.rs index 5332f23..82fa490 100644 --- a/crates/js/src/timers.rs +++ b/crates/js/src/timers.rs @@ -44,6 +44,18 @@ impl TimerState { thread_local! { static TIMER_STATE: RefCell = RefCell::new(TimerState::new()); + + /// Callbacks for timers that have been taken off the pending queue by + /// [`take_due_timers`] and are being executed by the current drain pass. + /// Once a one-shot timer is taken as "due" it is removed from + /// `TIMER_STATE.timers`, so [`timer_gc_roots`] would otherwise stop + /// keeping its callback alive. A GC triggered while an earlier due + /// callback runs (or while microtasks drain between callbacks) could then + /// free a not-yet-fired sibling callback and reuse its slot — leaving the + /// drain loop holding a dangling `GcRef` that now points at an unrelated + /// heap object (e.g. a closure `Cell`). Publishing the in-flight batch + /// here keeps every pending callback rooted for the whole drain. + static IN_FLIGHT_TIMERS: RefCell> = const { RefCell::new(Vec::new()) }; } /// Reset timer state (useful for tests to avoid leaking state). @@ -54,6 +66,16 @@ pub fn reset_timers() { state.next_id = 1; state.epoch = Instant::now(); }); + IN_FLIGHT_TIMERS.with(|c| c.borrow_mut().clear()); +} + +/// Publish `callbacks` as the in-flight due-timer batch and return the +/// previously published batch. The VM swaps the current batch in before +/// running due callbacks and restores the previous batch afterwards, so +/// nested drains (a callback that itself pumps the event loop) keep every +/// outer batch rooted too. Mirrors `set_in_flight_microtasks`. +pub fn set_in_flight_timers(callbacks: Vec) -> Vec { + IN_FLIGHT_TIMERS.with(|cell| std::mem::replace(&mut *cell.borrow_mut(), callbacks)) } /// Schedule a zero-delay callback. Used by `queueMicrotask` to run a function @@ -145,15 +167,28 @@ fn cancel_timer(id: u32) { /// Collect all GcRefs held by pending (non-cancelled) timers so the GC /// does not collect their callbacks. pub fn timer_gc_roots() -> Vec { - TIMER_STATE.with(|s| { - let state = s.borrow(); + let mut roots = TIMER_STATE.with(|s| { + // Only borrowed mutably during schedule/take; fall back to an empty + // set rather than panicking if a GC is triggered mid-borrow. + let state = match s.try_borrow() { + Ok(state) => state, + Err(_) => return Vec::new(), + }; state .timers .iter() .filter(|t| !t.cancelled) .map(|t| t.callback) - .collect() - }) + .collect::>() + }); + // Due callbacks pulled off the queue but not yet executed by the current + // drain pass must stay rooted too — see `IN_FLIGHT_TIMERS`. + IN_FLIGHT_TIMERS.with(|cell| { + if let Ok(batch) = cell.try_borrow() { + roots.extend(batch.iter().copied()); + } + }); + roots } /// A timer that is ready to fire. @@ -531,6 +566,52 @@ mod tests { assert_eq!(logs, vec!["survived gc"]); } + #[test] + fn test_due_timer_batch_survives_gc_during_drain() { + // Regression test: when several timers are due in the same drain pass, + // `take_due_timers` removes the one-shot timers from the pending queue + // and hands the whole batch to the VM at once. If a callback that runs + // early in the batch triggers a garbage collection (here by allocating + // a flood of closures), the not-yet-fired sibling callbacks must still + // be treated as GC roots. Before the in-flight timer roots were added + // they were collected mid-drain and their slots reused by freshly + // allocated closure cells, so calling them threw + // `TypeError: not a function` and the remaining timers silently + // dropped — exactly the failure that blocked Bing's hydration timers. + let n = 24; + let logs = eval_with_timers( + r#" + var fired = []; + function make(i) { + return function() { + if (i === 0) { + // Allocate a large number of closures (each capturing a + // variable, so each allocates a cell) to force at least + // one collection while callbacks 1..N are still queued + // in this drain batch. + var sink = []; + for (var k = 0; k < 1500; k++) { + sink.push((function(x) { return function() { return x; }; })(k)); + } + } + fired.push(i); + console.log("fired " + i); + }; + } + for (var i = 0; i < 24; i++) { + setTimeout(make(i), 0); + } + "#, + 64, + ); + let expected: Vec = (0..n).map(|i| format!("fired {i}")).collect(); + assert_eq!( + logs, expected, + "every due timer callback must fire even when an earlier callback \ + triggers a GC mid-drain" + ); + } + #[test] fn test_timer_and_promise_interaction() { // Promise microtasks should drain between timer callbacks. diff --git a/crates/js/src/vm.rs b/crates/js/src/vm.rs index 00ceaf2..2fb9460 100644 --- a/crates/js/src/vm.rs +++ b/crates/js/src/vm.rs @@ -2541,18 +2541,35 @@ impl Vm { /// microtask queue (so Promise `.then()` runs between timer callbacks). fn drain_due_timers(&mut self) -> Result<(), RuntimeError> { let due = crate::timers::take_due_timers(); - for timer in due { - // For requestAnimationFrame, pass the timestamp as an argument. - let args = match timer.raf_timestamp { - Some(ts) => vec![Value::Number(ts)], - None => vec![], - }; - if let Err(e) = self.call_function(timer.callback, &args) { - eprintln!("[timer] callback error: {e}"); - } - self.drain_microtasks()?; + if due.is_empty() { + return Ok(()); } - Ok(()) + // Publish every due callback as the in-flight batch so the GC keeps + // them all rooted while we run them one by one. `take_due_timers` + // already removed one-shot timers from the pending queue, so without + // this a collection triggered inside an earlier callback (or while + // microtasks drain between callbacks) could free a not-yet-fired + // sibling callback and reuse its slot. The drain would then call a + // `GcRef` that now points at an unrelated heap object — surfacing as a + // spurious `TypeError: not a function`. + let callbacks: Vec = due.iter().map(|t| t.callback).collect(); + let prev_batch = crate::timers::set_in_flight_timers(callbacks); + let result = (|| { + for timer in due { + // For requestAnimationFrame, pass the timestamp as an argument. + let args = match timer.raf_timestamp { + Some(ts) => vec![Value::Number(ts)], + None => vec![], + }; + if let Err(e) = self.call_function(timer.callback, &args) { + eprintln!("[timer] callback error: {e}"); + } + self.drain_microtasks()?; + } + Ok(()) + })(); + crate::timers::set_in_flight_timers(prev_batch); + result } /// Resolve/reject promises for completed fetch() requests.