rete_core/
build_trace.rs

1//! The **build trace**: where a build spent its wall clock, and what its
2//! external sorts did — the debugging half of the build record that `rete build`
3//! stores in the kind-7 build-info section.
4//!
5//! It is a lap timer, not a profiler. The builders call [`lap`] at the end of
6//! each phase; the time since the previous lap is charged to that phase, so the
7//! phases **partition** the build's wall clock and never overlap. Counters
8//! ([`add`], [`max`]) record what the memory-bounded build's spill did.
9//!
10//! Recording happens only while a [`Collector`] is alive on the **calling
11//! thread** — the CLI starts one around a build. Every other caller (the
12//! bindings, the browser builder, tests that build in parallel threads) pays
13//! one thread-local check per phase and records nothing. That check also keeps
14//! the clock out of `wasm32-unknown-unknown`, where `std::time::Instant::now()`
15//! panics: without a collector it is never called, and on wasm32 the functions
16//! are no-ops.
17
18#[cfg(not(target_arch = "wasm32"))]
19use std::cell::RefCell;
20use std::time::Duration;
21
22/// One phase of a build. A closed set, so a reader of the record knows every
23/// name it can meet, and a writer can size a record before the build has run.
24#[derive(Debug, Clone, Copy, PartialEq, Eq, Hash, PartialOrd, Ord)]
25pub enum Phase {
26    /// Reading the input `.rete` back (`repyramid`, `recard`).
27    Read,
28    /// Reading and parsing the inputs into memory (the in-RAM text path).
29    Parse,
30    /// `--materialize` / `--reason`: the reasoner over the default graph.
31    Reason,
32    /// The two-pass streaming build's first pass: read + parse + observe every
33    /// term, then sort the dictionary.
34    ParseDictionary,
35    /// The two-pass streaming build's second pass: read + parse + encode.
36    ParseEncode,
37    /// The memory-bounded build's single pass: read + parse + spill chunks.
38    ParseChunk,
39    /// The memory-bounded build's `--frequent-objects` pass: one k-way walk of
40    /// the chunks' object counts that picks the terms to promote.
41    FrequentObjects,
42    /// Building the dictionary from parsed statements (in-RAM), or merging the
43    /// chunk dictionaries (memory-bounded).
44    Dictionary,
45    /// Encoding statements to id-triples (in-RAM), or remapping the chunks'
46    /// local ids to global ones (memory-bounded).
47    Encode,
48    /// Deriving the Dataset Card.
49    CardDerive,
50    /// The community pyramid.
51    Pyramid,
52    /// The full-text index.
53    TextIndex,
54    /// The LABEL_INDEX and SCHEMA sections.
55    LabelsSchema,
56    /// Compressing and serializing the dictionary section.
57    DictionarySection,
58    /// Sorting and tiling the index permutations (and, in-RAM, the named
59    /// graphs' indexes).
60    IndexPermutations,
61    /// The memory-bounded build's named-graph indexes or quad index.
62    NamedGraphs,
63    /// Assembling the file image in memory.
64    Serialize,
65    /// Running the card's starter queries against the finished file.
66    StarterQueries,
67    /// Writing the file to disk.
68    Write,
69    /// Folding the content hash over the written sections for a card placed
70    /// after the data (the memory-bounded build, `rete recard --in-place`):
71    /// the card is hashed first, so the rest of the hash can only be folded
72    /// once it exists — one read of every hashed section.
73    ContentHash,
74}
75
76impl Phase {
77    /// Every phase, in declaration order.
78    pub const ALL: [Phase; 20] = [
79        Phase::Read,
80        Phase::Parse,
81        Phase::Reason,
82        Phase::ParseDictionary,
83        Phase::ParseEncode,
84        Phase::ParseChunk,
85        Phase::FrequentObjects,
86        Phase::Dictionary,
87        Phase::Encode,
88        Phase::CardDerive,
89        Phase::Pyramid,
90        Phase::TextIndex,
91        Phase::LabelsSchema,
92        Phase::DictionarySection,
93        Phase::IndexPermutations,
94        Phase::NamedGraphs,
95        Phase::Serialize,
96        Phase::StarterQueries,
97        Phase::Write,
98        Phase::ContentHash,
99    ];
100
101    /// The name the build record stores.
102    pub fn as_str(self) -> &'static str {
103        match self {
104            Phase::Read => "read",
105            Phase::Parse => "parse",
106            Phase::Reason => "reason",
107            Phase::ParseDictionary => "parse+dictionary",
108            Phase::ParseEncode => "parse+encode",
109            Phase::ParseChunk => "parse+chunk",
110            Phase::FrequentObjects => "frequent_objects",
111            Phase::Dictionary => "dictionary",
112            Phase::Encode => "encode",
113            Phase::CardDerive => "card_derive",
114            Phase::Pyramid => "pyramid",
115            Phase::TextIndex => "text_index",
116            Phase::LabelsSchema => "labels+schema",
117            Phase::DictionarySection => "dictionary_section",
118            Phase::IndexPermutations => "index_permutations",
119            Phase::NamedGraphs => "named_graphs",
120            Phase::Serialize => "serialize",
121            Phase::StarterQueries => "starter_queries",
122            Phase::Write => "write",
123            Phase::ContentHash => "content_hash",
124        }
125    }
126}
127
128/// What a [`Collector`] recorded.
129#[derive(Debug, Clone, Default, PartialEq, Eq)]
130pub struct Trace {
131    /// Wall-clock time per phase, in the order each phase first ended. A phase
132    /// that ends more than once (a lap per permutation, say) is summed.
133    pub phases: Vec<(Phase, Duration)>,
134    /// Named counters, sorted by name. The memory-bounded build records
135    /// `chunks`, `sort_runs`, `merge_passes` and `scratch_peak_bytes`.
136    pub counters: Vec<(&'static str, u64)>,
137}
138
139impl Trace {
140    /// A counter's value, if it was recorded.
141    pub fn counter(&self, name: &str) -> Option<u64> {
142        self.counters
143            .iter()
144            .find(|(n, _)| *n == name)
145            .map(|&(_, v)| v)
146    }
147}
148
149#[cfg(not(target_arch = "wasm32"))]
150struct State {
151    last: std::time::Instant,
152    trace: Trace,
153}
154
155#[cfg(not(target_arch = "wasm32"))]
156thread_local! {
157    static ACTIVE: RefCell<Option<State>> = const { RefCell::new(None) };
158}
159
160/// Records the build trace of the current thread for as long as it lives.
161/// Starting a second collector on a thread replaces the first.
162pub struct Collector {
163    _not_send: std::marker::PhantomData<*const ()>,
164}
165
166impl Collector {
167    /// Start recording on this thread; the first lap is timed from now.
168    pub fn start() -> Self {
169        #[cfg(not(target_arch = "wasm32"))]
170        ACTIVE.with(|a| {
171            *a.borrow_mut() = Some(State {
172                last: std::time::Instant::now(),
173                trace: Trace::default(),
174            })
175        });
176        Collector {
177            _not_send: std::marker::PhantomData,
178        }
179    }
180
181    /// What has been recorded so far (the collector keeps recording).
182    pub fn snapshot(&self) -> Trace {
183        #[cfg(not(target_arch = "wasm32"))]
184        {
185            ACTIVE.with(|a| {
186                a.borrow()
187                    .as_ref()
188                    .map(|s| s.trace.clone())
189                    .unwrap_or_default()
190            })
191        }
192        #[cfg(target_arch = "wasm32")]
193        Trace::default()
194    }
195}
196
197impl Drop for Collector {
198    fn drop(&mut self) {
199        #[cfg(not(target_arch = "wasm32"))]
200        ACTIVE.with(|a| *a.borrow_mut() = None);
201    }
202}
203
204/// End `phase`: charge it the wall-clock time since the previous lap (or since
205/// the collector started). A no-op without a collector on this thread.
206pub fn lap(phase: Phase) {
207    #[cfg(not(target_arch = "wasm32"))]
208    ACTIVE.with(|a| {
209        if let Some(s) = a.borrow_mut().as_mut() {
210            let now = std::time::Instant::now();
211            let d = now.duration_since(s.last);
212            s.last = now;
213            match s.trace.phases.iter_mut().find(|(p, _)| *p == phase) {
214                Some((_, total)) => *total += d,
215                None => s.trace.phases.push((phase, d)),
216            }
217        }
218    });
219    #[cfg(target_arch = "wasm32")]
220    let _ = phase;
221}
222
223/// Restart the lap clock without charging anything — for time a caller does
224/// not want attributed to the next phase.
225pub fn skip() {
226    #[cfg(not(target_arch = "wasm32"))]
227    ACTIVE.with(|a| {
228        if let Some(s) = a.borrow_mut().as_mut() {
229            s.last = std::time::Instant::now();
230        }
231    });
232}
233
234fn update(name: &'static str, f: impl FnOnce(u64) -> u64) {
235    #[cfg(not(target_arch = "wasm32"))]
236    ACTIVE.with(|a| {
237        if let Some(s) = a.borrow_mut().as_mut() {
238            let c = &mut s.trace.counters;
239            match c.binary_search_by(|(n, _)| (*n).cmp(name)) {
240                Ok(i) => c[i].1 = f(c[i].1),
241                Err(i) => c.insert(i, (name, f(0))),
242            }
243        }
244    });
245    #[cfg(target_arch = "wasm32")]
246    let _ = (name, f);
247}
248
249/// Add `v` to the counter `name`. A no-op without a collector.
250pub fn add(name: &'static str, v: u64) {
251    update(name, |c| c.saturating_add(v));
252}
253
254/// Raise the counter `name` to `v` if it is lower. A no-op without a collector.
255pub fn max(name: &'static str, v: u64) {
256    update(name, |c| c.max(v));
257}
258
259/// One k-way merge over `inputs` spilled, sorted files (the memory-bounded
260/// build): every such merge reads each of its inputs once, start to end.
261#[cfg(not(target_arch = "wasm32"))]
262pub(crate) fn note_merge(inputs: usize) {
263    add("merge_passes", 1);
264    add("sort_runs", inputs as u64);
265}
266
267/// True while a collector records on this thread — for a measurement that
268/// costs something (a directory walk) and is worth skipping otherwise.
269pub fn active() -> bool {
270    #[cfg(not(target_arch = "wasm32"))]
271    {
272        ACTIVE.with(|a| a.borrow().is_some())
273    }
274    #[cfg(target_arch = "wasm32")]
275    false
276}
277
278/// The Cargo features this `rete-core` was compiled with that change what a
279/// build writes or how fast it runs — recorded with the engine identity.
280pub fn enabled_features() -> Vec<&'static str> {
281    let mut f = Vec::new();
282    if cfg!(feature = "compression") {
283        f.push("compression");
284    }
285    if cfg!(feature = "parallel") {
286        f.push("parallel");
287    }
288    if cfg!(feature = "rdf12-turtle") {
289        f.push("rdf12-turtle");
290    }
291    if cfg!(feature = "unicode-regex") {
292        f.push("unicode-regex");
293    }
294    f
295}
296
297#[cfg(all(test, not(target_arch = "wasm32")))]
298mod tests {
299    use super::*;
300
301    #[test]
302    fn laps_partition_and_accumulate_only_under_a_collector() {
303        lap(Phase::Parse);
304        add("chunks", 3);
305        assert!(!active());
306        let c = Collector::start();
307        assert!(active());
308        lap(Phase::Parse);
309        lap(Phase::Encode);
310        lap(Phase::Parse);
311        add("sort_runs", 2);
312        add("sort_runs", 5);
313        max("scratch_peak_bytes", 10);
314        max("scratch_peak_bytes", 4);
315        let t = c.snapshot();
316        let names: Vec<_> = t.phases.iter().map(|(p, _)| p.as_str()).collect();
317        assert_eq!(
318            names,
319            ["parse", "encode"],
320            "first-end order, repeats summed"
321        );
322        assert_eq!(t.counter("sort_runs"), Some(7));
323        assert_eq!(t.counter("scratch_peak_bytes"), Some(10));
324        assert_eq!(t.counter("chunks"), None, "nothing before the collector");
325        drop(c);
326        assert!(!active());
327        lap(Phase::Write);
328    }
329
330    #[test]
331    fn phase_names_are_distinct() {
332        let mut names: Vec<_> = Phase::ALL.iter().map(|p| p.as_str()).collect();
333        names.sort_unstable();
334        names.dedup();
335        assert_eq!(names.len(), Phase::ALL.len());
336    }
337}
rete_core/build_trace.rs

rete_core/
build_trace.rs
