Tests: linear-time checks measure CPU time, not wall clock under load (#850)

The five tests that assert linear layout/export/hyphenation by comparing
the cost of an n-sized and a larger input (layout: unequal formats, hidden
separators with auto hyphenation, hidden float anchors; pdf: fragmented
hidden headings; proof: hyphenating a long word) timed both with wall
clock, fastest of three. On a loaded machine (CI, shared dev boxes, the
test harness running other tests in parallel) a preempted big run, timer
resolution on the small run, or a tight 4x/8.0 limit (hyphenation measured
~7.2 when linear) made them fail now and then.

Each now uses a shared cost_ratio helper (test-only, no production change):
- CPU time of the test thread from /proc/thread-self/schedstat on Linux, so
  time spent waiting for a CPU is left out (wall clock elsewhere);
- the small input runs `scale` times per timing so both timings are long
  against the clock's resolution;
- small and big runs alternate, five rounds after a warm-up, cheapest kept;
- 8x the input everywhere: linear ~8x, quadratic ~64x, limit 24x.

Measured under load (load avg ~15-35 on 32 cores): 60 linear ratios in
7.7-8.8. With the old quadratic code injected locally each test fails:
unequal formats (uncapped style bucket scan) ~90-104x, hidden separators
(hyphenator rescan per point) ~36x, float anchors (run walk restarted per
anchor) ~188x, PDF headings (left-out range scan per char) ~37x,
hyphenation 50-65x.

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>

crates/layout/src/tests.rs

@@ -166,29 +166,57 @@ fn hidden_text_adds_no_line_break_opportunity_when_not_shown() {
     }
 }
 
-/// How much longer laying out `doc(4n)` takes than `doc(n)` (fastest of three each, after a
-/// warm-up): ~4 when linear, ~16 when quadratic, whatever the machine.
-/// How much bigger the second document is in the linear-time tests. At 8x a linear layout takes
-/// about 8x as long and a quadratic one about 64x, so a limit of 24x stays far from both, however
-/// busy the machine running the tests is.
+/// How much bigger the second document is in the linear-time tests. At 8x a linear layout costs
+/// about 8x as much and a quadratic one about 64x, so a limit of 24x stays far from both.
 const SCALE: usize = 8;
 
-fn layout_time_ratio(doc: impl Fn(usize) -> Document, n: usize, opts: &LayoutOptions) -> (f64, f64, f64) {
-    let fastest = |d: &Document| {
-        (0..3)
-            .map(|_| {
-                let t = std::time::Instant::now();
-                layout(d, &mut LayoutCache::new(), opts);
-                t.elapsed().as_secs_f64()
-            })
-            .fold(f64::INFINITY, f64::min)
+/// The CPU time `f` takes on this thread, in seconds. On Linux it is the scheduler's count of the
+/// time the thread actually ran, so the time it waits while other work on a busy machine has the
+/// CPU is left out; elsewhere, wall-clock time.
+fn cpu_cost(f: &mut impl FnMut()) -> f64 {
+    let ran = || {
+        let s = std::fs::read_to_string("/proc/thread-self/schedstat").ok()?;
+        s.split_whitespace().next()?.parse::<u64>().ok()
     };
-    let (small, big) = (doc(n), doc(SCALE * n));
-    layout(&small, &mut LayoutCache::new(), opts);
-    let (t1, tk) = (fastest(&small), fastest(&big));
+    let (t, before) = (std::time::Instant::now(), ran());
+    f();
+    match (before, ran()) {
+        (Some(a), Some(b)) => b.saturating_sub(a) as f64 * 1e-9,
+        _ => t.elapsed().as_secs_f64(),
+    }
+}
+
+/// How much more `big` costs than `small`, for `big` an input `scale` times the size of `small`'s:
+/// (small, big, big / small), ~`scale` when linear and ~`scale`² when quadratic. Each is the
+/// cheapest of several runs after a warm-up, the runs alternating so a busy spell slows both sizes
+/// alike; `small` is timed `scale` times over per run, so both timings are long against the clock's
+/// resolution.
+fn cost_ratio(scale: usize, mut small: impl FnMut(), mut big: impl FnMut()) -> (f64, f64, f64) {
+    small();
+    big();
+    let mut small_scaled = || (0..scale).for_each(|_| small());
+    let (mut t1, mut tk) = (f64::INFINITY, f64::INFINITY);
+    for _ in 0..5 {
+        t1 = t1.min(cpu_cost(&mut small_scaled) / scale as f64);
+        tk = tk.min(cpu_cost(&mut big));
+    }
     (t1, tk, tk / t1.max(1e-9))
 }
 
+/// [`cost_ratio`] of laying out `doc(SCALE * n)` against `doc(n)`.
+fn layout_time_ratio(doc: impl Fn(usize) -> Document, n: usize, opts: &LayoutOptions) -> (f64, f64, f64) {
+    let (small, big) = (doc(n), doc(SCALE * n));
+    cost_ratio(
+        SCALE,
+        || {
+            layout(&small, &mut LayoutCache::new(), opts);
+        },
+        || {
+            layout(&big, &mut LayoutCache::new(), opts);
+        },
+    )
+}
+
 #[test]
 fn hidden_separators_with_automatic_hyphenation_lay_out_in_linear_time() {
     // "hyphenation " n times with every space hidden: one joined word of 11n letters reaches the

crates/pdf/src/tests.rs

@@ -300,11 +300,44 @@ fn hidden_heading_text_stays_out_of_bookmarks_and_tags() {
     }
 }
 
+/// The CPU time `f` takes on this thread, in seconds. On Linux it is the scheduler's count of the
+/// time the thread actually ran, so the time it waits while other work on a busy machine has the
+/// CPU is left out; elsewhere, wall-clock time.
+fn cpu_cost(f: &mut impl FnMut()) -> f64 {
+    let ran = || {
+        let s = std::fs::read_to_string("/proc/thread-self/schedstat").ok()?;
+        s.split_whitespace().next()?.parse::<u64>().ok()
+    };
+    let (t, before) = (std::time::Instant::now(), ran());
+    f();
+    match (before, ran()) {
+        (Some(a), Some(b)) => b.saturating_sub(a) as f64 * 1e-9,
+        _ => t.elapsed().as_secs_f64(),
+    }
+}
+
+/// How much more `big` costs than `small`, for `big` an input `scale` times the size of `small`'s:
+/// (small, big, big / small), ~`scale` when linear and ~`scale`² when quadratic. Each is the
+/// cheapest of several runs after a warm-up, the runs alternating so a busy spell slows both sizes
+/// alike; `small` is timed `scale` times over per run, so both timings are long against the clock's
+/// resolution.
+fn cost_ratio(scale: usize, mut small: impl FnMut(), mut big: impl FnMut()) -> (f64, f64, f64) {
+    small();
+    big();
+    let mut small_scaled = || (0..scale).for_each(|_| small());
+    let (mut t1, mut tk) = (f64::INFINITY, f64::INFINITY);
+    for _ in 0..5 {
+        t1 = t1.min(cpu_cost(&mut small_scaled) / scale as f64);
+        tk = tk.min(cpu_cost(&mut big));
+    }
+    (t1, tk, tk / t1.max(1e-9))
+}
+
 #[test]
 fn long_fragmented_hidden_headings_export_in_linear_time() {
     // Headings of n chars in one-char runs: all hidden with bold alternating, and hidden and visible
     // alternating. Layout and the bookmark/tag titles once scanned every left-out range for every
-    // char, quadratic in n. Machine-independent: the time for 4n against n, linear ~4, quadratic ~16.
+    // char, quadratic in n. Machine-independent: the cost for 8n against n, linear ~8, quadratic ~64.
     let doc = |n: usize| {
         let heading = |visible_every_other: bool| {
             let mut h = Paragraph::with_text(&"abcdefg ".repeat(n / 8), CharProps::default()).styled("Heading1");
@@ -321,23 +354,19 @@ fn long_fragmented_hidden_headings_export_in_linear_time() {
         d
     };
     let opts = PdfOptions { compress: false, ..Default::default() };
-    // The fastest of a few runs, after a warm-up, so one slow run on a busy machine counts less.
-    let fastest = |d: &Document| {
-        (0..3)
-            .map(|_| {
-                let t = std::time::Instant::now();
-                export(d, &opts).unwrap();
-                t.elapsed().as_secs_f64()
-            })
-            .fold(f64::INFINITY, f64::min)
-    };
-    let n = 25_000;
-    let (small, big) = (doc(n), doc(4 * n));
+    let n = 12_500;
+    let (small, big) = (doc(n), doc(8 * n));
+    let (t1, t8, ratio) = cost_ratio(
+        8,
+        || {
             export(&small, &opts).unwrap();
-    let (t1, t4) = (fastest(&small), fastest(&big));
-    let ratio = t4 / t1.max(1e-9);
-    eprintln!("t(n) {t1:.3} s, t(4n) {t4:.3} s, ratio {ratio:.1}");
-    assert!(ratio < 8.0, "4x the text took {ratio:.1}x the time ({t1:.3} s → {t4:.3} s): not linear");
+        },
+        || {
+            export(&big, &opts).unwrap();
+        },
+    );
+    eprintln!("t(n) {t1:.3} s, t(8n) {t8:.3} s, ratio {ratio:.1}");
+    assert!(ratio < 24.0, "8x the text took {ratio:.1}x the time ({t1:.3} s → {t8:.3} s): not linear");
     let pdf = String::from_utf8_lossy(&export(&big, &opts).unwrap()).into_owned();
     // The all-hidden heading has no bookmark; the other is titled with its visible chars only.
     assert!(!pdf.contains("abcd"), "hidden heading text in a title");

crates/proof/src/hyphen.rs

@@ -455,16 +455,37 @@ mod tests {
         assert!(hyphen_points("typography", &lim).is_empty());
     }
 
-    /// The fastest of three timings of `f`, after a warm-up.
-    fn fastest(f: impl Fn()) -> f64 {
+    /// The CPU time `f` takes on this thread, in seconds. On Linux it is the scheduler's count of the
+    /// time the thread actually ran, so the time it waits while other work on a busy machine has the
+    /// CPU is left out; elsewhere, wall-clock time.
+    fn cpu_cost(f: &mut impl FnMut()) -> f64 {
+        let ran = || {
+            let s = std::fs::read_to_string("/proc/thread-self/schedstat").ok()?;
+            s.split_whitespace().next()?.parse::<u64>().ok()
+        };
+        let (t, before) = (std::time::Instant::now(), ran());
         f();
-        (0..3)
-            .map(|_| {
-                let t = std::time::Instant::now();
-                f();
-                t.elapsed().as_secs_f64()
-            })
-            .fold(f64::INFINITY, f64::min)
+        match (before, ran()) {
+            (Some(a), Some(b)) => b.saturating_sub(a) as f64 * 1e-9,
+            _ => t.elapsed().as_secs_f64(),
+        }
+    }
+
+    /// How much more `big` costs than `small`, for `big` an input `scale` times the size of `small`'s:
+    /// (small, big, big / small), ~`scale` when linear and ~`scale`² when quadratic. Each is the
+    /// cheapest of several runs after a warm-up, the runs alternating so a busy spell slows both sizes
+    /// alike; `small` is timed `scale` times over per run, so both timings are long against the clock's
+    /// resolution.
+    fn cost_ratio(scale: usize, mut small: impl FnMut(), mut big: impl FnMut()) -> (f64, f64, f64) {
+        small();
+        big();
+        let mut small_scaled = || (0..scale).for_each(|_| small());
+        let (mut t1, mut tk) = (f64::INFINITY, f64::INFINITY);
+        for _ in 0..5 {
+            t1 = t1.min(cpu_cost(&mut small_scaled) / scale as f64);
+            tk = tk.min(cpu_cost(&mut big));
+        }
+        (t1, tk, tk / t1.max(1e-9))
     }
 
     /// `hyphen_points`' limit checks as first written (a rescan of the letter run per point): the
@@ -598,7 +619,7 @@ mod tests {
 
     #[test]
     fn hyphenating_a_long_word_is_linear() {
-        // A word of n letters against one of 4n: linear ~4x the time, the old rescans ~16x. One in
+        // A word of n letters against one of 8n: linear ~8x the cost, the old rescans ~64x. One in
         // the pattern alphabet, one outside it (the syllable heuristic).
         let pattern = |k: usize| "hyphenation".repeat(k);
         let heuristic = |k: usize| "smørrebrød".repeat(k);
@@ -607,17 +628,16 @@ mod tests {
         let ratios: Vec<(String, f64)> = [(pattern as fn(usize) -> String, 20), (heuristic, 40)]
             .into_iter()
             .map(|(word, repeat)| {
-                let (small, big) = (word(400), word(1600));
-                let time = |w: &str| fastest(|| (0..repeat).for_each(|_| drop(hyphen_points(w, &Limits::default()))));
-                let (t1, t4) = (time(&small), time(&big));
-                let ratio = t4 / t1.max(1e-9);
-                let what = format!("{}…: t(n) {t1:.4} s, t(4n) {t4:.4} s, ratio {ratio:.1}", word(1).chars().take(10).collect::<String>());
+                let (small, big) = (word(400), word(8 * 400));
+                let time = |w: &str| (0..repeat).for_each(|_| drop(hyphen_points(w, &Limits::default())));
+                let (t1, t8, ratio) = cost_ratio(8, || time(&small), || time(&big));
+                let what = format!("{}…: t(n) {t1:.4} s, t(8n) {t8:.4} s, ratio {ratio:.1}", word(1).chars().take(10).collect::<String>());
                 eprintln!("{what}");
                 (what, ratio)
             })
             .collect();
         for (what, ratio) in ratios {
-            assert!(ratio < 8.0, "4x the letters, not linear: {what}");
+            assert!(ratio < 24.0, "8x the letters, not linear: {what}");
         }
     }