diff --git a/cli/Cargo.toml b/cli/Cargo.toml index 2c466c9995d..cf1f7a1b186 100644 --- a/cli/Cargo.toml +++ b/cli/Cargo.toml @@ -44,6 +44,7 @@ default = [ dhat = ["dep:dhat"] fast-allocator = ["dep:mimalloc-safe", "dep:tikv-jemallocator"] fetch = ["boa_runtime/fetch", "boa_runtime/reqwest-blocking"] +gc-stats = ["boa_gc/gc-stats"] [target.x86_64-unknown-linux-gnu.dependencies] tikv-jemallocator = { workspace = true, optional = true } diff --git a/cli/src/debug/gc.rs b/cli/src/debug/gc.rs index 5a2b8aa5c4c..f51000f7444 100644 --- a/cli/src/debug/gc.rs +++ b/cli/src/debug/gc.rs @@ -1,3 +1,5 @@ +#[cfg(feature = "gc-stats")] +use boa_engine::property::Attribute; use boa_engine::{ Context, JsObject, JsResult, JsValue, NativeFunction, js_string, object::ObjectInitializer, }; @@ -8,12 +10,109 @@ fn collect(_: &JsValue, _: &[JsValue], _: &mut Context) -> JsResult { Ok(JsValue::undefined()) } +/// Get the garbage collector statistics of the current thread. +/// +/// Timings are reported in milliseconds. +#[cfg(feature = "gc-stats")] +fn stats(_: &JsValue, _: &[JsValue], context: &mut Context) -> JsResult { + let stats = boa_gc::stats(); + let ms = |duration: std::time::Duration| duration.as_secs_f64() * 1000.0; + + let object = ObjectInitializer::new(context) + .property( + js_string!("collections"), + stats.collections, + Attribute::all(), + ) + .property( + js_string!("finalizingCollections"), + stats.finalizing_collections, + Attribute::all(), + ) + .property( + js_string!("totalBytesAllocated"), + stats.total_bytes_allocated, + Attribute::all(), + ) + .property( + js_string!("totalBytesFreed"), + stats.total_bytes_freed, + Attribute::all(), + ) + .property( + js_string!("objectsAllocated"), + stats.objects_allocated, + Attribute::all(), + ) + .property( + js_string!("objectsSwept"), + stats.objects_swept, + Attribute::all(), + ) + .property( + js_string!("bytesAllocated"), + stats.bytes_allocated, + Attribute::all(), + ) + .property( + js_string!("traceNonRootsMs"), + ms(stats.trace_non_roots_time), + Attribute::all(), + ) + .property(js_string!("markMs"), ms(stats.mark_time), Attribute::all()) + .property( + js_string!("finalizeMs"), + ms(stats.finalize_time), + Attribute::all(), + ) + .property( + js_string!("remarkMs"), + ms(stats.remark_time), + Attribute::all(), + ) + .property( + js_string!("sweepMs"), + ms(stats.sweep_time), + Attribute::all(), + ) + .property( + js_string!("weakMapPruneMs"), + ms(stats.weak_map_prune_time), + Attribute::all(), + ) + .property( + js_string!("totalMs"), + ms(stats.total_time), + Attribute::all(), + ) + .build(); + + Ok(object.into()) +} + +/// Reset the garbage collector statistics of the current thread. +#[cfg(feature = "gc-stats")] +fn reset_stats(_: &JsValue, _: &[JsValue], _: &mut Context) -> JsResult { + boa_gc::reset_stats(); + Ok(JsValue::undefined()) +} + pub(super) fn create_object(context: &mut Context) -> JsObject { - ObjectInitializer::new(context) + let mut object = ObjectInitializer::new(context); + object.function( + NativeFunction::from_fn_ptr(collect), + js_string!("collect"), + 0, + ); + + #[cfg(feature = "gc-stats")] + object + .function(NativeFunction::from_fn_ptr(stats), js_string!("stats"), 0) .function( - NativeFunction::from_fn_ptr(collect), - js_string!("collect"), + NativeFunction::from_fn_ptr(reset_stats), + js_string!("resetStats"), 0, - ) - .build() + ); + + object.build() } diff --git a/core/engine/Cargo.toml b/core/engine/Cargo.toml index 04c0329c3cf..66b39af71f7 100644 --- a/core/engine/Cargo.toml +++ b/core/engine/Cargo.toml @@ -26,6 +26,8 @@ embedded_lz4 = ["boa_macros/embedded_lz4", "lz4_flex"] jsvalue-enum = [] deser = ["boa_interner/serde", "boa_ast/serde"] either = ["dep:either", "boa_gc/either"] +# Enable collection of GC statistics +gc-stats = ["boa_gc/gc-stats"] # Enables the `Intl` builtin object and bundles a default ICU4X data provider. # Prefer this over `intl` if you just want to enable `Intl` without dealing with the diff --git a/core/gc/Cargo.toml b/core/gc/Cargo.toml index 74039d945bc..2ec53d909e5 100644 --- a/core/gc/Cargo.toml +++ b/core/gc/Cargo.toml @@ -21,6 +21,8 @@ boa_string = ["dep:boa_string"] either = ["dep:either"] # Enable default implementations of trace and finalize for the arrayvec crate arrayvec = ["dep:arrayvec"] +# Enable collection of GC statistics (allocation/free counters and per-phase timings) +gc-stats = [] [dependencies] boa_macros.workspace = true diff --git a/core/gc/src/lib.rs b/core/gc/src/lib.rs index 4674236b57a..91d24eaa0ee 100644 --- a/core/gc/src/lib.rs +++ b/core/gc/src/lib.rs @@ -19,6 +19,8 @@ extern crate self as boa_gc; mod cell; mod pointers; +#[cfg(feature = "gc-stats")] +mod stats; mod trace; pub(crate) mod internals; @@ -36,6 +38,8 @@ pub use boa_macros::{Finalize, Trace}; pub use cell::{GcRef, GcRefCell, GcRefMut}; pub use internals::GcBox; pub use pointers::{Ephemeron, Gc, GcErased, WeakGc, WeakMap}; +#[cfg(feature = "gc-stats")] +pub use stats::{GcStats, reset_stats, stats}; type GcErasedPointer = NonNull>; type EphemeronPointer = NonNull; @@ -48,6 +52,8 @@ thread_local!(static BOA_GC: RefCell = RefCell::new( BoaGc { strongs: Vec::default(), weaks: Vec::default(), weak_maps: Vec::default(), + #[cfg(feature = "gc-stats")] + stats: GcStats::default(), })); #[derive(Debug, Clone, Copy)] @@ -84,6 +90,8 @@ struct BoaGc { strongs: Vec, weaks: Vec, weak_maps: Vec, + #[cfg(feature = "gc-stats")] + stats: GcStats, } impl Drop for BoaGc { @@ -140,6 +148,11 @@ impl Allocator { gc.strongs.push(erased); gc.runtime.bytes_allocated += element_size; + #[cfg(feature = "gc-stats")] + { + gc.stats.total_bytes_allocated += element_size as u64; + gc.stats.objects_allocated += 1; + } ptr }) @@ -159,6 +172,11 @@ impl Allocator { gc.weaks.push(erased); gc.runtime.bytes_allocated += element_size; + #[cfg(feature = "gc-stats")] + { + gc.stats.total_bytes_allocated += element_size as u64; + gc.stats.objects_allocated += 1; + } ptr }) @@ -206,6 +224,20 @@ struct Unreachables { weak: Vec>, } +/// Runs `$body` adding its runtime to `$gc.stats.$field` when `gc-stats` is enabled +macro_rules! timed { + ($gc:ident . $field:ident, $body:expr) => {{ + #[cfg(feature = "gc-stats")] + let start = std::time::Instant::now(); + let result = $body; + #[cfg(feature = "gc-stats")] + { + $gc.stats.$field += start.elapsed(); + } + result + }}; +} + /// This collector currently functions in four main phases /// /// Mark -> Finalize -> Mark -> Sweep @@ -223,58 +255,100 @@ struct Collector; impl Collector { /// Run a collection on the full heap. fn collect(gc: &mut BoaGc) { + #[cfg(feature = "gc-stats")] + let total_start = std::time::Instant::now(); + gc.runtime.collections += 1; - Self::trace_non_roots(gc); + #[cfg(feature = "gc-stats")] + { + gc.stats.collections += 1; + } + + timed!(gc.trace_non_roots_time, Self::trace_non_roots(gc)); let mut tracer = Tracer::new(); - let unreachables = Self::mark_heap(&mut tracer, &gc.strongs, &gc.weaks, &gc.weak_maps); + let unreachables = timed!( + gc.mark_time, + Self::mark_heap(&mut tracer, &gc.strongs, &gc.weaks, &gc.weak_maps) + ); assert!(tracer.is_empty(), "The queue should be empty"); // Only finalize if there are any unreachable nodes. if !unreachables.strong.is_empty() || !unreachables.weak.is_empty() { - // Finalize all the unreachable nodes. - // SAFETY: All passed pointers are valid, since we won't deallocate until `Self::sweep`. - unsafe { Self::finalize(unreachables) }; + #[cfg(feature = "gc-stats")] + { + gc.stats.finalizing_collections += 1; + } - // Reuse the tracer's already allocated capacity. - let _final_unreachables = - Self::mark_heap(&mut tracer, &gc.strongs, &gc.weaks, &gc.weak_maps); - } + timed!(gc.finalize_time, { + // Finalize all the unreachable nodes. + // SAFETY: All passed pointers are valid, since we won't deallocate until `Self::sweep`. + unsafe { Self::finalize(unreachables) } + }); - // SAFETY: The head of our linked list is always valid per the invariants of our GC. - unsafe { - Self::sweep( - &mut gc.strongs, - &mut gc.weaks, - &mut gc.runtime.bytes_allocated, + // Reuse the tracer's already allocated capacity. + let _final_unreachables = timed!( + gc.remark_time, + Self::mark_heap(&mut tracer, &gc.strongs, &gc.weaks, &gc.weak_maps) ); } - // Weak maps have to be cleared after the sweep, since the process dereferences GcBoxes. - gc.weak_maps.retain(|w| { - // SAFETY: The caller must ensure the validity of every node of `heap_start`. - let node_ref = unsafe { w.as_ref() }; - - if node_ref.is_live() { - node_ref.clear_dead_entries(); + #[cfg(feature = "gc-stats")] + let (bytes_before, objects_before) = ( + gc.runtime.bytes_allocated, + gc.strongs.len() + gc.weaks.len(), + ); - true - } else { - // SAFETY: - // The `Allocator` must always ensure its start node is a valid, non-null pointer that - // was allocated by `Box::from_raw(Box::new(..))`. - let _unmarked_node = unsafe { Box::from_raw(w.as_ptr()) }; - - false + timed!(gc.sweep_time, { + // SAFETY: The head of our linked list is always valid per the invariants of our GC. + unsafe { + Self::sweep( + &mut gc.strongs, + &mut gc.weaks, + &mut gc.runtime.bytes_allocated, + ); } }); + #[cfg(feature = "gc-stats")] + { + gc.stats.total_bytes_freed += (bytes_before - gc.runtime.bytes_allocated) as u64; + gc.stats.objects_swept += (objects_before - gc.strongs.len() - gc.weaks.len()) as u64; + } + + // Weak maps have to be cleared after the sweep, since the process dereferences GcBoxes. + timed!( + gc.weak_map_prune_time, + gc.weak_maps.retain(|w| { + // SAFETY: The caller must ensure the validity of every node of `heap_start`. + let node_ref = unsafe { w.as_ref() }; + + if node_ref.is_live() { + node_ref.clear_dead_entries(); + + true + } else { + // SAFETY: + // The `Allocator` must always ensure its start node is a valid, non-null pointer that + // was allocated by `Box::from_raw(Box::new(..))`. + let _unmarked_node = unsafe { Box::from_raw(w.as_ptr()) }; + + false + } + }) + ); + gc.strongs.shrink_to(gc.strongs.len() >> 2); gc.weaks.shrink_to(gc.weaks.len() >> 2); gc.weak_maps.shrink_to(gc.weak_maps.len() >> 2); + + #[cfg(feature = "gc-stats")] + { + gc.stats.total_time += total_start.elapsed(); + } } fn trace_non_roots(gc: &BoaGc) { diff --git a/core/gc/src/stats.rs b/core/gc/src/stats.rs new file mode 100644 index 00000000000..9f96f2fbe50 --- /dev/null +++ b/core/gc/src/stats.rs @@ -0,0 +1,97 @@ +//! Garbage collector statistics, enabled by the `gc-stats` feature. + +use crate::BOA_GC; +use std::time::Duration; + +/// Statistics about the garbage collector on the current thread. +/// +/// The garbage collector is thread-local, so each thread has its own statistics. +/// +/// Counters and timings are cumulative since the thread started or since the last call +/// to [`reset_stats`]. +/// +/// Byte counts are shallow: they only include the size of each `Gc` and `Ephemeron` +/// allocation itself, not heap memory owned by the allocated values (for example the +/// buffer of a `Vec` stored inside a `Gc`). The internal allocations backing `WeakMap`s +/// are not counted either. +#[derive(Default, Debug, Clone, Copy)] +#[non_exhaustive] +pub struct GcStats { + /// Number of collections run. + pub collections: u64, + /// Number of collections that found unreachable objects and therefore also ran the + /// finalize and second mark phases. + pub finalizing_collections: u64, + /// Total bytes allocated for `Gc` and `Ephemeron` values. + pub total_bytes_allocated: u64, + /// Total bytes freed by sweeps. + pub total_bytes_freed: u64, + /// Number of `Gc` and `Ephemeron` values allocated. + pub objects_allocated: u64, + /// Number of `Gc` and `Ephemeron` values freed by sweeps. + pub objects_swept: u64, + /// Time spent counting the references between objects in the heap, which is used to + /// find the roots. + pub trace_non_roots_time: Duration, + /// Time spent in the first mark phase, which marks every object reachable from the + /// roots. + pub mark_time: Duration, + /// Time spent running finalizers on unreachable objects. + /// + /// This only increases in collections counted by `finalizing_collections`. + pub finalize_time: Duration, + /// Time spent in the second mark phase, which finds objects resurrected by finalizers. + /// + /// This only increases in collections counted by `finalizing_collections`. + pub remark_time: Duration, + /// Time spent freeing unreachable objects. + pub sweep_time: Duration, + /// Time spent removing dead entries from weak maps and freeing dead weak maps. + pub weak_map_prune_time: Duration, + /// Time spent in collections overall, including work not covered by the per-phase + /// timings. + pub total_time: Duration, + /// Bytes currently allocated for live `Gc` and `Ephemeron` values. + /// + /// This is read when the snapshot is taken and is not affected by + /// [`reset_stats`]. + pub bytes_allocated: usize, +} + +/// Returns a snapshot of the garbage collector statistics for the current thread. +/// +/// # Panics +/// +/// Panics if called while the garbage collector is running on this thread, for example +/// from inside a [`Finalize::finalize`](crate::Finalize::finalize) implementation. +#[must_use] +pub fn stats() -> GcStats { + BOA_GC.with(|current| { + let gc = current.borrow(); + + GcStats { + bytes_allocated: gc.runtime.bytes_allocated, + ..gc.stats + } + }) +} + +/// Resets the current thread's counters and timings to zero. +/// +/// This only affects the statistics: the live allocation count and the collection +/// threshold are unchanged, so the garbage collector behaves the same afterwards. +/// +/// Objects allocated before a reset can be freed after it, so once `reset_stats` has +/// been called, `total_bytes_allocated - total_bytes_freed` no longer equals +/// `bytes_allocated`. +/// +/// # Panics +/// +/// Panics if called while the garbage collector is running on this thread, for example +/// from inside a [`Finalize::finalize`](crate::Finalize::finalize) implementation. +pub fn reset_stats() { + BOA_GC.with(|current| { + let mut gc = current.borrow_mut(); + gc.stats = GcStats::default(); + }); +} diff --git a/core/gc/src/test/mod.rs b/core/gc/src/test/mod.rs index 79b73d22093..1dc19c08971 100644 --- a/core/gc/src/test/mod.rs +++ b/core/gc/src/test/mod.rs @@ -3,6 +3,8 @@ use crate::BOA_GC; mod allocation; mod cell; mod erased; +#[cfg(feature = "gc-stats")] +mod stats; mod std_types; mod weak; mod weak_map; diff --git a/core/gc/src/test/stats.rs b/core/gc/src/test/stats.rs new file mode 100644 index 00000000000..6271042bb72 --- /dev/null +++ b/core/gc/src/test/stats.rs @@ -0,0 +1,140 @@ +mod miri { + use std::time::Duration; + + use super::super::run_test; + use crate::{Gc, GcBox, WeakGc, force_collect, internals::EphemeronBox, reset_stats, stats}; + + const COUNT: usize = 100; + const GC_BOX_SIZE: usize = size_of::>(); + + fn allocate(count: usize) -> Vec> { + (0..count as u64).map(Gc::new).collect() + } + + #[test] + fn stats_count_allocations() { + run_test(|| { + let values = allocate(COUNT); + + let snapshot = stats(); + assert_eq!(snapshot.objects_allocated, COUNT as u64); + assert_eq!(snapshot.total_bytes_allocated, (COUNT * GC_BOX_SIZE) as u64); + assert_eq!(snapshot.bytes_allocated, COUNT * GC_BOX_SIZE); + assert_eq!(snapshot.collections, 0); + + drop(values); + }); + } + + #[test] + fn stats_collection_without_garbage() { + run_test(|| { + let values = allocate(COUNT); + + force_collect(); + + let snapshot = stats(); + assert_eq!(snapshot.collections, 1); + assert_eq!(snapshot.finalizing_collections, 0); + assert_eq!(snapshot.total_bytes_freed, 0); + assert_eq!(snapshot.objects_swept, 0); + assert_eq!(snapshot.bytes_allocated, COUNT * GC_BOX_SIZE); + + drop(values); + }); + } + + #[test] + fn stats_free_everything() { + run_test(|| { + drop(allocate(COUNT)); + + force_collect(); + + let snapshot = stats(); + assert_eq!(snapshot.collections, 1); + assert_eq!(snapshot.finalizing_collections, 1); + assert_eq!(snapshot.total_bytes_freed, snapshot.total_bytes_allocated); + assert_eq!(snapshot.objects_swept, snapshot.objects_allocated); + assert_eq!(snapshot.bytes_allocated, 0); + + // `force_collect` skips the collection when nothing is allocated. + force_collect(); + assert_eq!(stats().collections, 1); + }); + } + + #[test] + fn stats_count_ephemerons() { + run_test(|| { + let value = Gc::new(1u8); + let weak = WeakGc::new(&value); + let expected_bytes = size_of::>() + size_of::>(); + + let snapshot = stats(); + assert_eq!(snapshot.objects_allocated, 2); + assert_eq!(snapshot.total_bytes_allocated, expected_bytes as u64); + assert_eq!(snapshot.bytes_allocated, expected_bytes); + + drop(weak); + drop(value); + force_collect(); + + let snapshot = stats(); + assert_eq!(snapshot.objects_swept, 2); + assert_eq!(snapshot.total_bytes_freed, expected_bytes as u64); + assert_eq!(snapshot.bytes_allocated, 0); + }); + } + + #[test] + fn stats_reset() { + run_test(|| { + let values = allocate(COUNT); + + force_collect(); + assert_eq!(stats().collections, 1); + + reset_stats(); + + let snapshot = stats(); + assert_eq!(snapshot.collections, 0); + assert_eq!(snapshot.finalizing_collections, 0); + assert_eq!(snapshot.total_bytes_allocated, 0); + assert_eq!(snapshot.total_bytes_freed, 0); + assert_eq!(snapshot.objects_allocated, 0); + assert_eq!(snapshot.objects_swept, 0); + assert_eq!(snapshot.trace_non_roots_time, Duration::ZERO); + assert_eq!(snapshot.mark_time, Duration::ZERO); + assert_eq!(snapshot.finalize_time, Duration::ZERO); + assert_eq!(snapshot.remark_time, Duration::ZERO); + assert_eq!(snapshot.sweep_time, Duration::ZERO); + assert_eq!(snapshot.weak_map_prune_time, Duration::ZERO); + assert_eq!(snapshot.total_time, Duration::ZERO); + // The live byte count is not a statistic, so a reset leaves it unchanged. + assert_eq!(snapshot.bytes_allocated, COUNT * GC_BOX_SIZE); + + drop(values); + }); + } + + #[test] + fn stats_phase_times_within_total() { + run_test(|| { + drop(allocate(COUNT)); + + force_collect(); + + let snapshot = stats(); + assert_eq!(snapshot.finalizing_collections, 1); + + let phases = snapshot.trace_non_roots_time + + snapshot.mark_time + + snapshot.finalize_time + + snapshot.remark_time + + snapshot.sweep_time + + snapshot.weak_map_prune_time; + assert!(phases <= snapshot.total_time); + }); + } +}