retex_engine/
macroprof.rs

1//! A macro profiler for performance work: with `RETEX_MACRO_PROFILE=<file>`
2//! in the environment, every macro call is counted per control sequence,
3//! and every 64th call samples the macros being expanded on the input
4//! stack (inclusive counts). The report, written at the end of the run,
5//! groups both by package prefix (`\pgfmath…`, `\__fp_…`, `\@…`) to show
6//! which TeX-coded libraries the time goes to; `<file>.tsv` lists every
7//! macro (calls, inclusive samples, name).
8//!
9//! Inclusive counts are a lower bound: a macro whose last token calls
10//! another macro leaves the input stack before the callee runs (TeX's
11//! `back_list` tail-call behaviour), so callers through tail calls are not
12//! seen.
13
14use std::collections::HashMap;
15use std::fmt::Write as _;
16
17use crate::Engine;
18use crate::hash::CsId;
19use crate::input::Level;
20
21/// Counts of the profiler.
22#[derive(Default)]
23pub struct MacroProfile {
24    /// Where to write the report.
25    path: String,
26    /// Calls per macro.
27    calls: HashMap<CsId, u64>,
28    /// Samples in which the macro was on the input stack.
29    inclusive: HashMap<CsId, u64>,
30    /// All calls.
31    total: u64,
32    /// Samples taken.
33    samples: u64,
34}
35
36/// Calls between two input-stack samples.
37const SAMPLE_EVERY: u64 = 64;
38
39impl MacroProfile {
40    /// The profiler, if `RETEX_MACRO_PROFILE` is set.
41    pub fn from_env() -> Option<Box<MacroProfile>> {
42        let path = std::env::var("RETEX_MACRO_PROFILE").ok()?;
43        Some(Box::new(MacroProfile {
44            path,
45            ..MacroProfile::default()
46        }))
47    }
48}
49
50/// The package a control sequence name belongs to, from its prefix.
51fn package_of(name: &str) -> String {
52    let n = name.trim_start_matches('_');
53    // expl3: module before the first `_` (`fp_add:Nn`, `__fp_parse…`).
54    if name.contains(':') || name.starts_with("__") {
55        let module = n.split(['_', ':']).next().unwrap_or(n);
56        return format!("expl3 {module}");
57    }
58    for p in [
59        "pgfmath",
60        "pgfplots",
61        "pgfkeys",
62        "pgfsys",
63        "pgfutil",
64        "pgfpoint",
65        "pgfpath",
66        "pgf@",
67        "pgf",
68        "tikz@",
69        "tikz",
70        "tcb@",
71        "tcb",
72        "sisetup",
73        "si@",
74        "SI",
75        "num",
76        "bbl@",
77        "beamer@",
78        "beamer",
79        "Hy@",
80        "HyPsd@",
81        "hyper",
82        "Gin@",
83        "Gread@",
84        "@float",
85        "@makecaption",
86        "@ifnextchar",
87        "@ifstar",
88        "@xifnextchar",
89        "@tempa",
90        "@for",
91        "@tfor",
92        "@tempb",
93        "@protected@",
94        "@expl@",
95        "fontspec",
96        "f@",
97    ] {
98        if n.starts_with(p) {
99            return p.trim_end_matches('@').to_owned();
100        }
101    }
102    if n.contains('@') {
103        return "LaTeX internals (@)".to_owned();
104    }
105    "(other)".to_owned()
106}
107
108impl Engine {
109    /// Records a call of `cs` (called from `macro_call`).
110    #[cold]
111    pub(crate) fn profile_macro_call(&mut self, cs: CsId) {
112        let Some(p) = self.macro_profile.as_mut() else {
113            return;
114        };
115        *p.calls.entry(cs).or_default() += 1;
116        p.total += 1;
117        if p.total % SAMPLE_EVERY != 0 {
118            return;
119        }
120        p.samples += 1;
121        let mut seen: Vec<CsId> = vec![cs];
122        for level in &self.input.stack {
123            if let Level::Tokens(t) = level
124                && t.name != crate::hash::NO_CS
125                && !seen.contains(&t.name)
126            {
127                seen.push(t.name);
128            }
129        }
130        for c in seen {
131            *p.inclusive.entry(c).or_default() += 1;
132        }
133    }
134
135    /// Writes the profile report, if profiling.
136    pub fn write_macro_profile(&mut self) {
137        let Some(p) = self.macro_profile.take() else {
138            return;
139        };
140        let name = |e: &Engine, c: CsId| String::from_utf8_lossy(e.hash.name(c)).into_owned();
141        let mut out = String::new();
142        let _ = writeln!(
143            out,
144            "macro calls: {}, input-stack samples: {} (every {SAMPLE_EVERY} calls)\n",
145            p.total, p.samples
146        );
147        let mut by_pkg: HashMap<String, (u64, u64)> = HashMap::new();
148        for (&c, &n) in &p.calls {
149            by_pkg.entry(package_of(&name(self, c))).or_default().0 += n;
150        }
151        // Inclusive per package: a sample counts once per package.
152        // Approximated from per-macro inclusive counts, capped by samples.
153        for (&c, &n) in &p.inclusive {
154            let e = by_pkg.entry(package_of(&name(self, c))).or_default();
155            e.1 = e.1.max(n);
156        }
157        let mut pk: Vec<_> = by_pkg.into_iter().collect();
158        pk.sort_by(|a, b| b.1.0.cmp(&a.1.0));
159        let _ = writeln!(
160            out,
161            "{:>7} {:>7}  package (calls %, max inclusive %)",
162            "calls", "incl"
163        );
164        for (k, (c, i)) in pk.iter().take(40) {
165            let _ = writeln!(
166                out,
167                "{:>6.2}% {:>6.2}%  {k}",
168                *c as f64 * 100.0 / p.total.max(1) as f64,
169                *i as f64 * 100.0 / p.samples.max(1) as f64
170            );
171        }
172        let mut calls: Vec<_> = p.calls.iter().map(|(&c, &n)| (n, c)).collect();
173        calls.sort_by(|a, b| b.0.cmp(&a.0));
174        let _ = writeln!(out, "\ntop macros by calls:");
175        for (n, c) in calls.iter().take(60) {
176            let _ = writeln!(
177                out,
178                "{:>6.2}% {:>10}  \\{}",
179                *n as f64 * 100.0 / p.total.max(1) as f64,
180                n,
181                name(self, *c)
182            );
183        }
184        let mut incl: Vec<_> = p.inclusive.iter().map(|(&c, &n)| (n, c)).collect();
185        incl.sort_by(|a, b| b.0.cmp(&a.0));
186        let _ = writeln!(out, "\ntop macros by inclusive samples:");
187        for (n, c) in incl.iter().take(60) {
188            let _ = writeln!(
189                out,
190                "{:>6.2}%  \\{}",
191                *n as f64 * 100.0 / p.samples.max(1) as f64,
192                name(self, *c)
193            );
194        }
195        let _ = std::fs::write(&p.path, out);
196        // Every macro, for further analysis: calls, inclusive samples, name.
197        let mut tsv = String::from("calls\tinclusive\tname\n");
198        for (n, c) in &calls {
199            let incl = p.inclusive.get(c).copied().unwrap_or(0);
200            let _ = writeln!(tsv, "{n}\t{incl}\t\\{}", name(self, *c));
201        }
202        let _ = std::fs::write(format!("{}.tsv", p.path), tsv);
203    }
204}
retex_engine/macroprof.rs

retex_engine/
macroprof.rs
