fix(gc): bound the atomic work inside a time-budgeted incremental step (#7903)

changelog.d/7938-bounded-budgeted-step-work.md

@@ -0,0 +1,70 @@
+### Fixed
+
+- **GC: a time-budgeted incremental step no longer contains an unbounded atomic
+  work unit (#7903).** `js_gc_step_us` consults its clock *between* work units
+  and never during one, so the budget it advertises is exactly as strong as the
+  most expensive single unit. Weak processing charged **one unit per registered
+  holder** — and a `FinalizationRegistry` is one holder however many records it
+  owns, so `process_finreg_after_mark` walked an arbitrarily long record array
+  inside that one unit. A single registry with a million registrations was an
+  atomic, heap-sized "work unit" sitting behind a time-budgeted API, and no
+  amount of tightening the microsecond budget could reach it.
+
+  Weak processing now charges **one unit per record** and keeps a cursor *into*
+  the record array (`crates/perry-runtime/src/weakref/sliced.rs`).
+
+  The previous atomicity was not accidental, and preserving what it protected is
+  most of the change. `FinalizationRegistry.prototype.unregister` **rebuilds**
+  the entries array without the matching records, so every index after a removed
+  element shifts down; a resumed index-only cursor would skip exactly as many
+  records as were removed before it, and a skipped record is a weak slot that
+  never gets tombstoned — on a non-moving budgeted cycle its target is then
+  swept and the slot dangles. That is a use-after-free, not a latency bug.
+
+  So the cursor is validated rather than trusted: alongside the record index it
+  carries the *identity* of the array it indexes (the value word of the
+  registry's `entries` field plus that array's length). Both mutator mutation
+  paths change one of the two — `unregister` installs a freshly built array,
+  `register` pushes — so on resume a mismatch means the held indices are
+  meaningless and that registry's scan restarts from 0 against the new array.
+  Restarting is safe because a rescan is idempotent: the first pass writes
+  `undefined` into a collected record's target and `false` into its pending flag
+  after enqueueing, so a second pass enqueues nothing and clears nothing twice.
+  Restart-on-mutation alone is livelock-shaped, so restarts are capped; past the
+  cap a registry is finished in one atomic pass **and charged as such**. The
+  worst case is therefore stated rather than implied.
+
+- **Final root remark is now measured instead of claimed (#7903).**
+  `AtomicFinalizeSubphase::FinalRootRemark` re-scans the roots and then drains
+  everything they newly reach, both at `usize::MAX`. Its inline comment claimed
+  the phase was "bounded by root-set size, not heap size" — true of the scan,
+  **false of the drain**, since a root installed after the initial scan can
+  anchor an arbitrarily large graph. Both ways to bound it were rejected on
+  correctness grounds: yielding mid-drain invalidates the remark itself (the
+  mutator installs new roots, so the scan must repeat, with no termination
+  guarantee), and yielding after the liveness decision is the weak-read race
+  tracked in #7900. The phase therefore stays deliberately atomic, is documented
+  as such, and its cost is now reported separately from the general step maximum
+  so a heap-sized pause cannot hide behind "the collector's worst step".
+
+### Added
+
+- **`[gc-step-bounds]` diagnostic line (#7903).** Emitted on the existing
+  `PERRY_GC_DIAG=1` path — **no new environment knob**, per the GC knob
+  kill-policy. Reports `step_max_us`, `final_remark_max_us` / `final_remarks`,
+  `weak_records` / `weak_max_records_per_step`, `weak_steps_sliced`, and
+  `weak_registry_restarts` / `weak_registry_atomic_finishes`.
+
+  `weak_steps_sliced` is the **subject-was-live** counter: a run reporting `0`
+  has not exercised the sliced path at all, whatever else it reports. Most
+  programs register no weak holders and will legitimately report zeros across
+  the whole line, which is exactly why the five new acceptance tests
+  (`crates/perry-runtime/src/gc/tests/step_bounds.rs`) build the pathological
+  registry directly and assert the liveness counter *before* asserting any
+  bound — including an adversarial case where the mutator restructures the
+  entries array in every single window, which must reach the bounded atomic
+  fallback rather than restarting forever.
+
+- `docs/src/internals/gc-step-bounds.md` — which collector phases are
+  intentionally atomic, what each phase's defensible bound is, and how to read
+  the new line.

crates/perry-runtime/src/gc/cycle.rs

@@ -1369,27 +1369,28 @@ impl GcCycleState {
                 if budget == 0 {
                     return;
                 }
-                // Re-scan every root with the marks nearly final (see the
-                // enum doc). Reuses the RootScan machinery unbudgeted —
-                // bounded by root-set size, not heap size. consider_evacuation
-                // is false: pinning decisions were made in the original scan,
-                // and budgeted cycles are non-moving anyway.
+                // Re-scan every root with the marks nearly final (see the enum
+                // doc). DELIBERATELY ATOMIC and NOT bounded by the step budget:
+                // the scan is bounded by root-set size, but the drain below is
+                // bounded by the newly-reachable graph, which a root installed
+                // after the initial scan can make arbitrarily large. Measured
+                // rather than claimed — `final_remark_max_us` in
+                // `[gc-step-bounds]`; docs/src/internals/gc-step-bounds.md has
+                // the bound and rejected alternatives (#7903).
+                // consider_evacuation is false: pinning was decided already.
                 {
+                    let _remark_timer = instruments::FinalRemarkTimer::start();
                     let valid_ptrs = self.valid_ptrs.as_ref().expect("valid pointer set built");
                     let minor_only = self.minor.is_some();
                     let remark_scan = self.root_scan.get_or_insert_with(RootScanCycleState::new);
-                    loop {
-                        if remark_scan.step_current_subphase(
-                            valid_ptrs,
-                            &mut self.trace,
-                            /* consider_evacuation = */ false,
-                            usize::MAX,
-                            /* allow_synchronous_scanners = */ true,
-                            minor_only,
-                        ) {
-                            break;
-                        }
-                    }
+                    while !remark_scan.step_current_subphase(
+                        valid_ptrs,
+                        &mut self.trace,
+                        /* consider_evacuation = */ false,
+                        usize::MAX,
+                        /* allow_synchronous_scanners = */ true,
+                        minor_only,
+                    ) {}
                     self.root_scan = None;
                     // Trace everything the remark newly discovered so
                     // WeakProcessing (and the full path's RS rebuild) read a

crates/perry-runtime/src/gc/instruments.rs

@@ -243,3 +243,157 @@ pub fn budgeted_step_skips() -> (u64, u64, u64, u64) {
         SKIP_RESUME_BLOCKED.load(Ordering::Relaxed),
     )
 }
+
+// ---------------------------------------------------------------------------
+// #7903 — step-boundedness telemetry
+//
+// `js_gc_step_us` can only check its clock BETWEEN work units, so the honest
+// question about a "time-budgeted" collector is not "what budget was requested"
+// but "how long did the longest single step actually take, and what was it
+// doing". These counters answer that directly, and they are the liveness proof
+// for the slicing work: a run where `weak_steps_sliced` is zero has not
+// exercised the sliced path at all, however green it looks.
+// ---------------------------------------------------------------------------
+
+/// Longest single `cycle.state.step(...)` observed, microseconds.
+static STEP_MAX_US: AtomicU64 = AtomicU64::new(0);
+/// Longest single ATOMIC final-remark (root re-scan + transitive drain).
+///
+/// Deliberately a separate number from `STEP_MAX_US`: final remark is an
+/// intentionally atomic phase whose cost is bounded by the newly-reachable
+/// graph, not by the step budget. Folding it into the general maximum would let
+/// a heap-sized pause hide behind "the collector's worst step".
+static REMARK_MAX_US: AtomicU64 = AtomicU64::new(0);
+static REMARK_COUNT: AtomicU64 = AtomicU64::new(0);
+/// FinalizationRegistry records scanned during weak processing.
+static WEAK_RECORDS: AtomicU64 = AtomicU64::new(0);
+/// Most records charged to a single weak-processing step.
+static WEAK_MAX_RECORDS_PER_STEP: AtomicU64 = AtomicU64::new(0);
+/// Steps that ended PARTWAY THROUGH one registry's record array — the sliced
+/// path actually running. Zero means the slicing never happened.
+static WEAK_STEPS_SLICED: AtomicU64 = AtomicU64::new(0);
+/// A registry's record cursor was invalidated by mutator restructuring.
+static WEAK_REGISTRY_RESTARTS: AtomicU64 = AtomicU64::new(0);
+/// A registry hit the restart cap and was finished in one atomic pass.
+static WEAK_REGISTRY_ATOMIC_FINISHES: AtomicU64 = AtomicU64::new(0);
+
+#[inline]
+fn bump_max(slot: &AtomicU64, value: u64) {
+    let mut cur = slot.load(Ordering::Relaxed);
+    while value > cur {
+        match slot.compare_exchange_weak(cur, value, Ordering::Relaxed, Ordering::Relaxed) {
+            Ok(_) => return,
+            Err(observed) => cur = observed,
+        }
+    }
+}
+
+/// Record one budgeted step's wall duration.
+#[inline]
+pub(crate) fn note_budgeted_step_duration(us: u64) {
+    bump_max(&STEP_MAX_US, us);
+}
+
+/// Record one atomic final-remark's wall duration.
+#[inline]
+pub(crate) fn note_final_remark_duration(us: u64) {
+    bump_max(&REMARK_MAX_US, us);
+    REMARK_COUNT.fetch_add(1, Ordering::Relaxed);
+}
+
+/// Record the FinalizationRegistry records one weak-processing step charged,
+/// and whether that step stopped mid-registry.
+#[inline]
+pub(crate) fn note_weak_step_records(records: u64, sliced: bool) {
+    if records > 0 {
+        WEAK_RECORDS.fetch_add(records, Ordering::Relaxed);
+        bump_max(&WEAK_MAX_RECORDS_PER_STEP, records);
+    }
+    if sliced {
+        WEAK_STEPS_SLICED.fetch_add(1, Ordering::Relaxed);
+    }
+}
+
+#[inline]
+pub(crate) fn note_weak_registry_restart() {
+    WEAK_REGISTRY_RESTARTS.fetch_add(1, Ordering::Relaxed);
+}
+
+#[inline]
+pub(crate) fn note_weak_registry_atomic_finish() {
+    WEAK_REGISTRY_ATOMIC_FINISHES.fetch_add(1, Ordering::Relaxed);
+}
+
+/// Longest single budgeted step, microseconds.
+pub fn step_max_us() -> u64 {
+    STEP_MAX_US.load(Ordering::Relaxed)
+}
+
+/// Longest single atomic final remark, microseconds.
+pub fn final_remark_max_us() -> u64 {
+    REMARK_MAX_US.load(Ordering::Relaxed)
+}
+
+/// Atomic final remarks performed.
+pub fn final_remark_count() -> u64 {
+    REMARK_COUNT.load(Ordering::Relaxed)
+}
+
+/// FinalizationRegistry records scanned during weak processing.
+pub fn weak_records_scanned() -> u64 {
+    WEAK_RECORDS.load(Ordering::Relaxed)
+}
+
+/// Most records charged to a single weak-processing step.
+pub fn weak_max_records_per_step() -> u64 {
+    WEAK_MAX_RECORDS_PER_STEP.load(Ordering::Relaxed)
+}
+
+/// Steps that ended partway through one registry's record array.
+pub fn weak_steps_sliced() -> u64 {
+    WEAK_STEPS_SLICED.load(Ordering::Relaxed)
+}
+
+/// Record cursors invalidated by mutator restructuring.
+pub fn weak_registry_restarts() -> u64 {
+    WEAK_REGISTRY_RESTARTS.load(Ordering::Relaxed)
+}
+
+/// Registries that hit the restart cap and were finished atomically.
+pub fn weak_registry_atomic_finishes() -> u64 {
+    WEAK_REGISTRY_ATOMIC_FINISHES.load(Ordering::Relaxed)
+}
+
+/// Reset the #7903 step-boundedness counters. Test-only: the process-wide
+/// statics would otherwise leak between in-process test cases.
+#[cfg(test)]
+pub(crate) fn reset_step_bound_counters() {
+    STEP_MAX_US.store(0, Ordering::Relaxed);
+    REMARK_MAX_US.store(0, Ordering::Relaxed);
+    REMARK_COUNT.store(0, Ordering::Relaxed);
+    WEAK_RECORDS.store(0, Ordering::Relaxed);
+    WEAK_MAX_RECORDS_PER_STEP.store(0, Ordering::Relaxed);
+    WEAK_STEPS_SLICED.store(0, Ordering::Relaxed);
+    WEAK_REGISTRY_RESTARTS.store(0, Ordering::Relaxed);
+    WEAK_REGISTRY_ATOMIC_FINISHES.store(0, Ordering::Relaxed);
+}
+
+/// Times one atomic final remark and records it on drop.
+///
+/// An RAII guard rather than a pair of calls so that an early `return` out of
+/// the phase cannot silently drop the sample — an unmeasured atomic phase is
+/// exactly the state #7903 exists to end.
+pub(crate) struct FinalRemarkTimer(std::time::Instant);
+
+impl FinalRemarkTimer {
+    #[inline]
+    pub(crate) fn start() -> Self {
+        Self(std::time::Instant::now())
+    }
+}
+
+impl Drop for FinalRemarkTimer {
+    fn drop(&mut self) {
+        note_final_remark_duration(self.0.elapsed().as_micros().min(u128::from(u64::MAX)) as u64);
+    }
+}

crates/perry-runtime/src/gc/mod.rs

@@ -1102,6 +1102,43 @@ fn emit_incremental_liveness_diag() {
         poll_arm::poll_arm_events(),
         poll_arm::poll_armed_count(),
     );
+    emit_step_bounds_diag();
+}
+
+/// What the "time-budgeted" collector actually cost, as opposed to what it was
+/// asked to cost (#7903).
+///
+/// `js_gc_step_us` and mutator assist can only consult the clock BETWEEN work
+/// units, so a budget is only as good as the largest single unit. These are the
+/// measured maxima plus the liveness counters for the sliced weak path:
+///
+/// * `step_max_us` — longest single budgeted step.
+/// * `final_remark_max_us` / `final_remarks` — the deliberately ATOMIC phase,
+///   reported separately so a heap-sized pause cannot hide inside the general
+///   maximum.
+/// * `weak_records` / `weak_max_records_per_step` — FinalizationRegistry
+///   records scanned, and the worst single step's share of them. Before #7903
+///   one registry was one work unit, so this maximum was the whole registry.
+/// * `weak_steps_sliced` — steps that ended PARTWAY THROUGH a registry. **This
+///   is the subject-was-live counter**: a run reporting zero has not exercised
+///   the sliced path, whatever else it reports.
+/// * `weak_registry_restarts` / `weak_registry_atomic_finishes` — cursors
+///   invalidated by mutator restructuring, and the bounded fallback taken when
+///   one registry exhausted its restart budget.
+fn emit_step_bounds_diag() {
+    eprintln!(
+        "[gc-step-bounds] step_max_us={} final_remark_max_us={} final_remarks={} \
+         weak_records={} weak_max_records_per_step={} weak_steps_sliced={} \
+         weak_registry_restarts={} weak_registry_atomic_finishes={}",
+        instruments::step_max_us(),
+        instruments::final_remark_max_us(),
+        instruments::final_remark_count(),
+        instruments::weak_records_scanned(),
+        instruments::weak_max_records_per_step(),
+        instruments::weak_steps_sliced(),
+        instruments::weak_registry_restarts(),
+        instruments::weak_registry_atomic_finishes(),
+    );
 }
 
 /// Print what the rate-1 schedule endpoint actually did, and **fail the

crates/perry-runtime/src/gc/policy.rs

@@ -3271,7 +3271,14 @@ fn gc_budgeted_step_work_units_inner_with_progress(
             return BudgetedStepOutcome::Result(gc_idle_step_result());
         };
 
+        // #7903: the step's own wall duration, not the budget that was asked
+        // for. `js_gc_step_us` can only consult its clock BETWEEN units, so the
+        // only honest statement about pause is a measured maximum.
+        let step_started = std::time::Instant::now();
         let step = cycle.state.step(GcWorkBudget::bounded(work_units));
+        super::instruments::note_budgeted_step_duration(
+            step_started.elapsed().as_micros().min(u128::from(u64::MAX)) as u64,
+        );
         super::instruments::note_incremental_step();
         if step.completed {
             super::instruments::note_incremental_completion();

crates/perry-runtime/src/gc/tests/mod.rs

@@ -40,6 +40,7 @@ mod scan_fallback;
 mod schedule;
 mod shadow_stack_ops;
 mod smoke;
+mod step_bounds;
 pub(super) mod support;
 mod teardown;
 mod telemetry_verifier;