diff --git a/Cargo.toml b/Cargo.toml index 0d47097c..8418f8da 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -19,6 +19,7 @@ name = "pathmap" path = "src/lib.rs" [dependencies] +span-timing = { version = "0.1.0", path = "../span-timing" } pathmap-derive = { version = "0.3.0", path = "./pathmap-derive" } maybe-dangling = "0.1.1" dyn-clone = "1.0.17" # NOTE, we can eliminate this when we eliminate `!slim_ptrs` diff --git a/examples/arena_compact_tests/src/main.rs b/examples/arena_compact_tests/src/main.rs index 576eef7c..4258353d 100644 --- a/examples/arena_compact_tests/src/main.rs +++ b/examples/arena_compact_tests/src/main.rs @@ -29,6 +29,8 @@ fn arena_create() -> Result<(), std::io::Error> { println!("len {:.2?}", tree.get_data().len()); // pathmap::alloc_tracking::read().print(); // pathmap::alloc_tracking::reset(); + pathmap::timed_span::print_counters(); + pathmap::timed_span::reset_counters(); let start = Instant::now(); let mut zipper = tree.read_zipper(); @@ -38,6 +40,8 @@ fn arena_create() -> Result<(), std::io::Error> { assert!(zipper.descend_to_existing(path) == path.len()); // assert_eq!(zipper.path(), path); } + pathmap::timed_span::print_counters(); + println!("checked act in {:.2?}", start.elapsed()); let start = Instant::now(); let tree2 = ArenaCompactTree::from_zipper(tree.read_zipper(), |_v| 0); @@ -78,6 +82,7 @@ fn arena_dump() -> Result<(), std::io::Error> { assert!(zipper.descend_to_existing(path) == path.len()); // assert_eq!(zipper.path(), path); } + pathmap::timed_span::print_counters(); println!("checked act in {:.2?}", start.elapsed()); let start = Instant::now(); let tree2 = ArenaCompactTree::from_zipper(tree.read_zipper(), |_v| 0); diff --git a/src/arena_compact.rs b/src/arena_compact.rs index 086ea772..ed8a65d0 100644 --- a/src/arena_compact.rs +++ b/src/arena_compact.rs @@ -82,6 +82,7 @@ use std::marker::PhantomData; use fast_slice_utils::starts_with; use crate::alloc::{GlobalAlloc, global_alloc}; +use crate::timed_span::{TimingEntries::*, COUNTERS, timed_span}; use crate::{ PathMap, morphisms::Catamorphism, @@ -92,7 +93,6 @@ use crate::{ ZipperConcrete, ZipperReadOnlyConditionalValues, TrieRef }, }; - use crate::gxhash::{GxHasher, HashMap, HashMapExt}; /// The identifier of a node (branch node or line node) @@ -2886,6 +2886,7 @@ where Storage: AsRef<[u8]> /// Resets the zipper's focus back to the root fn reset(&mut self) { + timed_span!(Reset, COUNTERS); // self.ascend(self.path.len() - self.origin_depth); let (cur_node, _) = self.tree.get_node(self.stack[0].node_id); self.cur_node = cur_node; @@ -2902,6 +2903,7 @@ where Storage: AsRef<[u8]> /// /// WARNING: This is not a cheap method. It may have an order-N cost fn val_count(&self) -> usize { + timed_span!(ValueCount, COUNTERS); let mut zipper = self.clone(); zipper.reset(); let mut count = 0; @@ -2919,6 +2921,7 @@ where Storage: AsRef<[u8]> /// Returns `true` if the zipper points to an existing path within the tree, otherwise `false`. The /// zipper's location will be updated, regardless of whether or not the path exists within the tree. fn descend_to>(&mut self, path: P) { + timed_span!(DescendTo, COUNTERS); let path = path.as_ref(); let depth = path.len(); let descended = self.descend_to_existing(path); @@ -2935,6 +2938,7 @@ where Storage: AsRef<[u8]> /// existing path after this method returns, unless the method was called with the focus on a /// non-existent path. fn descend_to_existing>(&mut self, path: P) -> usize { + timed_span!(DescendToExisting, COUNTERS); self.descend_cond(path.as_ref(), false) } @@ -2945,17 +2949,15 @@ where Storage: AsRef<[u8]> /// /// If the focus is already on a value, this method will descend to the *next* value along /// the path. - fn descend_to_value>(&mut self, path: K) -> usize { - self.descend_cond(path.as_ref(), true) - } - fn descend_to_val>(&mut self, path: K) -> usize { + timed_span!(DescendToVal, COUNTERS); self.descend_cond(path.as_ref(), true) } /// Moves the zipper one byte deeper into the trie. Identical in effect to [descend_to](Self::descend_to) /// with a 1-byte key argument fn descend_to_byte(&mut self, k: u8) { + timed_span!(DescendToByte, COUNTERS); self.descend_to(&[k]) } @@ -2967,6 +2969,7 @@ where Storage: AsRef<[u8]> /// to the trie. This method should only be used as part of a directed traversal operation, but /// index-based paths may not be stored as locations within the trie. fn descend_indexed_byte(&mut self, idx: usize) -> bool { + timed_span!(DescendIndexedByte, COUNTERS); if self.invalid > 0 { return false; } @@ -3021,12 +3024,14 @@ where Storage: AsRef<[u8]> /// NOTE: This method should have identical behavior to passing `0` to [descend_indexed_byte](ZipperMoving::descend_indexed_byte), /// although with less overhead fn descend_first_byte(&mut self) -> bool { + timed_span!(DescendFirstByte, COUNTERS); self.descend_indexed_byte(0) } /// Descends the zipper's focus until a branch or a value is encountered. Returns `true` if the focus /// moved otherwise returns `false` fn descend_until(&mut self) -> bool { + timed_span!(DescendUntil, COUNTERS); self.trace_pos(); let mut descended = false; 'descend: while self.child_count() == 1 { @@ -3077,6 +3082,7 @@ where Storage: AsRef<[u8]> /// If the root is fewer than `n` steps from the zipper's position, then this method will stop at /// the root and return `false` fn ascend(&mut self, mut steps: usize) -> bool { + timed_span!(Ascend, COUNTERS); self.trace_pos(); if !self.ascend_invalid(Some(&mut steps)) { return false; @@ -3103,12 +3109,14 @@ where Storage: AsRef<[u8]> /// Ascends the zipper up a single byte. Equivalent to passing `1` to [ascend](Self::ascend) fn ascend_byte(&mut self) -> bool { + timed_span!(AscendByte, COUNTERS); self.ascend(1) } /// Ascends the zipper to the nearest upstream branch point or value. Returns `true` if the zipper /// focus moved upwards, otherwise returns `false` if the zipper was already at the root fn ascend_until(&mut self) -> bool { + timed_span!(AscendUntil, COUNTERS); self.ascend_to_branch(true) } @@ -3116,16 +3124,19 @@ where Storage: AsRef<[u8]> /// `true` if the zipper focus moved upwards, otherwise returns `false` if the zipper was already at the /// root fn ascend_until_branch(&mut self) -> bool { + timed_span!(AscendUntilBranch, COUNTERS); self.ascend_to_branch(false) } #[inline] fn to_next_sibling_byte(&mut self) -> bool { + timed_span!(ToNextSiblingByte, COUNTERS); self.to_sibling(true) } #[inline] fn to_prev_sibling_byte(&mut self) -> bool { + timed_span!(ToPrevSiblingByte, COUNTERS); self.to_sibling(false) } @@ -3141,6 +3152,7 @@ where Storage: AsRef<[u8]> /// /// Returns a reference to the value or `None` if the zipper has encountered the root. fn to_next_val(&mut self) -> bool { + timed_span!(ToNextVal, COUNTERS); while self.to_next_step() { if self.is_val() { return true; @@ -3160,6 +3172,7 @@ where Storage: AsRef<[u8]> /// /// See: [to_next_k_path](ZipperIteration::to_next_k_path) fn descend_first_k_path(&mut self, k: usize) -> bool { + timed_span!(DescendFirstKPath, COUNTERS); for ii in 0..k { if !self.descend_first_byte() { self.ascend(ii); @@ -3181,6 +3194,7 @@ where Storage: AsRef<[u8]> /// /// See: [descend_first_k_path](ZipperIteration::descend_first_k_path) fn to_next_k_path(&mut self, k: usize) -> bool { + timed_span!(ToNextKPath, COUNTERS); let mut depth = k; 'outer: loop { while depth > 0 && self.child_count() <= 1 { diff --git a/src/lib.rs b/src/lib.rs index 8df862be..302363dc 100644 --- a/src/lib.rs +++ b/src/lib.rs @@ -114,6 +114,9 @@ pub mod random; #[cfg(feature = "counters")] pub mod counters; +/// Feature for code instrumentation and optimization +pub mod timed_span; + /// Shims to allow the use of a custom [`Allocator`](std::alloc::Allocator) type, if running with the `nightly` feature. Does nothing otherwise pub mod alloc; diff --git a/src/timed_span.rs b/src/timed_span.rs new file mode 100644 index 00000000..5a73dce1 --- /dev/null +++ b/src/timed_span.rs @@ -0,0 +1,85 @@ +use core::sync::atomic::Ordering; + +use span_timing::{Counter, timing_entries}; + +/// Set to `true` to enable timing on ReadZipperCore and ACTZipper ops. Currently not implemented for +/// other zipper types, except insofar as they call through to a zipper with the implementation. +pub(crate) const ENABLED: bool = false; + +/// Wrapper macro to enable and disable span timing +macro_rules! timed_span { + ($entry:expr, $counters:expr $(,)?) => { + let _timed_span_guard = if $crate::timed_span::ENABLED { + Some(::span_timing::timed_span!($entry, $counters)) + } else { + None + }; + }; +} + +pub(crate) use timed_span; + +timing_entries! { + pub enum TimingEntries { + Reset, + ValueCount, + DescendTo, + DescendToExisting, + DescendToVal, //ReadZipperCore doesn't have a native impl for this method yet + DescendToByte, + DescendIndexedByte, + DescendFirstByte, + DescendUntil, + // MoveToPath, This is only implemented with a default impl, and it's composed from other zipper ops + AscendByte, + Ascend, + ToNextSiblingByte, + ToPrevSiblingByte, + // ToNextStep, This is only implemented with a default impl, and it's composed from other zipper ops + AscendUntil, + AscendUntilBranch, + ToNextVal, + DescendFirstKPath, + ToNextKPath, + ToNextGetValue, + ForkReadZipper, + } + pub static COUNTERS: [Counter]; +} + +pub fn reset_counters() { + for counter in &COUNTERS { + counter.reset(); + } +} + +pub fn print_counters() { + println!("{:>20},Count,TicksDelta,TicksAverage", "Name"); + for &entry in TimingEntries::ALL { + let counter = &COUNTERS[entry as usize]; + let count = counter.count.load(Ordering::Relaxed); + let ticks = counter.ticks.load(Ordering::Relaxed); + if count == 0 && ticks == 0 { + continue; + } + let average = ticks as f64 / count as f64; + println!("{:>20},{},{},{}", entry.to_str(), count, ticks, average); + } +} + +#[cfg(test)] +mod tests { + use super::*; + + #[test] + fn test_timed_span() { + reset_counters(); + { + timed_span!(TimingEntries::Reset, COUNTERS); + for ii in 0..100_000 { + core::hint::black_box(ii); + } + } + print_counters(); + } +} diff --git a/src/zipper.rs b/src/zipper.rs index 95314fe9..ada57c47 100644 --- a/src/zipper.rs +++ b/src/zipper.rs @@ -13,6 +13,7 @@ use crate::alloc::{Allocator, GlobalAlloc}; use crate::utils::ByteMask; use crate::trie_node::*; use crate::PathMap; +use crate::timed_span::{TimingEntries::*, COUNTERS, timed_span}; pub use crate::write_zipper::*; pub use crate::trie_ref::*; @@ -1348,7 +1349,7 @@ pub(crate) mod read_zipper_core { } } //GOAT, may be unneeded - // /// Returns a reference to the + // /// Returns a reference to the // #[inline] // pub fn as_option(&self) -> Option<&T> { // match self { @@ -1476,6 +1477,7 @@ pub(crate) mod read_zipper_core { impl ZipperForking for ReadZipperCore<'_, '_, V, A> { type ReadZipperT<'a> = ReadZipperCore<'a, 'a, V, A> where Self: 'a; fn fork_read_zipper<'a>(&'a self) -> Self::ReadZipperT<'a> { + timed_span!(ForkReadZipper, COUNTERS); let new_root_val = self.val(); let new_root_path = self.origin_path(); let new_root_key_start = new_root_path.len() - self.node_key().len(); @@ -1558,6 +1560,7 @@ pub(crate) mod read_zipper_core { } fn reset(&mut self) { + timed_span!(Reset, COUNTERS); self.ancestors.truncate(1); match self.ancestors.pop() { Some((node, _tok, _prefix_len)) => { @@ -1579,6 +1582,7 @@ pub(crate) mod read_zipper_core { } fn val_count(&self) -> usize { + timed_span!(ValueCount, COUNTERS); let root_val = self.is_val() as usize; if self.node_key().len() == 0 { val_count_below_root(*self.focus_node) + root_val @@ -1592,6 +1596,7 @@ pub(crate) mod read_zipper_core { } } fn descend_to>(&mut self, k: K) { + timed_span!(DescendTo, COUNTERS); let k = k.as_ref(); if k.len() == 0 { return //Zero-length path is a no-op @@ -1623,6 +1628,7 @@ pub(crate) mod read_zipper_core { #[inline] fn descend_to_byte(&mut self, k: u8) { + timed_span!(DescendToByte, COUNTERS); self.prepare_buffers(); debug_assert!(self.is_regularized()); @@ -1658,6 +1664,7 @@ pub(crate) mod read_zipper_core { } fn descend_indexed_byte(&mut self, child_idx: usize) -> bool { + timed_span!(DescendIndexedByte, COUNTERS); self.prepare_buffers(); debug_assert!(self.is_regularized()); @@ -1679,6 +1686,7 @@ pub(crate) mod read_zipper_core { } fn descend_first_byte(&mut self) -> bool { + timed_span!(DescendFirstByte, COUNTERS); self.prepare_buffers(); debug_assert!(self.is_regularized()); let cur_tok = self.focus_node.iter_token_for_path(self.node_key()); @@ -1720,6 +1728,7 @@ pub(crate) mod read_zipper_core { } fn descend_until(&mut self) -> bool { + timed_span!(DescendUntil, COUNTERS); debug_assert!(self.is_regularized()); let mut moved = false; while self.child_count() == 1 { @@ -1780,6 +1789,7 @@ pub(crate) mod read_zipper_core { } fn descend_to_existing>(&mut self, k: K) -> usize { + timed_span!(DescendToExisting, COUNTERS); let mut k = k.as_ref(); if k.len() == 0 { return 0 //Zero-length path is a no-op @@ -1845,6 +1855,7 @@ pub(crate) mod read_zipper_core { // } fn to_next_sibling_byte(&mut self) -> bool { + timed_span!(ToNextSiblingByte, COUNTERS); self.prepare_buffers(); if self.prefix_buf.len() == 0 { return false @@ -1905,10 +1916,12 @@ pub(crate) mod read_zipper_core { } fn to_prev_sibling_byte(&mut self) -> bool { + timed_span!(ToPrevSiblingByte, COUNTERS); self.to_sibling(false) } fn ascend(&mut self, mut steps: usize) -> bool { + timed_span!(Ascend, COUNTERS); debug_assert!(self.is_regularized()); while steps > 0 { if self.excess_key_len() == 0 { @@ -1932,6 +1945,7 @@ pub(crate) mod read_zipper_core { } fn ascend_byte(&mut self) -> bool { + timed_span!(AscendByte, COUNTERS); debug_assert!(self.is_regularized()); if self.excess_key_len() == 0 { match self.ancestors.pop() { @@ -1951,6 +1965,7 @@ pub(crate) mod read_zipper_core { } fn ascend_until(&mut self) -> bool { + timed_span!(AscendUntil, COUNTERS); debug_assert!(self.is_regularized()); if self.at_root() { return false; @@ -1967,6 +1982,7 @@ pub(crate) mod read_zipper_core { } fn ascend_until_branch(&mut self) -> bool { + timed_span!(AscendUntilBranch, COUNTERS); debug_assert!(self.is_regularized()); if self.at_root() { return false; @@ -2109,9 +2125,11 @@ pub(crate) mod read_zipper_core { impl<'trie, V: Clone + Send + Sync + Unpin + 'trie, A: Allocator + 'trie> ZipperIteration for ReadZipperCore<'trie, '_, V, A> { fn to_next_val(&mut self) -> bool { + timed_span!(ToNextVal, COUNTERS); unsafe{ self.to_next_get_val() }.is_some() } fn descend_first_k_path(&mut self, k: usize) -> bool { + timed_span!(DescendFirstKPath, COUNTERS); self.prepare_buffers(); debug_assert!(self.is_regularized()); @@ -2121,6 +2139,7 @@ pub(crate) mod read_zipper_core { self.k_path_internal(k, self.prefix_buf.len()) } fn to_next_k_path(&mut self, k: usize) -> bool { + timed_span!(ToNextKPath, COUNTERS); let base_idx = if self.path_len() >= k { self.prefix_buf.len() - k } else { @@ -2359,6 +2378,7 @@ pub(crate) mod read_zipper_core { /// See [ReadZipperCore::get_val] for explanation as to why this is unsafe pub(crate) unsafe fn to_next_get_val(&mut self) -> Option<&'a V> { + timed_span!(ToNextGetValue, COUNTERS); self.prepare_buffers(); loop { if self.focus_iter_token == NODE_ITER_INVALID { @@ -2923,7 +2943,7 @@ pub struct ReadZipperPathIter<'a, 'path, V: Clone + Send + Sync, A: Allocator = } impl ReadZipperPathIter<'_, '_, V, A> { - /// Returns a reference to the value at the last-returned path + /// Returns a reference to the value at the last-returned path pub fn val(&self) -> Option<&V> { self.zipper.as_ref().and_then(|z| z.val()) }