crates/nornir-docbook/examples/bench.rs
//! **What a render costs, stage by stage, and where the parallelism is.**
//!
//! ```text
//! cargo run --release --example bench # stages + allocations
//! cargo run --release --example bench -- parallel # the threading A/B
//! RAYON_NUM_THREADS=1 cargo run --release --example bench -- parallel
//! cargo run --release --example mem # WHERE the memory goes
//! ```
//!
//! This example answers what a render COSTS. `examples/mem.rs` answers the one
//! question its peak-RSS column could only raise — whether the memory is typst
//! or this crate — and the two share `examples/common/mod.rs` so they are
//! asking it of the same documents.
//!
//! An example and not a `benches/` target, and not criterion: the house rule
//! (`gunnar-bitmap/Cargo.toml`) is that a measurement must not pull a benchmark
//! harness into the crate's graph, and timings are persisted to nornir's
//! `bench_runs` rather than to a framework's own store.
//!
//! # The corpus is generated, not read
//!
//! Four documents at 3 KB, 30 KB, 300 KB and 3 MB, built here from a fixed
//! seedless pattern — headings at three levels, bullet and numbered lists, GFM
//! tables, fenced code with a language, links, and twenty relative images
//! offered through an [`ImageSet`]. No file on disk, so the numbers are the same
//! on a laptop and in CI, and the ratio between the four is a property of the
//! renderer rather than of whichever README happened to be lying around.
//!
//! # ── MEASURED 2026-09-09, this laptop (16 threads, rustc 1.96, --release) ──
//!
//! ```text
//! input runs md->typ ms html e2e ms svg e2e ms html out svg out peak RSS
//! 3 KB 20 0.07/0.18 3.6/27.6 21.6/24.1 9 KB 372 KB 37 MB
//! 29 KB 20 0.22/0.30 21.6/22.3 126.8/146.4 82 KB 2921 KB 70 MB
//! 293 KB 20 2.28/2.79 252.1/266.4 1411.6/1518.9 788 KB 28636 KB 388 MB
//! 2929 KB 5 30.25/33.56 2596.6/2641.3 16183.5/17133.3 7739 KB 286369 KB 3359 MB
//! ```
//!
//! # ── RE-MEASURED 2026-09-12, oden (32 threads, --release): 0.1.4 -> 0.1.5 ──
//!
//! The same corpus and the same binary shape, the two runs back to back on the
//! same machine. **Every `out` column is identical to the byte across the
//! pair** — 0.1.5 moves memory, not output, and `svgz::tests` and
//! `export::tests` hold that as an assertion against 0.1.4's own spelling of
//! each function rather than as a hope.
//!
//! ```text
//! ──────── 0.1.4 ──────── ──────── 0.1.5 ────────
//! input svg e2e ms peak RSS svg e2e ms peak RSS peak RSS
//! 3 KB 34.1/37.1 38 MB 28.0/30.1 38 MB 0%
//! 29 KB 229.0/236.7 70 MB 218.5/228.1 63 MB -10%
//! 293 KB 2392.4/2421.6 389 MB 2299.3/2346.7 310 MB -20%
//! 2929 KB 24716.4/24741.4 3361 MB 23132.6/23710.9 2850 MB -15%
//! ```
//!
//! **oden is a SHARED box and other lanes were compiling throughout**: load
//! average 5.70 when the 0.1.4 run started, 2.23 when it ended and the 0.1.5
//! run began, 2.17 at the end. The 0.1.4 timings are therefore the pessimistic
//! half of the pair and **no timing in that table is a comparison** — it is
//! recorded so the row is complete, not so it can be quoted. Peak RSS is not
//! sensitive to a busy box; that column is the measurement.
//!
//! **The `svg` column is now the 0.1.2 default grade** — `TextLayer::On`, with
//! the selectable text layer — which is why `svg out` is about a quarter above
//! the same table's 0.1.1 line (317/2383/23313/234101 KB). `text_layer_cost()`
//! separates the two grades; the layer costs +4% of the time and +23% of the
//! bytes, and neither moves the conclusions below.
//!
//! p50/p99. Four things this said, and only one of them was the expected one:
//!
//! * **The translation is not the cost.** `md_to_typst` runs at a steady
//! **86 MB/s** and produces 1.31x its input in typst markup at every size.
//! On a 3 KB README it is 0.05 ms against a 3.3 ms render — **1.5%** — and on
//! the 3 MB document it is 30 ms against 2.6 s, **1.2%**. Preallocating its
//! `String` or borrowing from pulldown-cmark's `CowStr` would be measurable
//! and would move nothing a caller can feel, so neither was done: the rule is
//! that a change is justified by a number, and the number here says no.
//! * **There is a large fixed cost per render**, and it is not the content:
//! a one-word document took **16.30 ms**. `TypstEngine::build()` runs
//! typst-kit's font search on every call, and `export::embedded_fonts` now
//! runs it once for the process — 16.30 -> **14.60 ms**, -10%, reproducible
//! across three runs. Most of what is left is
//! `typst::Library::builder().build()`, which is inside typst-as-lib and out
//! of reach without a fork.
//! * **The typeset grade costs about 6x the HTML grade** in time and 35x in
//! bytes, at every size. That used to be the whole reason a consumer showing a
//! README defaulted to HTML: the picture was expensive AND unreadable, so it
//! could only be a toggle. 0.1.2 answers the second half — the typeset page
//! now carries its own text — so the trade is a cached render and a bigger
//! response against a page that is set properly and still selectable. gunnar-ui
//! made it the default on that basis; the cost is unchanged and is here.
//! * **Memory is the real ceiling on a big document**: 3.2 GB of peak RSS for
//! 3 MB of markdown, roughly a thousand times the input. — *and that is as
//! far as one number could take it. See the split below.*
//!
//! ## Where the 3.2 GB actually was (2026-09-12)
//!
//! One number could not be acted on, because it did not say whether the memory
//! was typst laying the document out or this crate copying the result
//! afterwards. `examples/mem.rs` splits it: [`gunnar_stage`]'s per-stage
//! attributor, a counting `#[global_allocator]`, and a rebuild of the pipeline
//! that is **proved byte-identical to the shipped one before any number is
//! taken** — 2 469 320 B of page compared, because "a plausible number measured
//! off the real path" is the way this measurement would have failed.
//!
//! One render of the 3 MB document, oden, `--release`:
//!
//! ```text
//! stage churn MB peak+ MB kept MB whose
//! md_to_typst 78.5 41.6 5.7 OURS
//! engine 4.1 0.0 0.9 typst
//! compile 10431.5 2249.6 1449.1 typst
//! typst_svg 2986.3 0.0 512.2 typst
//! optimize_svg 331.2 0.0 313.5 OURS
//! ```
//!
//! `peak+` is how much a stage raised the high-water mark of LIVE bytes, so the
//! column sums to the peak instead of every stage claiming it. **typst's
//! compile owns 2249.6 of 2397.9 MB — 93.8%** — and still holds 1449 MB of
//! laid-out frames when it returns. Everything this crate did afterwards
//! happened *on top of* those frames and *beside* the page in copies of it:
//! `typst_svg` hands over a 512 MB buffer, the optimizer answered with a second
//! 313 MB string, and the text layer built a third.
//!
//! 0.1.5 drops the document the moment the page is serialised and the runs are
//! collected, and does the rest in the page's own buffer. ONE render, fresh
//! process (`cargo run --release --example mem -- one`), interleaved 0.1.4 /
//! 0.1.5 runs:
//!
//! ```text
//! input VmHWM 0.1.4 0.1.5 peak live 0.1.4 0.1.5
//! 3 KB 70 MB 70 MB 0% 11.9 MB 10.9 MB -8%
//! 29 KB 70 MB 70 MB 0% 37.1 MB 32.6 MB -12%
//! 293 KB 357 MB 305 MB -15% 291.9 MB 252.5 MB -13%
//! 2929 KB 3195 MB 2685 MB -16% 2915.6 MB 2331.5 MB -20%
//! ```
//!
//! **What is left is typst's.** 2331 MB of peak live against compile's own
//! 2249 MB is 3.5% of headroom: this crate no longer raises the high-water mark
//! at all on a big document. Moving the rest means changing how `typst-layout`
//! arenas a document or how `typst-svg` serialises one into a `String` it grows
//! by doubling — a fork or an upstream change, and not a call this crate makes.
//!
//! Two facts worth carrying that are nobody's bug:
//!
//! * **RSS is a high-water mark, not a level.** At 3 MB the process holds
//! 2331 MB of live bytes at the peak and reports 2685 MB of `VmHWM`; the
//! 354 MB between them is the allocator keeping freed pages. See
//! `nordisk-alloc`, which is about exactly that and is a *binary's* choice,
//! never a library's.
//! * **719 MB is still live after the render returns and the output is
//! dropped**, at 3 MB in — and it does NOT grow: a second and a third render
//! of different documents leave the same floor, and `comemo::evict(0)` frees
//! 0.1 MB of it, so it is a per-process floor and not a leak. Unchanged by
//! 0.1.5, because none of it is this crate's.
//!
//! ## The threading A/B (`-- parallel`)
//!
//! ```text
//! typst layout threads: default typst layout threads: 1 (pinned)
//! shape serial gatling cpu-s serial gatling cpu-s speedup
//! 1 x 3 MB 14870ms 15359ms 14.9/15.3 14706ms 15461ms 14.7/15.5 0.95x
//! 8 x 300 KB 13567ms 3280ms 13.6/21.4 13482ms 3276ms 13.5/21.5 4.12x
//! 32 x 30 KB 6680ms 1352ms 6.7/9.0 6632ms 1328ms 6.6/8.6 4.99x
//! ```
//!
//! **Pinning typst's rayon to one thread changes nothing** — every pair above
//! is within noise of the other, and `cpu-s` ~= wall time on the serial arm,
//! which says typst 0.14 was laying this shape out on about one core anyway.
//! So the choice the ruling anticipated does not arise: there is no single-large-
//! document cost to weigh, because there was no internal parallelism to give up.
//!
//! The win is entirely **across documents**, and it is gatling's — ROOT-LAW #0,
//! never rayon: 4.12x on the book/README-farm shape at 1.6x the CPU seconds.
//! Where that shape exists in this crate — `export_svg_pages_per_chapter` — it
//! cannot be taken, because a chapter's page offset is the page count of its
//! predecessors; that function's docs carry the number and the reason.
mod common;
use std::time::Instant;
use common::{document, images, meta, ms, peak_rss_kb, stats};
use nornir_docbook::export::md_to_typst;
use nornir_docbook::{export_html, export_svg_column, ImageSet, TextLayer};
fn main() {
let mode = std::env::args().nth(1).unwrap_or_default();
if mode == "parallel" {
parallel();
} else {
stages();
}
}
// ───────────────────────────────────────────────────────────────────────────
// Report 1 — where the time goes, per stage
// ───────────────────────────────────────────────────────────────────────────
fn stages() {
let sizes = [3_000usize, 30_000, 300_000, 3_000_000];
// 3 MB compiles in seconds, so the big one gets fewer runs than the cap
// asks for and the row says so rather than quietly reporting a p99 over 3.
let runs = |bytes: usize| if bytes >= 1_000_000 { 5 } else { 20 };
println!(
"{:>9} {:>4} {:>9} {:>9} {:>10} {:>10} {:>10} {:>10}",
"input", "runs", "md->typ", "html e2e", "svg e2e", "html out", "svg out", "peak RSS"
);
println!("{}", "-".repeat(88));
let images = images();
let meta = meta();
for bytes in sizes {
let md = document(bytes);
let n = runs(bytes);
// md_to_typst alone.
let mut translate = Vec::new();
let mut typ_len = 0;
for _ in 0..n {
let t = Instant::now();
let typ = md_to_typst(&md);
translate.push(t.elapsed());
typ_len = typ.len();
}
// The HTML grade end to end: engine build + compile + serialise. The
// three cannot be split from outside the crate's own boundary without
// making the split itself the measurement — `export_html` is what a
// caller actually pays.
let mut html = Vec::new();
let mut html_len = 0;
for i in 0..n {
let src = format!("{md}\n\nrun {i}\n");
let t = Instant::now();
let out = export_html(&src, &meta, &images).expect("html");
html.push(t.elapsed());
html_len = out.len();
}
// The typeset grade end to end: engine build + compile + typst_svg +
// the lossless pass.
let mut svg = Vec::new();
let mut svg_len = 0;
for i in 0..n {
let src = format!("{md}\n\nrun {i}\n");
let t = Instant::now();
let out = export_svg_column(&src, &meta, &images, 720.0, TextLayer::On).expect("svg");
svg.push(t.elapsed());
svg_len = out.len();
}
let (t50, t99) = stats(translate);
let (h50, h99) = stats(html);
let (s50, s99) = stats(svg);
println!(
"{:>7} KB {:>4} {:>9} {:>9} {:>10} {:>10} {:>10} {:>7} MB",
md.len() / 1024,
n,
format!("{:.2}/{:.2}", ms(t50), ms(t99)),
format!("{:.1}/{:.1}", ms(h50), ms(h99)),
format!("{:.1}/{:.1}", ms(s50), ms(s99)),
format!("{} KB", html_len / 1024),
format!("{} KB", svg_len / 1024),
peak_rss_kb() / 1024,
);
let _ = typ_len;
}
println!("\np50/p99 in ms. `md->typ` is the translation alone; the two `e2e`");
println!("columns are what a caller pays, engine construction included.\n");
translation_detail();
text_layer_cost();
fixed_cost();
}
/// **What the selectable text layer costs**, in bytes and in milliseconds.
///
/// The layer is a second walk of the page's frames and one `<text>` element per
/// shaped run — no typesetting, no glyph outlining, no second compile. The
/// question this answers is whether that is cheap enough to be the DEFAULT
/// grade, which is what a console showing a README wants it to be.
fn text_layer_cost() {
let sizes = [3_000usize, 30_000, 300_000];
let images = images();
let meta = meta();
println!(
"{:>9} {:>4} {:>12} {:>12} {:>8} {:>10} {:>10} {:>8}",
"input", "runs", "off ms", "on ms", "time", "off out", "on out", "bytes"
);
println!("{}", "-".repeat(86));
for bytes in sizes {
let md = document(bytes);
let n = if bytes >= 100_000 { 10 } else { 20 };
let mut off = Vec::new();
let mut on = Vec::new();
let (mut off_len, mut on_len) = (0usize, 0usize);
for i in 0..n {
let src = format!("{md}\n\nrun {i}\n");
let t = Instant::now();
let a = export_svg_column(&src, &meta, &images, 720.0, TextLayer::Off).expect("off");
off.push(t.elapsed());
off_len = a.len();
let t = Instant::now();
let b = export_svg_column(&src, &meta, &images, 720.0, TextLayer::On).expect("on");
on.push(t.elapsed());
on_len = b.len();
}
let (o50, _) = stats(off);
let (n50, _) = stats(on);
println!(
"{:>7} KB {:>4} {:>12} {:>12} {:>8} {:>10} {:>10} {:>8}",
md.len() / 1024,
n,
format!("{:.1}", ms(o50)),
format!("{:.1}", ms(n50)),
format!("+{:.1}%", (ms(n50) / ms(o50) - 1.0) * 100.0),
format!("{} KB", off_len / 1024),
format!("{} KB", on_len / 1024),
format!("+{:.1}%", (on_len as f64 / off_len as f64 - 1.0) * 100.0),
);
}
println!();
}
/// **What a render costs before it has rendered anything.**
///
/// An empty document still builds a `TypstEngine`, and `build()` runs
/// typst-kit's font search and `typst::Library::builder().build()` every time.
/// This is that floor, and it is the number that decides whether hoisting the
/// fonts is worth doing: on a forge answering README requests, every one of
/// them pays it.
fn fixed_cost() {
let meta = meta();
let empty = ImageSet::new();
let mut html = Vec::new();
let mut svg = Vec::new();
for i in 0..40 {
let src = format!("x{i}\n");
let t = Instant::now();
export_html(&src, &meta, &empty).expect("html");
html.push(t.elapsed());
let t = Instant::now();
export_svg_column(&src, &meta, &empty, 720.0, TextLayer::On).expect("svg");
svg.push(t.elapsed());
}
let (h50, h99) = stats(html);
let (s50, s99) = stats(svg);
println!("fixed cost of a render (a one-word document), 40 runs:");
println!(" html p50 {:.2} ms p99 {:.2} ms", ms(h50), ms(h99));
println!(" svg p50 {:.2} ms p99 {:.2} ms", ms(s50), ms(s99));
println!();
}
/// The translation on its own, against the input size — the one stage that is
/// entirely this crate's code and therefore the one a change here can move.
fn translation_detail() {
println!(
"{:>9} {:>10} {:>12} {:>14}",
"input", "md->typ", "typst bytes", "ratio"
);
println!("{}", "-".repeat(52));
for bytes in [3_000usize, 30_000, 300_000, 3_000_000] {
let md = document(bytes);
let mut runs = Vec::new();
let mut typ = String::new();
for _ in 0..20 {
let t = Instant::now();
typ = md_to_typst(&md);
runs.push(t.elapsed());
}
let (p50, _) = stats(runs);
println!(
"{:>7} KB {:>9.2}ms {:>10} KB {:>13.2}x ({:.0} MB/s)",
md.len() / 1024,
ms(p50),
typ.len() / 1024,
typ.len() as f64 / md.len() as f64,
(md.len() as f64 / 1_048_576.0) / p50.as_secs_f64(),
);
}
println!();
}
// ───────────────────────────────────────────────────────────────────────────
// Report 2 — the threading A/B
// ───────────────────────────────────────────────────────────────────────────
/// **typst's layout is internally parallel (rayon, inside `typst-layout`); the
/// constellation's own parallelism is gatling's, across documents.**
///
/// ROOT-LAW #0 forbids rayon in any code of ours, so the question is not "which
/// library" but which SHAPE wins:
///
/// * **TypstInternal** — one document at a time, typst's own threads.
/// * **AcrossDocuments** — typst pinned to one thread, N documents at once
/// through `gatling::gatling_forkjoin::gatling_map_balanced`.
///
/// The pin is `RAYON_NUM_THREADS=1` in the environment rather than a
/// `rayon::ThreadPool` here, because a `ThreadPool` would mean this crate
/// linking rayon to forbid rayon.
///
/// Three shapes, because they answer different questions: ONE 3 MB document is
/// where typst's internal parallelism is all there is; 8 x 300 KB is the book
/// and README-farm shape and is what the default is chosen on; 32 x 30 KB is a
/// forge front page.
fn parallel() {
let pinned = std::env::var("RAYON_NUM_THREADS").as_deref() == Ok("1");
println!(
"typst layout threads: {}\n",
if pinned {
"1 (pinned)"
} else {
"default (all cores)"
}
);
println!(
"{:>18} {:>12} {:>12} {:>10} {:>9}",
"shape", "serial wall", "gatling wall", "cpu-s", "speedup"
);
println!("{}", "-".repeat(70));
let images = images();
let meta = meta();
for (label, count, bytes) in [
("1 x 3 MB", 1usize, 3_000_000usize),
("8 x 300 KB", 8, 300_000),
("32 x 30 KB", 32, 30_000),
] {
// Distinct documents, or typst's memo would answer every one of them
// after the first and the whole comparison would be of a cache.
let docs: Vec<String> = (0..count)
.map(|i| format!("{}\n\ndocument {i}\n", document(bytes)))
.collect();
let before = cpu_seconds();
let t = Instant::now();
for doc in &docs {
export_svg_column(doc, &meta, &images, 720.0, TextLayer::On).expect("svg");
}
let serial = t.elapsed();
let serial_cpu = cpu_seconds() - before;
let before = cpu_seconds();
let t = Instant::now();
let meta_ref = &meta;
let images_ref = &images;
gatling::gatling_forkjoin::gatling_map_balanced(
docs.as_slice(),
0,
1,
|_| 1,
|_, doc: &String| {
export_svg_column(doc, meta_ref, images_ref, 720.0, TextLayer::On)
.expect("svg")
.len()
},
);
let across = t.elapsed();
let across_cpu = cpu_seconds() - before;
println!(
"{:>18} {:>10.0}ms {:>10.0}ms {:>9} {:>8.2}x",
label,
ms(serial),
ms(across),
format!("{serial_cpu:.1}/{across_cpu:.1}"),
serial.as_secs_f64() / across.as_secs_f64().max(f64::EPSILON),
);
}
println!("\n`cpu-s` is serial/gatling total CPU seconds — the honest cost of a");
println!("speedup. Peak RSS {} MB.", peak_rss_kb() / 1024);
}
/// Total CPU seconds this process has used, user + system, from
/// `/proc/self/stat`.
///
/// Wall time alone cannot tell "it got faster" from "it used eight cores to get
/// twice as fast", and on a shared appliance the second one is a cost.
fn cpu_seconds() -> f64 {
let ticks = std::fs::read_to_string("/proc/self/stat")
.ok()
.and_then(|s| {
// Field 14 (utime) and 15 (stime), 1-based, AFTER the comm field —
// which can contain spaces, so the split starts past its `)`.
let rest = s.rsplit_once(')')?.1;
let f: Vec<&str> = rest.split_whitespace().collect();
let utime: u64 = f.get(11)?.parse().ok()?;
let stime: u64 = f.get(12)?.parse().ok()?;
Some(utime + stime)
})
.unwrap_or(0);
ticks as f64 / 100.0
}