Skip to main content

sui_eval/
perf.rs

1//! Lightweight evaluation profiling counters.
2//! Enabled via `SUI_EVAL_PERF=1` environment variable.
3//!
4//! Uses enum-indexed array dispatch instead of string matching —
5//! a single `counts[variant as usize] += 1` per call, zero string
6//! comparisons.
7
8use std::cell::RefCell;
9use std::sync::atomic::{AtomicBool, Ordering};
10use std::time::Instant;
11
12/// Cached flag — checked once at startup to avoid repeated `env::var` calls.
13static ENABLED: AtomicBool = AtomicBool::new(false);
14
15/// Check the env var and, if set, enable counters. Called on every
16/// top-level `eval()`. Deliberately one-way: if `SUI_EVAL_PERF` is
17/// NOT set we leave the flag as-is rather than clearing it, so that
18/// a prior `set_enabled(true)` (from a profiling tool or integration
19/// test) survives the next `eval()` call.
20pub fn init() {
21    if std::env::var("SUI_EVAL_PERF").ok().as_deref() == Some("1") {
22        ENABLED.store(true, Ordering::Relaxed);
23    }
24}
25
26/// Enable or disable perf counters programmatically. Use this from
27/// profiling tools, integration tests, or the `sui perf` subcommand
28/// that wants counters even when `SUI_EVAL_PERF=1` isn't set in the
29/// environment. Production code paths don't call this.
30pub fn set_enabled(on: bool) {
31    ENABLED.store(on, Ordering::Relaxed);
32}
33
34/// Whether profiling is enabled (fast atomic load).
35#[inline(always)]
36pub fn enabled() -> bool {
37    ENABLED.load(Ordering::Relaxed)
38}
39
40/// Performance counter identifiers.
41///
42/// Each variant maps to a fixed array index via `as usize`.
43/// This avoids string matching in the hot path.
44#[repr(u8)]
45#[derive(Clone, Copy)]
46pub enum Counter {
47    EvalExpr = 0,
48    ForceValue = 1,
49    ThunkForce = 2,
50    ThunkHit = 3,
51    Import = 4,
52    ImportHit = 5,
53    Apply = 6,
54    Select = 7,
55    Attrset = 8,
56    EnvClone = 9,
57    EnvLookup = 10,
58    EnvLookupDepth = 11,
59    // Expression type breakdown
60    ExprIdent = 12,
61    ExprLiteral = 13,
62    ExprStr = 14,
63    ExprList = 15,
64    ExprAttrs = 16,
65    ExprSelect = 17,
66    ExprApply = 18,
67    ExprLetIn = 19,
68    ExprIfElse = 20,
69    ExprWith = 21,
70    ExprLambda = 22,
71    ExprOther = 23,
72    // Dead binding elimination
73    DeadBindingsSkipped = 24,
74    // Finer "other" breakdown
75    ExprBinOp = 25,
76    ExprHasAttr = 26,
77    ExprUnaryOp = 27,
78    ExprAssert = 28,
79    ExprPath = 29,
80    // Overlay (`//`) flatten instrumentation. `OverlayFlattenAttempt` counts
81    // every `as_flat()` call on an Overlay node; `OverlayFlattenBuild` counts
82    // the subset that actually ran the merge closure (a cache MISS — real
83    // O(n) work). `OverlayFlattenEntries` accumulates total (left+right)
84    // entries merged across all builds — the raw work volume. The redundancy
85    // signal is builds / attempts: a high ratio means the same logical
86    // overlay content is re-flattened because each fixpoint iteration mints a
87    // fresh node with a cold cache.
88    OverlayFlattenAttempt = 30,
89    OverlayFlattenBuild = 31,
90    OverlayFlattenEntries = 32,
91    OverlayCreated = 33,
92    // `sorted_entries()` — the sorted-name/value path used by `attrNames`,
93    // `attrValues`, `keys`, `iter`. Each call resolves every Symbol → String
94    // and string-sorts. `SortedEntriesCalls` counts invocations;
95    // `SortedEntriesRows` accumulates entries sorted.
96    SortedEntriesCalls = 34,
97    SortedEntriesRows = 35,
98    // List concatenation (`++` / `concatLists` / `concatMap`). `ListConcatCalls`
99    // counts concat operations; `ListConcatElemsCopied` accumulates the total
100    // number of list ELEMENTS physically copied (cloned) into a fresh Vec —
101    // the O(n) storm signal. `ListConcatElemsReused` accumulates the elements
102    // that were appended in place (Rc uniquely owned) instead of copied — the
103    // work the structural-share fix elides. A left-associative `++` fold over a
104    // growing accumulator makes elems_copied grow quadratically without the fix.
105    ListConcatCalls = 36,
106    ListConcatElemsCopied = 37,
107    ListConcatElemsReused = 38,
108    // Attrset structural equality (`Concrete::eq` Attrs arm, the non-ptr-eq /
109    // non-derivation fallback that runs a full structural compare).
110    // `AttrsEqStructuralCalls` counts how often that fallback is reached — each
111    // is one site where the old `a.inner() == b.inner()` cloned BOTH backing
112    // FxHashMaps purely to feed `HashMap::eq`. `AttrsEqEntriesCloneElided`
113    // accumulates the combined entry count of both operands (the total map
114    // entries no longer cloned by the borrow-compare fix). Purely a
115    // measurement of eliminated clone/allocation work — the compare itself is
116    // byte-identical (PERF-ARSENAL C-A).
117    AttrsEqStructuralCalls = 39,
118    AttrsEqEntriesCloneElided = 40,
119    // M2 RISKY-tier waste measurement (C-with / C-slash / C-store).
120    // `WithScopeCacheClone` counts every `(**attrs).clone()` a with-scope
121    // lookup does to populate its `Rc<RefCell<Option<NixAttrs>>>` cache (C-with)
122    // — an `im_rc` HAMT root clone (O(1) structural share), NOT an O(n) deep
123    // copy. `SlashDeferredTailClone` counts the `(**la).clone()` in
124    // `lazy_overlay_merge` (C-slash) — same O(1) HAMT clone, then COW-mutated.
125    // `ThunkStoreWrites` counts the double `repr = Evaluated` + `cache.set`
126    // stores per successful force (C-store). Pure measurement — confirms
127    // whether the "waste" the arsenal names is real O(n) or already-O(1).
128    WithScopeCacheClone = 41,
129    SlashDeferredTailClone = 42,
130    ThunkStoreWrites = 43,
131    // C-store sub-probe: counts forces where the post-Store#1 thunk-chain
132    // unwrap loop actually MUTATED `value` (so Store#2's content ≠ Store#1's).
133    // When this is 0, Store#1 and Store#2 write byte-identical content and a
134    // collapse to a single store is trivially content-neutral; when > 0, the
135    // two stores hold different values and collapsing would change what an
136    // interleaved observer sees.
137    ThunkStoreLoopMutated = 44,
138    // C-store sub-probe #2: forces where `value` was NOT a thunk at Store#1,
139    // so the unwrap loop never ran and Store#2 is a pure redundant rewrite of
140    // byte-identical content. Skipping Store#2 here is provably
141    // content-and-order-neutral (Store#1 already established the final state).
142    ThunkStoreRedundant = 45,
143    // Storm A instrumentation: `referenced_idents` (eval.rs) is the residual
144    // self/mutual-recursion detection walk. `referenced_idents` already hoisted
145    // the original O(N²) per-`(binding × sibling-name)` re-walk down to O(N) per
146    // scope (ONE subtree walk per RHS, then O(1) set lookups). These counters
147    // measure the RESIDUAL cost that survives that hoist — the per-fixpoint-
148    // iteration subtree walks that still run once per let/rec binding RHS.
149    // `SelfRecWalkCalls` counts every `referenced_idents` invocation (= number
150    // of binding RHS subtree walks). `SelfRecWalkNodes` accumulates the total
151    // rnix `descendants()` visited across all walks — the raw work volume, the
152    // Storm-A analogue of `sorted_entries_rows`. A DEEP nested-let closure (the
153    // cid module-fixpoint) re-parses + re-walks the same RHS shapes across
154    // fixpoint iterations, so nodes/call stays high even though the O(N²) is
155    // gone. Byte-neutral: pure measurement, the recursion verdict is unchanged.
156    SelfRecWalkCalls = 46,
157    SelfRecWalkNodes = 47,
158    // M2 thunk-waste creation-site attribution (byte-neutral): categorize
159    // WHERE `new_suspended` thunks are minted so the 51.8%-never-forced waste
160    // can be traced to a source. Each counter is one class of call site:
161    // `ThunkSiteMaybeOther` = the `maybe_thunk` `_` fall-through arm (every
162    // non-trivial expr the attrset/let-binding thunker wraps); `ThunkSiteApplyArg`
163    // = the `eval_apply` lambda-arg thunk (call-by-need); `ThunkSiteMaybeIdent`
164    // = the `maybe_thunk` ident arms that fall back to a thunk (blackhole/miss);
165    // `ThunkSiteLetForward` = a forward-reference let/rec binding thunk;
166    // `ThunkSiteOther` = every other direct `new_suspended` (inherit source,
167    // select-source, misc). Pure measurement — the thunk minted is identical.
168    ThunkSiteMaybeOther = 48,
169    ThunkSiteApplyArg = 49,
170    ThunkSiteMaybeIdent = 50,
171    ThunkSiteLetForward = 51,
172    ThunkSiteOther = 52,
173    // Further split of the "rest" bucket to confirm it is
174    // already-forced-by-construction (evaluated) / flake-input (native) /
175    // inherit-source, NOT harmful never-forced waste.
176    ThunkSiteInheritSrc = 53,
177    ThunkSiteNative = 54,
178    ThunkSiteEvaluated = 55,
179}
180
181const NUM_COUNTERS: usize = 56;
182
183/// Display names for each counter, indexed by `Counter as usize`.
184const COUNTER_NAMES: [&str; NUM_COUNTERS] = [
185    "eval_expr",
186    "force_value",
187    "thunk_forces",
188    "thunk_hits",
189    "imports",
190    "import_hits",
191    "apply",
192    "select",
193    "attrsets",
194    "env_clones",
195    "env_lookups",
196    "env_lookup_depth",
197    "expr_ident",
198    "expr_literal",
199    "expr_str",
200    "expr_list",
201    "expr_attrs",
202    "expr_select",
203    "expr_apply",
204    "expr_letin",
205    "expr_ifelse",
206    "expr_with",
207    "expr_lambda",
208    "expr_other",
209    "dead_bindings_skipped",
210    "expr_binop",
211    "expr_hasattr",
212    "expr_unaryop",
213    "expr_assert",
214    "expr_path",
215    "overlay_flatten_attempt",
216    "overlay_flatten_build",
217    "overlay_flatten_entries",
218    "overlay_created",
219    "sorted_entries_calls",
220    "sorted_entries_rows",
221    "list_concat_calls",
222    "list_concat_elems_copied",
223    "list_concat_elems_reused",
224    "attrs_eq_structural_calls",
225    "attrs_eq_entries_clone_elided",
226    "with_scope_cache_clone",
227    "slash_deferred_tail_clone",
228    "thunk_store_writes",
229    "thunk_store_loop_mutated",
230    "thunk_store_redundant",
231    "self_rec_walk_calls",
232    "self_rec_walk_nodes",
233    "thunk_site_maybe_other",
234    "thunk_site_apply_arg",
235    "thunk_site_maybe_ident",
236    "thunk_site_let_forward",
237    "thunk_site_other",
238    "thunk_site_inherit_src",
239    "thunk_site_native",
240    "thunk_site_evaluated",
241];
242
243struct PerfCounters {
244    counts: [u64; NUM_COUNTERS],
245}
246
247impl Default for PerfCounters {
248    fn default() -> Self {
249        Self {
250            counts: [0; NUM_COUNTERS],
251        }
252    }
253}
254
255impl PerfCounters {
256    #[inline(always)]
257    fn inc(&mut self, counter: Counter) {
258        self.counts[counter as usize] += 1;
259    }
260
261    #[inline(always)]
262    fn add(&mut self, counter: Counter, n: u64) {
263        self.counts[counter as usize] += n;
264    }
265
266    #[inline(always)]
267    fn get(&self, counter: Counter) -> u64 {
268        self.counts[counter as usize]
269    }
270}
271
272thread_local! {
273    static COUNTERS: RefCell<PerfCounters> = RefCell::new(PerfCounters::default());
274    static START: RefCell<Option<Instant>> = RefCell::new(None);
275}
276
277pub fn start() {
278    if enabled() {
279        START.with(|s| *s.borrow_mut() = Some(Instant::now()));
280    }
281}
282
283/// How often to print a progress snapshot (every N eval_expr calls).
284const PROGRESS_INTERVAL: u64 = 1_000_000;
285
286#[inline(always)]
287pub fn inc(counter: Counter) {
288    if !enabled() {
289        return;
290    }
291    COUNTERS.with(|c| {
292        let mut c = c.borrow_mut();
293        c.inc(counter);
294        // Progress reporting for EvalExpr
295        if matches!(counter, Counter::EvalExpr)
296            && c.get(Counter::EvalExpr) % PROGRESS_INTERVAL == 0
297        {
298            let elapsed = START.with(|s| {
299                s.borrow()
300                    .map(|s| s.elapsed().as_secs_f64())
301                    .unwrap_or(0.0)
302            });
303            eprintln!(
304                "[perf] {:.1}s | eval:{} force:{} thunk_f:{} thunk_h:{} import:{}({}) apply:{} select:{} attrset:{} env_c:{} env_l:{}",
305                elapsed,
306                c.get(Counter::EvalExpr),
307                c.get(Counter::ForceValue),
308                c.get(Counter::ThunkForce),
309                c.get(Counter::ThunkHit),
310                c.get(Counter::Import),
311                c.get(Counter::ImportHit),
312                c.get(Counter::Apply),
313                c.get(Counter::Select),
314                c.get(Counter::Attrset),
315                c.get(Counter::EnvClone),
316                c.get(Counter::EnvLookup),
317            );
318            // Expression type breakdown
319            eprintln!(
320                "  [id:{} ap:{} if:{} let:{} sel:{} at:{} w:{} lam:{} lit:{} str:{} list:{} ot:{}]",
321                c.get(Counter::ExprIdent),
322                c.get(Counter::ExprApply),
323                c.get(Counter::ExprIfElse),
324                c.get(Counter::ExprLetIn),
325                c.get(Counter::ExprSelect),
326                c.get(Counter::ExprAttrs),
327                c.get(Counter::ExprWith),
328                c.get(Counter::ExprLambda),
329                c.get(Counter::ExprLiteral),
330                c.get(Counter::ExprStr),
331                c.get(Counter::ExprList),
332                c.get(Counter::ExprOther),
333            );
334            // Finer "other" breakdown
335            let binop = c.get(Counter::ExprBinOp);
336            let hasattr = c.get(Counter::ExprHasAttr);
337            let unary = c.get(Counter::ExprUnaryOp);
338            let assert = c.get(Counter::ExprAssert);
339            let path = c.get(Counter::ExprPath);
340            if binop + hasattr + unary + assert + path > 0 {
341                eprintln!(
342                    "  [binop:{binop} hasattr:{hasattr} unary:{unary} assert:{assert} path:{path}]",
343                );
344            }
345            // Dead binding elimination stats
346            let dead = c.get(Counter::DeadBindingsSkipped);
347            // Thunk creation stats
348            let created = crate::trace::get_thunks_created();
349            let forced = crate::trace::get_thunks_forced();
350            if created > 0 {
351                let waste = (1.0 - forced as f64 / created as f64) * 100.0;
352                eprintln!("  [thunks created:{created} forced:{forced} waste:{waste:.0}% dead_skipped:{dead}]");
353            }
354            // Force-site breakdown
355            crate::eval::dump_force_sites();
356        }
357    });
358}
359
360/// Increment the lookup depth accumulator by `depth`.
361#[inline(always)]
362pub fn add(counter: Counter, n: u64) {
363    if !enabled() {
364        return;
365    }
366    COUNTERS.with(|c| {
367        c.borrow_mut().add(counter, n);
368    });
369}
370
371pub fn report() {
372    if !enabled() {
373        return;
374    }
375    COUNTERS.with(|c| {
376        let c = c.borrow();
377        let elapsed = START.with(|s| {
378            s.borrow()
379                .map(|s| s.elapsed().as_secs_f64())
380                .unwrap_or(0.0)
381        });
382        let lookups = c.get(Counter::EnvLookup);
383        let depth_total = c.get(Counter::EnvLookupDepth);
384        let avg_lookup = if lookups > 0 {
385            depth_total as f64 / lookups as f64
386        } else {
387            0.0
388        };
389        eprintln!("\n=== sui-eval performance ===");
390        eprintln!("elapsed:        {elapsed:.2}s");
391        eprintln!("eval_expr:      {}", c.get(Counter::EvalExpr));
392        eprintln!("force_value:    {}", c.get(Counter::ForceValue));
393        eprintln!("thunk_forces:   {}", c.get(Counter::ThunkForce));
394        eprintln!("thunk_hits:     {}", c.get(Counter::ThunkHit));
395        eprintln!(
396            "imports:        {} ({} cached)",
397            c.get(Counter::Import),
398            c.get(Counter::ImportHit)
399        );
400        eprintln!("apply:          {}", c.get(Counter::Apply));
401        eprintln!("select:         {}", c.get(Counter::Select));
402        eprintln!("attrsets:       {}", c.get(Counter::Attrset));
403        eprintln!("env_clones:     {}", c.get(Counter::EnvClone));
404        eprintln!(
405            "env_lookups:    {} (avg depth {avg_lookup:.1})",
406            lookups
407        );
408        // Expression type breakdown
409        let total = c.get(Counter::EvalExpr);
410        if total > 0 {
411            eprintln!("--- expression breakdown ---");
412            for (counter, name) in [
413                (Counter::ExprIdent, "ident"),
414                (Counter::ExprApply, "apply"),
415                (Counter::ExprLetIn, "let-in"),
416                (Counter::ExprIfElse, "if-else"),
417                (Counter::ExprSelect, "select"),
418                (Counter::ExprAttrs, "attrset"),
419                (Counter::ExprWith, "with"),
420                (Counter::ExprLambda, "lambda"),
421                (Counter::ExprLiteral, "literal"),
422                (Counter::ExprStr, "string"),
423                (Counter::ExprList, "list"),
424                (Counter::ExprBinOp, "binop"),
425                (Counter::ExprHasAttr, "hasattr"),
426                (Counter::ExprUnaryOp, "unaryop"),
427                (Counter::ExprAssert, "assert"),
428                (Counter::ExprPath, "path"),
429                (Counter::ExprOther, "other"),
430            ] {
431                let n = c.get(counter);
432                if n > 0 {
433                    let pct = (n as f64 / total as f64) * 100.0;
434                    eprintln!("  {name:<12} {n:>12} ({pct:.1}%)");
435                }
436            }
437        }
438        // Dead binding elimination
439        let dead = c.get(Counter::DeadBindingsSkipped);
440        if dead > 0 {
441            eprintln!("dead_skipped:   {dead}");
442        }
443        // Overlay (`//`) flatten stats — the re-flatten storm signal.
444        let ov_created = c.get(Counter::OverlayCreated);
445        let ov_attempt = c.get(Counter::OverlayFlattenAttempt);
446        let ov_build = c.get(Counter::OverlayFlattenBuild);
447        let ov_entries = c.get(Counter::OverlayFlattenEntries);
448        if ov_created > 0 || ov_attempt > 0 {
449            let hit = ov_attempt.saturating_sub(ov_build);
450            let hit_rate = if ov_attempt > 0 {
451                (hit as f64 / ov_attempt as f64) * 100.0
452            } else {
453                0.0
454            };
455            eprintln!("--- overlay (`//`) flatten ---");
456            eprintln!("  overlays_created:  {ov_created}");
457            eprintln!("  flatten_attempts:  {ov_attempt}");
458            eprintln!("  flatten_builds:    {ov_build}  (cache-miss = real O(n) merge)");
459            eprintln!("  cache_hit_rate:    {hit_rate:.1}%");
460            eprintln!("  entries_merged:    {ov_entries}  (sum of left+right over all builds)");
461            if ov_created > 0 {
462                let builds_per_overlay = ov_build as f64 / ov_created as f64;
463                eprintln!("  builds_per_overlay:{builds_per_overlay:.2}");
464            }
465            let flatten_ms = crate::trace::get_overlay_flatten_nanos() as f64 / 1_000_000.0;
466            let pct = if elapsed > 0.0 {
467                (flatten_ms / 1000.0 / elapsed) * 100.0
468            } else {
469                0.0
470            };
471            eprintln!("  flatten_walltime:  {flatten_ms:.1}ms  ({pct:.1}% of eval, incl. nested)");
472        }
473        let se_calls = c.get(Counter::SortedEntriesCalls);
474        let se_rows = c.get(Counter::SortedEntriesRows);
475        if se_calls > 0 {
476            let se_ms = crate::trace::get_sorted_entries_nanos() as f64 / 1_000_000.0;
477            let se_pct = if elapsed > 0.0 {
478                (se_ms / 1000.0 / elapsed) * 100.0
479            } else {
480                0.0
481            };
482            eprintln!("--- sorted_entries (attrNames/iter) ---");
483            eprintln!("  calls:             {se_calls}");
484            eprintln!("  rows_sorted:       {se_rows}");
485            eprintln!("  walltime:          {se_ms:.1}ms  ({se_pct:.1}% of eval)");
486        }
487        // List concatenation (`++` / concatLists / concatMap) — the O(n) copy
488        // storm. `elems_copied` is the raw work volume; `elems_reused` is what
489        // the in-place structural-share fix elides. A copied/reused ratio near
490        // 0 means most concats hit the shared fast path.
491        let lc_calls = c.get(Counter::ListConcatCalls);
492        let lc_copied = c.get(Counter::ListConcatElemsCopied);
493        let lc_reused = c.get(Counter::ListConcatElemsReused);
494        if lc_calls > 0 {
495            let total = lc_copied + lc_reused;
496            let reuse_pct = if total > 0 {
497                (lc_reused as f64 / total as f64) * 100.0
498            } else {
499                0.0
500            };
501            eprintln!("--- list concat (`++` / concatLists) ---");
502            eprintln!("  calls:             {lc_calls}");
503            eprintln!("  elems_copied:      {lc_copied}");
504            eprintln!("  elems_reused:      {lc_reused}  (in-place, Rc uniquely owned)");
505            eprintln!("  reuse_rate:        {reuse_pct:.1}%");
506        }
507        // Attrset structural `==` — the clones the borrow-compare fix elides.
508        let eq_calls = c.get(Counter::AttrsEqStructuralCalls);
509        let eq_elided = c.get(Counter::AttrsEqEntriesCloneElided);
510        if eq_calls > 0 {
511            eprintln!("--- attrs structural eq (`==` fallback) ---");
512            eprintln!("  structural_calls:  {eq_calls}");
513            eprintln!(
514                "  map_clones_elided: {}  ({eq_elided} entries not cloned — was 2 FxHashMap clones/call)",
515                eq_calls * 2
516            );
517        }
518        // M2 RISKY-tier waste measurement (C-with / C-slash / C-store).
519        // Each `im_rc` HAMT clone is O(1) structural sharing, so these counts
520        // are the NUMBER of O(1) clones, not an O(n) copy volume.
521        let wc = c.get(Counter::WithScopeCacheClone);
522        let sc = c.get(Counter::SlashDeferredTailClone);
523        let ts = c.get(Counter::ThunkStoreWrites);
524        if wc + sc + ts > 0 {
525            eprintln!("--- M2 RISKY-tier waste probes ---");
526            eprintln!("  with_scope_cache_clone:   {wc}  (C-with; O(1) HAMT clone each)");
527            eprintln!("  slash_deferred_tail_clone:{sc}  (C-slash; O(1) HAMT clone, then COW-merged)");
528            eprintln!("  thunk_store_writes:       {ts}  (C-store; repr+cache double-store per force)");
529            let tm = c.get(Counter::ThunkStoreLoopMutated);
530            eprintln!("  thunk_store_loop_mutated: {tm}  (C-store; Store#2 content ≠ Store#1 — collapse NOT content-neutral if >0)");
531            let tr = c.get(Counter::ThunkStoreRedundant);
532            eprintln!("  thunk_store_redundant:    {tr}  (C-store; Store#2 = pure redundant rewrite — provably skippable)");
533        }
534        // Storm A: `referenced_idents` residual self/mutual-recursion walk.
535        // The original O(N²) is already hoisted to O(N) per scope; these show
536        // the residual per-fixpoint-iteration subtree-walk cost that remains.
537        let sr_calls = c.get(Counter::SelfRecWalkCalls);
538        let sr_nodes = c.get(Counter::SelfRecWalkNodes);
539        if sr_calls > 0 {
540            let nodes_per_call = sr_nodes as f64 / sr_calls as f64;
541            let sr_ms = crate::trace::get_self_rec_walk_nanos() as f64 / 1_000_000.0;
542            let sr_pct = if elapsed > 0.0 {
543                (sr_ms / 1000.0 / elapsed) * 100.0
544            } else {
545                0.0
546            };
547            eprintln!("--- Storm A: referenced_idents (self/mutual-rec walk) ---");
548            eprintln!("  walk_calls:        {sr_calls}  (= binding RHS subtree walks)");
549            eprintln!("  nodes_walked:      {sr_nodes}  (total rnix descendants visited)");
550            eprintln!("  nodes_per_call:    {nodes_per_call:.1}");
551            eprintln!("  walltime:          {sr_ms:.1}ms  ({sr_pct:.1}% of eval)");
552        }
553        // Thunk-creation site attribution — WHERE the never-forced thunks are
554        // minted. `maybe_other` (the maybe_thunk `_` arm) + `apply_arg` (lambda
555        // call-by-need) are the two dominant, closable classes.
556        let s_maybe = c.get(Counter::ThunkSiteMaybeOther);
557        let s_apply = c.get(Counter::ThunkSiteApplyArg);
558        let s_ident = c.get(Counter::ThunkSiteMaybeIdent);
559        let s_recfwd = c.get(Counter::ThunkSiteLetForward);
560        let s_withid = c.get(Counter::ThunkSiteOther);
561        let s_tagged = s_maybe + s_apply + s_ident + s_recfwd + s_withid;
562        let created = crate::trace::get_thunks_created();
563        // Untagged remainder = inherit-source + select-source + nested-attr +
564        // native/evaluated/misc constructors not on the hot creation paths.
565        let s_rest = created.saturating_sub(s_tagged);
566        if s_tagged > 0 {
567            eprintln!("--- thunk-creation site attribution ---");
568            eprintln!("  maybe_thunk `_` arm:  {s_maybe}");
569            eprintln!("  apply lambda-arg:     {s_apply}");
570            eprintln!("  maybe_thunk ident fb: {s_ident}");
571            eprintln!("  recursive let/rec:    {s_recfwd}");
572            eprintln!("  with-ident deferred:  {s_withid}");
573            let s_inh = c.get(Counter::ThunkSiteInheritSrc);
574            let s_nat = c.get(Counter::ThunkSiteNative);
575            let s_ev = c.get(Counter::ThunkSiteEvaluated);
576            eprintln!("  inherit-select:       {s_inh}");
577            eprintln!("  native (flake input): {s_nat}");
578            eprintln!("  evaluated (pre-done): {s_ev}");
579            let s_rest2 = s_rest.saturating_sub(s_inh + s_nat + s_ev);
580            eprintln!("  rest (select-src/…):  {s_rest2}");
581            eprintln!("  thunks_created:       {created}");
582        }
583        crate::trace::report_maybe_other_kinds();
584        // Thunk stats from trace module.
585        crate::trace::report_thunk_stats();
586        eprintln!("===========================\n");
587    });
588}
589
590/// Get the display name for a counter.
591#[allow(dead_code)]
592pub fn counter_name(counter: Counter) -> &'static str {
593    COUNTER_NAMES[counter as usize]
594}
595
596// ──────────────────────────────────────────────────────────────────
597// Programmatic snapshot API — the foundation for perf-analysis tools.
598//
599// `report()` dumps to stderr; great for humans, useless for tools that
600// want structured data, want to sort, diff, or capture counter deltas
601// per-eval. `PerfSnapshot` gives you a plain struct you can move
602// around, serialize, subtract, and inspect.
603// ──────────────────────────────────────────────────────────────────
604
605/// An immutable snapshot of counter + timer state at a single point.
606///
607/// Cheap to clone (just a fixed-size array + a few u64). Subtract two
608/// snapshots (`b.delta_from(&a)`) to get the work done between them —
609/// the foundation of `with_scope` and per-program profiling.
610#[derive(Clone, Debug)]
611pub struct PerfSnapshot {
612    /// Wall-clock elapsed since [`start`] was called. `None` if `start`
613    /// wasn't called in this thread.
614    pub elapsed: Option<std::time::Duration>,
615    /// Raw counter values, indexed by `Counter as usize`.
616    pub counters: [u64; NUM_COUNTERS],
617    /// Thunks allocated in this thread to date (from `trace` module).
618    pub thunks_created: u64,
619    /// Thunks forced (from suspended → evaluated) to date.
620    pub thunks_forced: u64,
621}
622
623impl PerfSnapshot {
624    /// All-zero snapshot. Useful as the identity element for folds.
625    #[must_use]
626    pub fn zero() -> Self {
627        Self {
628            elapsed: None,
629            counters: [0; NUM_COUNTERS],
630            thunks_created: 0,
631            thunks_forced: 0,
632        }
633    }
634
635    /// Read a counter by enum variant.
636    #[must_use]
637    pub fn get(&self, counter: Counter) -> u64 {
638        self.counters[counter as usize]
639    }
640
641    /// `self - other`, treating both as counter totals. Used to get
642    /// the delta across a scoped evaluation (snapshot before, snapshot
643    /// after, subtract). Saturates to zero on underflow — shouldn't
644    /// happen in normal use but guards against races / manual resets.
645    #[must_use]
646    pub fn delta_from(&self, other: &PerfSnapshot) -> PerfSnapshot {
647        let mut counters = [0u64; NUM_COUNTERS];
648        for i in 0..NUM_COUNTERS {
649            counters[i] = self.counters[i].saturating_sub(other.counters[i]);
650        }
651        let elapsed = match (self.elapsed, other.elapsed) {
652            (Some(a), Some(b)) => Some(a.saturating_sub(b)),
653            _ => self.elapsed,
654        };
655        PerfSnapshot {
656            elapsed,
657            counters,
658            thunks_created: self.thunks_created.saturating_sub(other.thunks_created),
659            thunks_forced: self.thunks_forced.saturating_sub(other.thunks_forced),
660        }
661    }
662
663    /// Thunk memoization hit rate — 1.0 means every suspended thunk
664    /// produced useful work; 0.0 means everything we built was wasted.
665    /// Returns `None` when no thunks were created in this window.
666    #[must_use]
667    pub fn thunk_hit_rate(&self) -> Option<f64> {
668        let created = self.thunks_created;
669        if created == 0 {
670            return None;
671        }
672        #[allow(clippy::cast_precision_loss)]
673        let r = self.thunks_forced as f64 / created as f64;
674        Some(r)
675    }
676
677    /// `(top_variant, count)` — the expression kind with the highest
678    /// count in this snapshot. For ranking "what is this eval mostly
679    /// doing?" at a glance.
680    #[must_use]
681    pub fn dominant_expr_kind(&self) -> Option<(Counter, u64)> {
682        let kinds = [
683            Counter::ExprIdent,
684            Counter::ExprLiteral,
685            Counter::ExprStr,
686            Counter::ExprList,
687            Counter::ExprAttrs,
688            Counter::ExprSelect,
689            Counter::ExprApply,
690            Counter::ExprLetIn,
691            Counter::ExprIfElse,
692            Counter::ExprWith,
693            Counter::ExprLambda,
694            Counter::ExprBinOp,
695            Counter::ExprHasAttr,
696            Counter::ExprUnaryOp,
697            Counter::ExprAssert,
698            Counter::ExprPath,
699            Counter::ExprOther,
700        ];
701        kinds
702            .iter()
703            .map(|&k| (k, self.get(k)))
704            .filter(|&(_, n)| n > 0)
705            .max_by_key(|&(_, n)| n)
706    }
707}
708
709/// Capture the current counter state as a [`PerfSnapshot`].
710///
711/// Does NOT reset anything — the next `snapshot()` / `inc()` / `add()`
712/// call sees the same state. Use [`reset`] if you want a fresh window.
713#[must_use]
714pub fn snapshot() -> PerfSnapshot {
715    let mut out = [0u64; NUM_COUNTERS];
716    COUNTERS.with(|c| {
717        let c = c.borrow();
718        out.copy_from_slice(&c.counts);
719    });
720    let elapsed = START.with(|s| s.borrow().map(|s| s.elapsed()));
721    PerfSnapshot {
722        elapsed,
723        counters: out,
724        thunks_created: crate::trace::get_thunks_created(),
725        thunks_forced: crate::trace::get_thunks_forced(),
726    }
727}
728
729/// Zero every counter and restart the timer. The thread-local thunk
730/// trace counters are reset too.
731pub fn reset() {
732    COUNTERS.with(|c| {
733        let mut c = c.borrow_mut();
734        *c = PerfCounters::default();
735    });
736    START.with(|s| *s.borrow_mut() = Some(Instant::now()));
737    crate::trace::reset_thunk_stats();
738}
739
740/// Scoped profiling: enable counters if they aren't already, reset
741/// them, run `f`, and return `(result, delta_snapshot)`.
742///
743/// The counters are left enabled after this returns — callers that
744/// want strict zero-overhead production eval should `set_enabled(false)`
745/// afterwards.
746pub fn with_scope<F, R>(f: F) -> (R, PerfSnapshot)
747where
748    F: FnOnce() -> R,
749{
750    let prev_enabled = enabled();
751    set_enabled(true);
752    reset();
753    let before = snapshot();
754    let result = f();
755    let after = snapshot();
756    let delta = after.delta_from(&before);
757    set_enabled(prev_enabled);
758    (result, delta)
759}
760
761#[cfg(test)]
762mod tests {
763    use super::*;
764
765    #[test]
766    fn counter_enum_has_30_variants() {
767        // Each variant maps to a fixed index; NUM_COUNTERS is the array size.
768        // Extended by the M2 RISKY-tier waste probes (41..=45): C-with /
769        // C-slash / C-store measurement + the C-store redundant-store skip;
770        // then the M2 thunk-waste creation-site attribution (48..=55).
771        assert_eq!(NUM_COUNTERS, 56);
772        assert_eq!(COUNTER_NAMES.len(), NUM_COUNTERS);
773        assert_eq!(Counter::OverlayFlattenAttempt as usize, 30);
774        assert_eq!(Counter::OverlayCreated as usize, 33);
775        assert_eq!(Counter::SortedEntriesCalls as usize, 34);
776        assert_eq!(Counter::SortedEntriesRows as usize, 35);
777        assert_eq!(Counter::ListConcatCalls as usize, 36);
778        assert_eq!(Counter::ListConcatElemsCopied as usize, 37);
779        assert_eq!(Counter::ListConcatElemsReused as usize, 38);
780        assert_eq!(Counter::AttrsEqStructuralCalls as usize, 39);
781        assert_eq!(Counter::AttrsEqEntriesCloneElided as usize, 40);
782        assert_eq!(Counter::WithScopeCacheClone as usize, 41);
783        assert_eq!(Counter::SlashDeferredTailClone as usize, 42);
784        assert_eq!(Counter::ThunkStoreWrites as usize, 43);
785        assert_eq!(Counter::ThunkStoreLoopMutated as usize, 44);
786        assert_eq!(Counter::ThunkStoreRedundant as usize, 45);
787        assert_eq!(Counter::SelfRecWalkCalls as usize, 46);
788        assert_eq!(Counter::SelfRecWalkNodes as usize, 47);
789        assert_eq!(Counter::ThunkSiteMaybeOther as usize, 48);
790        assert_eq!(Counter::ThunkSiteApplyArg as usize, 49);
791        assert_eq!(Counter::ThunkSiteMaybeIdent as usize, 50);
792        assert_eq!(Counter::ThunkSiteLetForward as usize, 51);
793        assert_eq!(Counter::ThunkSiteOther as usize, 52);
794        assert_eq!(Counter::ThunkSiteInheritSrc as usize, 53);
795        assert_eq!(Counter::ThunkSiteNative as usize, 54);
796        assert_eq!(Counter::ThunkSiteEvaluated as usize, 55);
797        assert_eq!(Counter::EvalExpr as usize, 0);
798        assert_eq!(Counter::ForceValue as usize, 1);
799        assert_eq!(Counter::ThunkForce as usize, 2);
800        assert_eq!(Counter::ThunkHit as usize, 3);
801        assert_eq!(Counter::Import as usize, 4);
802        assert_eq!(Counter::ImportHit as usize, 5);
803        assert_eq!(Counter::Apply as usize, 6);
804        assert_eq!(Counter::Select as usize, 7);
805        assert_eq!(Counter::Attrset as usize, 8);
806        assert_eq!(Counter::EnvClone as usize, 9);
807        assert_eq!(Counter::EnvLookup as usize, 10);
808        assert_eq!(Counter::EnvLookupDepth as usize, 11);
809        assert_eq!(Counter::DeadBindingsSkipped as usize, 24);
810        assert_eq!(Counter::ExprBinOp as usize, 25);
811        assert_eq!(Counter::ExprPath as usize, 29);
812    }
813
814    #[test]
815    fn inc_does_not_panic_when_disabled() {
816        // Ensure ENABLED is false (default for tests).
817        ENABLED.store(false, Ordering::Relaxed);
818        // Should be a no-op, not panic.
819        inc(Counter::EvalExpr);
820        inc(Counter::ForceValue);
821        inc(Counter::ThunkForce);
822    }
823
824    #[test]
825    fn counter_variant_maps_to_correct_index() {
826        assert_eq!(counter_name(Counter::EvalExpr), "eval_expr");
827        assert_eq!(counter_name(Counter::ForceValue), "force_value");
828        assert_eq!(counter_name(Counter::ThunkForce), "thunk_forces");
829        assert_eq!(counter_name(Counter::ThunkHit), "thunk_hits");
830        assert_eq!(counter_name(Counter::Import), "imports");
831        assert_eq!(counter_name(Counter::ImportHit), "import_hits");
832        assert_eq!(counter_name(Counter::Apply), "apply");
833        assert_eq!(counter_name(Counter::Select), "select");
834        assert_eq!(counter_name(Counter::Attrset), "attrsets");
835        assert_eq!(counter_name(Counter::EnvClone), "env_clones");
836        assert_eq!(counter_name(Counter::EnvLookup), "env_lookups");
837        assert_eq!(counter_name(Counter::EnvLookupDepth), "env_lookup_depth");
838    }
839
840    #[test]
841    fn add_increments_by_given_amount() {
842        let mut counters = PerfCounters::default();
843        assert_eq!(counters.get(Counter::EvalExpr), 0);
844        counters.add(Counter::EvalExpr, 5);
845        assert_eq!(counters.get(Counter::EvalExpr), 5);
846        counters.add(Counter::EvalExpr, 3);
847        assert_eq!(counters.get(Counter::EvalExpr), 8);
848    }
849}