diff --git a/docs/findings/compare-store-scan.md b/docs/findings/compare-store-scan.md index 8bda2c8..75ef019 100644 --- a/docs/findings/compare-store-scan.md +++ b/docs/findings/compare-store-scan.md @@ -104,15 +104,195 @@ large serial block left in `b_compare`: the parallel map is 66% of the phase and bandwidth-bound above 48 threads, which is [a different problem](compare-screen-vs-align.md) with a different lever. -Two smaller things are open and measured but not decided: - -- **Collecting the map's result at 16 B instead of 48 B** in production runs - (`--verbose` needs the 48 B form for its cost attribution). This is real but - ambiguous: −5.9% / −1.5% wall on ITS2, `sys` time collapsing 93%, and `user` - time *rising* 6–12% with no mechanism established for the rise. The leading - account is glibc's dynamic `mmap` threshold, which caps at 32 MB: the 48 B - vector is 39.6–62.6 MB and is `munmap`ped and re-faulted every call, while the - 16 B vector fits under the cap and is reused. That predicts the *allocation*, - not the element width, is the thing to fix. -- **Reusing one scratch buffer** across calls rather than allocating per call, - which would remove the allocation at either width. +Two further levers were built and measured, and **neither is merged.** They are +the rest of this page, because the reasons are more useful than the result. + +## The allocation levers: a real cost that does not pay + +`b_compare_parallel` allocates its `nraw`-long result vector on every call and +frees it — 45.1 MB on soil ITS2, 58.8 MB on 16S, over thousands of calls. Two +ways to stop paying for that were built: + +- **Lever A** — collect at 16 B instead of 48 B in production runs, dropping + `CompCost` from the element (`--verbose` still needs the 48 B form for its + attribution). This works by *accident*: it puts the vector under a threshold. +- **Lever D** — hold one buffer on `B` and fill it with `collect_into_vec`, + removing the allocation at either width. + +Both collapse `sys` time — 70% for A, **94% for D** (674.6 → 38.6 s on ITS2 R2). +The mechanism is glibc's dynamic `mmap` threshold, which caps at 32 MB: a vector +above the cap is `mmap`ped and `munmap`ped every call rather than recycled from +the arena, so the kernel re-faults and re-zeroes every page each time. +`examples/parallel_overhead` confirms it directly — at 16 B the vector is +15.0–19.6 MB, under the cap, and fresh-vs-reuse shows no consistent difference; +at 48 B it is 45.1–58.8 MB, over the cap, and the gap is **~5 ms per call at +both pool sizes**. + +That arithmetic is consistent end to end: 4,017 calls × 5 ms ≈ 20 s against a +131 s map, and 674 core-seconds of `sys` is ~10.5 s of wall across 64 threads. + +**And removing it returns nothing.** + +| soil ITS2 R2, non-verbose | baseline | D (scratch buffer) | A (16 B) | +|---|---|---|---| +| real | 258.3 s | 264.7 s (**+2.5%**) | 257.7 s (−1.5%) | +| user | 7,381 s | 8,592 s (**+16%**) | 8,536 s (+11%) | +| sys | 674.6 s | 38.6 s (−94%) | 202 s (−70%) | + +Both levers convert a large `sys` saving into an equal-or-larger `user` cost and +a wall time that does not improve. Total CPU goes *up*: 8,056 core-seconds +becomes 8,631 (D) or 8,738 (A). + +### Where the `user` time actually goes + +A verbose B-vs-D pair localises it. `busy` — the sum of per-item timers taken +inside the map closure — rises **+16.0%** on ITS2 R2, against a `user` rise of ++16.4% measured non-verbose. The extra CPU is inside the map closure, not in the +serial phases and not in framework overhead. + +| ITS2 | B | D | change | +|---|---|---|---| +| `busy` R1 | 4834 / 5175 core-s | 4907 / 5212 | +1.1% | +| `busy` R2 | 5534 / 5715 core-s | 6307 / 6745 | **+16.0%** | +| `free` | 1.10–1.99 s | 0.00 s | buffer confirmed reused | +| map parallel efficiency | 87–88% | **93–94%** | see below | +| `run_dada` R1 | 167.3 / 172.3 s | 161.7 / 164.7 s | −3.9% | +| `run_dada` R2 | 211.2 / 214.4 s | 217.9 / 235.4 s | **+6.5%** | + +**A read-for-ownership account was proposed and this falsifies it** — or rather, +shows the test was built wrong, which amounts to the same thing. The account was +that a freshly-`mmap`ped page is zeroed by the kernel immediately before a worker +writes it, so the destination store is cache-warm, while a reused buffer's lines +are cold and dirty. `busy` rising was written down in advance as the confirming +prediction. + +It cannot be. `busy` times the closure *body*; the write into the destination +vector happens in rayon's collect, **after the closure returns**. A cost on the +destination store could never appear in `busy`. What got slower is the +screen-and-align compute itself, which that account does not predict. The +prediction was mapped onto an instrument that could not observe the thing it was +predicting. + +What survives is narrower and, in one respect, more interesting: **reused memory +is slower than freshly-faulted memory for this workload, across two independent +implementations and two buffer sizes.** Lever A reuses a 15 MB buffer through +glibc's arena and pays +11%; lever D reuses a 45 MB buffer explicitly and pays ++16%. Size modulates the penalty but does not cause it — the common factor is +reuse itself. That is worth knowing beyond this issue, because "hoist the +allocation out of the loop" is a routine optimisation instinct and here it costs +more than it saves. + +The candidate that fits the size dependence — offered as a hypothesis, having +already been wrong once on this page — is that a live buffer stays resident in +LLC and contends with the 1.7 GB of k-mer vectors the screen streams, while a +freed region's lines die naturally. Settling it needs hardware counters +(LLC-misses, dTLB-misses) on one B-vs-D pair, not another timer. + +`parallel_overhead` cannot settle that, and says so: its synthetic reports reuse +as **faster**, the opposite of production. Its work function is pure ALU while +production's map streams 1.7 GB of k-mer vectors, so it has nothing to contend +with. Same failure mode as `screen_bandwidth` — a stand-in reproduces ordering, +not magnitudes, when it stands in for real work. + +**Consequence: do not retry either lever on the strength of the `sys` number.** +The `sys` time is real, well-understood, and not on the critical path. Anything +that revisits this needs to explain the `user` rise first, with hardware +counters rather than a timer. + +## Load imbalance in the map: falsified + +The same investigation was pointed at a second target. Production reports 86–90% +map parallel efficiency, and the residual looked like threads idling at the tail +of each collect waiting on stragglers — plausible, since raws are +abundance-sorted and a few percent pay a full alignment while the rest are +screened out. + +It is not happening. `join_uniform` and `join_skewed` do the **same total work** +per call and differ only in its distribution: + +| | ITS2 shape (0.8% heavy) | 16S shape (4.5% heavy) | +|---|---|---| +| skewed vs work-matched uniform | +0.1% | −0.1% | + +Zero, on both parameterisations, at production's measured 14× aligner/screen +cost ratio. The heavy region is ~235 tasks of 29,360 spread over 64 threads, so +`with_max_len(32)` gives work-stealing far more splits than it needs. + +**So the 86–90% figure is not idle time**, and an earlier reading of it here as +"1,166 core-seconds lost to imbalance" was wrong. `busy` is the sum of timers +taken *inside* the map closure: it never measured rayon's per-task dispatch, the +collect's stores into the destination, or the timer calls themselves. The gap is +mostly unmeasured work. + +Roughly half of it is now identified. Removing the per-call allocation (lever D) +raises map parallel efficiency from 87–88% to **93–94%** while `busy` is +unchanged or higher — so ~6 of the missing 10–14 points was allocation and +page-fault work, sitting inside map wall but outside the per-item timers. The +remaining ~6 points is still unattributed and needs a different instrument. + +**Consequence: the load-balancing knobs are closed.** `DADA2RS_PAR_GRAIN` is +already doing its job, and there is no parallel-dampening problem to chase. + +## The run is not uniform, and the means describe no part of it + +Every figure above is a total over the whole bud loop. Per-window progress lines +(#150) show that is hiding a lot. + +Soil ITS2 R1, 30-second windows: + +| window | eff cores | `align` | map | shuffle | bud+pupd | +|---|---|---|---|---|---| +| 0–30 s | 24.4 | 1.62% | 12.6 s | 9.1 s | 6.6 s | +| 60–90 s | 29.0 | 0.42% | 15.4 s | 8.5 s | 3.1 s | +| 120–150 s | **37.9** | 1.01% | 20.2 s | **4.0 s** | **1.7 s** | + +Occupancy climbs monotonically from 22 to 42 effective cores of 64. The +end-of-run mean of ~29 describes no window of the run. + +**The ramp is the serial fraction, not the workload.** `align` falls six-fold +and then rises again while occupancy climbs straight through, so the alignment +pass rate is not driving it. Serial work per window collapses from 15.7 s to +5.7 s — the partition stabilises, the incremental reconcile finds less to do, +and `b_shuffle` plus `p_update` shrink out of the way. + +A prediction made before looking was that occupancy should *fall* over the run, +because greedy skips increase as cluster centres get less abundant. That +reasoned about the map, and the map is not where the answer is. + +**Consequence for how this project measures.** "Effective cores 31.4 → 38.4" and +"map parallel efficiency 86–90%" have both been used to rank levers, and both are +means over a run that spans nearly a factor of two. A change that helps the +early, serial-heavy phase and one that helps the late, map-heavy phase are +indistinguishable in the totals. Prefer per-window figures when the question is +*where* a change acts. + +## Three instrument errors, and what each cost + +This page's negative results all came from measurement mistakes caught late, so +they are recorded rather than quietly fixed: + +1. **A hypothesis killed by accounting, not by a run.** Rayon spin-wait was the + first explanation for the `user` rise. The whole ITS2 R2 run has only 838 + core-seconds of CPU outside the map's summed busy time, while lever D's + `user` rise alone is 1,211 — there was no room for it. Doing that arithmetic + before booking node time is the cheapest step in this entire page. +2. **A skew model that could not exhibit the thing it measured.** The first + imbalance arm marked every 32nd index heavy while the task grain was 32, so + every task held exactly one heavy item and mean task cost equalled max task + cost *by construction*. It reported "no imbalance" and would have done so + whatever the truth was. A skew uniform at the granularity of a task is not a + skew. +3. **The right estimator applied to the wrong arm.** Reporting the per-round + minimum defends against a noisy neighbour, and is correct for five of the six + arms. `collect_fresh`'s spread is *intrinsic* — glibc allocator state, i.e. + whether a round recycled rather than remapped — so the minimum systematically + selects the rounds where the effect under test did not occur. On `min` the + allocation cost appeared to shrink as the vector grew (2.5 ms at 45.1 MB, + 1.3 ms at 58.8 MB); on `median` it is 5.04 and 5.10 ms, essentially identical. + The tell was in the output the whole time: that arm runs at `med/min` + 1.06–1.10 while every other arm sits at 1.00–1.01. + +The generalisation, and the reason this section exists: **an arm that cannot +produce the effect, and an estimator that selects against it, both return a +clean-looking null.** A null is only evidence once the instrument has been shown +capable of returning something else. diff --git a/docs/findings/index.md b/docs/findings/index.md index e2c068b..9516e06 100644 --- a/docs/findings/index.md +++ b/docs/findings/index.md @@ -124,9 +124,17 @@ here is the evidence, and here is the path it opens or closes." **83–87% of the scan**; hoisting `e_minmax` into a dense array parallel to `raw_cluster` cut the store **71%** and `run_dada` **20.1–21.3%** on soil 16S (−15.2% on ITS2), byte-identical, with the untouched phases flat. Effective - cores go 31.4 → 38.4 of 64. Also a note on synthetics: the microbenchmark got - the mechanism right and the magnitude wrong by 3×, so plan against its - *ordering*, not its numbers. + cores go 31.4 → 38.4 of 64. Then two follow-on levers were built and + **neither merged**: removing the map's per-call allocation collapses `sys` by + 94% and returns *nothing* — wall +2.5%, `user` +16%, total CPU up — because + that `sys` time was never on the critical path; and map load imbalance, the + suspected cause of the 86–90% parallel efficiency, measures at ±0.1% on both + pool shapes, so the residual is unmeasured work rather than idle threads. + Ends with the three instrument errors behind those nulls — a hypothesis killed + by arithmetic instead of node time, a skew model that could not exhibit skew, + and the right estimator applied to the one arm whose variance was intrinsic — + and the rule they share: **a null is evidence only once the instrument has + been shown capable of returning something else.** - [Measuring on a NUMA node](measuring-on-numa.md) — **a methodology result that reversed a verdict.** The benchmark node has two NUMA domains and nothing was ever pinned, so page placement re-rolled every run and replicates of the *same diff --git a/examples/parallel_overhead.rs b/examples/parallel_overhead.rs new file mode 100644 index 0000000..6fa19af --- /dev/null +++ b/examples/parallel_overhead.rs @@ -0,0 +1,451 @@ +//! Decompose what the parallel `b_compare` map loses that is not compute +//! (issue #147 follow-up). +//! +//! ## What this exists to settle +//! +//! Two questions came out of the #147 A/B runs, and the phase accounting is +//! not fine-grained enough to separate them. +//! +//! **1. Where does the +12% `user` time come from?** Removing +//! `b_compare_parallel`'s per-call allocation — either by shrinking the result +//! element under glibc's 32 MB `mmap` cap (lever A) or by reusing one buffer +//! (lever D) — collapses `sys` by 70-94% and *raises* `user` by 11-16%. Both +//! levers do it, at different element widths, so it tracks reusing the +//! allocation rather than its size. +//! +//! A rayon spin-wait explanation was **falsified by accounting** before this +//! benchmark was written: on soil ITS2 R2 the whole run has only 838 +//! core-seconds of CPU outside the map's summed per-item busy time (8,056 total +//! vs 7,218 busy), while lever D's `user` rise alone is 1,211. There is no room +//! for it, and 48.7% overall occupancy says workers sleep through the serial +//! phases rather than burning CPU in them. So the rise is *inside* busy: the +//! workers' own stores got more expensive. +//! +//! The mechanism this tests: a freshly-`mmap`ped page is zeroed by the kernel +//! immediately before a worker writes it, so the line is already warm in the +//! local cache and the store is nearly free. A reused buffer's lines are cold +//! and dirty, so every store pays a read-for-ownership from DRAM plus a +//! writeback of what it evicts. Identical work, moved out of kernel zeroing +//! (`sys`) and into user-mode memory stalls (`user`) — and *more* of it, since +//! the kernel zeroes with non-temporal stores and the collect does not. +//! +//! If that is right, `collect_fresh` and `collect_reuse` differ in the same +//! direction and rough proportion as the production `user` figures, and +//! `collect_reuse_nt`-style mitigation becomes the question rather than which +//! lever to merge. +//! +//! **2. What does the map lose to load imbalance?** Production reports 86-90% +//! map parallel efficiency, which on soil ITS2 R2 is 1,166 core-seconds lost +//! *inside* the parallel region across 4,017 calls — 4.6 ms per thread per +//! call. That is far too long to be rayon's spin-then-sleep (microseconds), so +//! it is threads idling at the tail of each collect waiting on stragglers. +//! `join_uniform` and `join_skewed` do the *same total work* per call and differ +//! only in how it is distributed, so the gap between them is the imbalance cost +//! rather than the framework cost. Pass `--base 0` for the fork/join/wake floor +//! with no work at all. +//! +//! This is the largest unexamined parallel loss in the project and it is +//! independent of the allocation question, so both are measured here. +//! +//! ## Reading the results +//! +//! Absolute numbers are not the point; the *arms are matched pairs* and only +//! the differences carry the argument: +//! +//! - `collect_fresh` vs `collect_reuse` — the allocation question. Same work, +//! same element, differing only in whether the destination is newly mapped. +//! - `join_uniform` vs `join_skewed` — the imbalance question. Same call count, +//! thread count, **and total work**, differing only in how that work is +//! distributed across items. An arm that simply does less work would measure +//! work rather than imbalance. +//! +//! Per-call figures matter more than totals here, because production's cost +//! scales with call count (4,017 on ITS2, 11,283 on 16S), not with wall time. +//! +//! ## Running it on a node you do not have to yourself +//! +//! Prefer an idle node. When one is not available this benchmark is built to +//! survive a neighbour, by two deliberate choices: +//! +//! - **Arms run round-robin, one round each**, never as sequential blocks. +//! Contention drifts over the life of a run, so blocked arms sample different +//! node states and the between-arm difference picks up whatever the +//! neighbouring job was doing during each block. Interleaved, every arm sees +//! the same drift, and because only the matched pairs carry the argument the +//! common component cancels. +//! - **Both a per-round minimum and a median are reported.** The minimum is the +//! right statistic when an arm's spread comes from a noisy neighbour: the +//! least-disturbed round is closest to the uncontended truth, where a mean is +//! pulled around by whatever else is on the node. The `med/min` line is the +//! contention readout — near 1.00 is a quiet node. +//! +//! It is the **wrong** statistic when the spread is intrinsic to what the arm +//! measures, and `collect_fresh` is exactly that: its variance is glibc's +//! allocator state — whether a given round recycled rather than remapped — so +//! the minimum systematically selects the rounds where the thing under test +//! did not happen. It runs at med/min 1.06–1.10 in every cluster run so far +//! while every other arm sits at 1.00–1.01. Read the median for the +//! allocation pair, the minimum for the rest, and say which was used. +//! +//! This is not hypothetical: on `min` the allocation cost appeared to shrink +//! as the vector grew (2.5 ms at 45.1 MB, 1.3 ms at 58.8 MB), which is +//! backwards; on `median` it is ~5 ms/call at both sizes, which is what a +//! page-fault cost should look like. +//! +//! Neither trick rescues a badly oversubscribed node. If the neighbour is using +//! cores this run also wants, `join_skewed` is measuring the neighbour's +//! stragglers as well as its own and the imbalance number is not meaningful. +//! Leave headroom with `--threads` rather than oversubscribing, and say what +//! the node was doing when reporting the result. +//! +//! Run under `numactl --interleave=all`, at the thread count production uses. +//! Page placement re-rolls per run and the serial scattered phases have swung +//! 25% between replicates of one binary without it — see +//! docs/findings/measuring-on-numa.md. +//! +//! ## Variants +//! +//! | arm | what it does per round | isolates | +//! |---|---|---| +//! | `collect_fresh` | parallel collect into a newly allocated `Vec` | today's `b_compare_parallel` | +//! | `collect_reuse` | parallel collect into one reused `Vec` | lever D | +//! | `collect_fresh16` | as `collect_fresh`, 16 B element | lever A, allocation kept | +//! | `collect_reuse16` | as `collect_reuse`, 16 B element | levers A+D | +//! | `join_uniform` | parallel map, cost spread evenly over items | work-matched control | +//! | `join_skewed` | same total work, concentrated in the abundance-sorted front | + load imbalance | +//! +//! ## Usage +//! +//! ```text +//! cargo build --profile release-native --example parallel_overhead +//! numactl --interleave=all ./target/release-native/examples/parallel_overhead \ +//! --raws 939532 --rounds 200 --threads 64 +//! ``` +//! +//! `--raws` defaults to the soil ITS2 R2 pool (939,532) so the 48 B result +//! vector is 45.1 MB — above glibc's 32 MB cap, which is the regime under +//! test. Drop it below ~700,000 and the fresh/reuse arms should converge, +//! because the allocation stops being `mmap`ped; that is a useful positive +//! control on the mechanism. + +use rayon::prelude::*; +use std::hint::black_box; +use std::time::Instant; + +/// Mirrors `b_compare_parallel`'s result element: `(f64, u32, bool, CompCost)`. +#[derive(Clone, Copy, Default)] +#[repr(C)] +struct Item48 { + lambda: f64, + hamming: u32, + skipped: bool, + cost: [u64; 4], +} + +/// The same without `CompCost` (lever A's production element). +#[derive(Clone, Copy, Default)] +#[repr(C)] +struct Item16 { + lambda: f64, + hamming: u32, + skipped: bool, +} + +fn arg(name: &str, default: T) -> T { + let args: Vec = std::env::args().collect(); + args.iter() + .position(|a| a == name) + .and_then(|i| args.get(i + 1)) + .and_then(|v| v.parse().ok()) + .unwrap_or(default) +} + +/// Stand-in for per-item alignment cost. +/// +/// Production's raws are **abundance-sorted**, and the few percent that clear +/// the k-mer screen and pay a full alignment are concentrated at the *front* of +/// the index range. So the skew has to be positional: the first `heavy_frac` of +/// indices cost `base * skew`, the rest cost `base`. +/// +/// The first version of this got it wrong in a way that made the imbalance arm +/// measure nothing. It marked every 32nd index heavy, while the task grain is +/// `with_max_len(32)` — so every task contained exactly one heavy item and mean +/// task cost equalled max task cost by construction. The arm reported −3.3%, +/// i.e. no imbalance, because there was none to find. A skew that is uniform at +/// the granularity of a task is not a skew. +#[inline] +fn work(index: usize, nraw: usize, base: usize, skew: usize, heavy_frac: f64) -> f64 { + let heavy_until = (nraw as f64 * heavy_frac) as usize; + let iters = if skew > 1 && index < heavy_until { + base * skew + } else { + base + }; + let mut acc = index as f64; + for _ in 0..iters { + acc = black_box(acc * 1.000_001 + 1.0); + } + acc +} + +fn main() { + // Soil ITS2 R2: 939,532 uniques, so the 48 B vector is 45.1 MB. + let nraw: usize = arg("--raws", 939_532); + let rounds: usize = arg("--rounds", 200); + let threads: usize = arg("--threads", 0); + // Production's alignment pass rate is 0.8% (ITS2) to 4.5% (16S); the skew + // multiplier stands in for how much more a passing comparison costs. + // Production's cost ratio, not a round number: soil 16S R1 measures the + // aligner at 17,759 ns/comp against the screen's 1,282, so a comparison + // that clears the screen costs ~14x one that does not. + let skew: usize = arg("--skew", 14); + // Per-item work, in iterations of a dependent FLOP. The default is set so + // `join_skewed` lands near production's map cost on soil ITS2 R2 — + // 131 s over 4,017 calls at 64 threads is 2,086 core-ms/call, or ~2.2 us + // per raw. With the default skew and heavy fraction the mean is + // `base * 1.104` iterations, which is why this is 430 and not 160. An under-costed stand-in makes the collect look dominant and + // understates imbalance, which is the thing being measured. Pass `--base 0` + // to strip the compute out entirely and read the fork/join/wake floor. + let base: usize = arg("--base", 430); + // Fraction of the (abundance-sorted) index range that pays a full + // alignment: 0.8% on soil ITS2, 4.5% on soil 16S. + let heavy_frac: f64 = arg("--heavy-frac", 0.008); + + if threads > 0 { + rayon::ThreadPoolBuilder::new() + .num_threads(threads) + .build_global() + .expect("failed to set rayon thread count"); + } + let nthreads = rayon::current_num_threads(); + + let bytes48 = nraw * std::mem::size_of::(); + let bytes16 = nraw * std::mem::size_of::(); + println!( + "raws={nraw} rounds={rounds} threads={nthreads} base={base} skew={skew} heavy_frac={heavy_frac}\n\ + result vector: {:.1} MB at 48 B, {:.1} MB at 16 B \ + (glibc mmap cap is 32 MB)\n\ + production reference: soil ITS2 R2 map = 2086 core-ms/call \ + (131 s / 4017 calls x 64 threads)\n\ + mean {mean_iters} iters/item; heavy tasks cost {task_ratio:.0}x a light one\n", + bytes48 as f64 / 1e6, + bytes16 as f64 / 1e6, + mean_iters = base + (base as f64 * (skew - 1) as f64 * heavy_frac) as usize, + task_ratio = skew as f64, + ); + + let grain = 32; + // Work-matched to `join_skewed`: same mean iterations per item. + let uniform = base + (base as f64 * (skew - 1) as f64 * heavy_frac) as usize; + + // Reused destinations. Faulted in once so the first round is not charged + // for page faults the later rounds do not pay. + let mut buf48: Vec = vec![Item48::default(); nraw]; + let mut buf16: Vec = vec![Item16::default(); nraw]; + + // Arms are run **round-robin, one round each**, not as sequential blocks. + // + // On a shared node this is the difference between a usable measurement and + // a worthless one. Contention drifts over the life of the run, so blocked + // arms sample different node states and the between-arm difference picks up + // whatever the neighbouring job happened to be doing during each block. + // Interleaved, every arm sees the same drift, and since only the matched + // pairs carry the argument the common component cancels. + // + // Per-round times are kept rather than summed so the reporting can use the + // **minimum** as the estimator: the least-disturbed round is the one + // closest to the uncontended truth, while the mean is pulled around by + // whatever else is on the node. Median and max are printed alongside so + // contention is visible instead of silent -- a wide min-to-median spread is + // the signal to distrust the run. + type Arm<'a> = (&'a str, Box, usize); + let mut arms: Vec = vec![ + ( + "collect_fresh", + Box::new(|| { + let v: Vec = (0..nraw) + .into_par_iter() + .with_max_len(grain) + .map(|i| Item48 { + lambda: work(i, nraw, base, skew, heavy_frac), + hamming: i as u32, + skipped: false, + cost: [0; 4], + }) + .collect(); + black_box(&v); + }), + bytes48, + ), + ( + "collect_reuse", + Box::new(|| { + (0..nraw) + .into_par_iter() + .with_max_len(grain) + .map(|i| Item48 { + lambda: work(i, nraw, base, skew, heavy_frac), + hamming: i as u32, + skipped: false, + cost: [0; 4], + }) + .collect_into_vec(&mut buf48); + black_box(&buf48); + }), + bytes48, + ), + ( + "collect_fresh16", + Box::new(|| { + let v: Vec = (0..nraw) + .into_par_iter() + .with_max_len(grain) + .map(|i| Item16 { + lambda: work(i, nraw, base, skew, heavy_frac), + hamming: i as u32, + skipped: false, + }) + .collect(); + black_box(&v); + }), + bytes16, + ), + ( + "collect_reuse16", + Box::new(|| { + (0..nraw) + .into_par_iter() + .with_max_len(grain) + .map(|i| Item16 { + lambda: work(i, nraw, base, skew, heavy_frac), + hamming: i as u32, + skipped: false, + }) + .collect_into_vec(&mut buf16); + black_box(&buf16); + }), + bytes16, + ), + ( + "join_uniform", + Box::new(|| { + let s: f64 = (0..nraw) + .into_par_iter() + .with_max_len(grain) + .map(|i| work(i, nraw, uniform, 1, 0.0)) + .sum(); + black_box(s); + }), + 0, + ), + ( + "join_skewed", + Box::new(|| { + let s: f64 = (0..nraw) + .into_par_iter() + .with_max_len(grain) + .map(|i| work(i, nraw, base, skew, heavy_frac)) + .sum(); + black_box(s); + }), + 0, + ), + ]; + + let mut times: Vec> = vec![Vec::with_capacity(rounds); arms.len()]; + // One untimed round per arm: first touch, allocator warm-up, and branch + // predictor state should not land on the first measured round. + for (_, run, _) in arms.iter_mut() { + run(); + } + for _ in 0..rounds { + for (a, (_, run, _)) in arms.iter_mut().enumerate() { + let t = Instant::now(); + run(); + times[a].push(t.elapsed().as_secs_f64()); + } + } + + println!( + "{:<16} {:>10} {:>10} {:>10} {:>10} {:>9} {:>12}", + "arm", "min ms", "med ms", "max ms", "ns/raw", "GB/s", "core-ms" + ); + let mut mins = Vec::with_capacity(arms.len()); + let mut meds = Vec::with_capacity(arms.len()); + for (a, (name, _, bytes)) in arms.iter().enumerate() { + let mut v = times[a].clone(); + v.sort_by(|x, y| x.partial_cmp(y).expect("no NaN in timings")); + let (min, med, max) = (v[0], v[v.len() / 2], v[v.len() - 1]); + mins.push(min); + meds.push(med); + println!( + "{name:<16} {:>10.3} {:>10.3} {:>10.3} {:>10.1} {:>9.1} {:>12.1}", + min * 1e3, + med * 1e3, + max * 1e3, + min * 1e9 / nraw as f64, + if *bytes > 0 { + *bytes as f64 / min / 1e9 + } else { + 0.0 + }, + min * nthreads as f64 * 1e3, + ); + } + + // The two comparisons this benchmark exists for, reported on BOTH + // estimators because they disagree for one arm and the disagreement is + // itself informative. + // + // `min` is the right statistic when an arm's spread comes from a noisy + // neighbour: the least-disturbed round is closest to the truth. It is the + // wrong one when the spread is *intrinsic* to what the arm measures, and + // `collect_fresh` is exactly that case -- its variance is glibc's + // allocator state (whether a round happened to recycle rather than remap), + // so taking the minimum systematically picks the rounds where the thing + // under test did not happen. Every other arm here runs at med/min 1.00 + // while collect_fresh sits at 1.06-1.10 across every run so far. + // + // Read the median line for the allocation pair and the min line for the + // rest. Where they disagree, say which you used: on `min` the allocation + // cost appeared to shrink as the vector grew (2.5 ms at 45 MB, 1.3 ms at + // 59 MB), which is backwards; on `median` it is ~5 ms/call at both sizes, + // which is what a page-fault cost should look like. + let dpct = |v: &[f64], a: usize, b: usize| (v[b] - v[a]) / v[a] * 100.0; + println!( + "\nallocation 48 B: reuse is {:+.1}% (min) / {:+.1}% (med) vs fresh \ + 16 B: {:+.1}% (min) / {:+.1}% (med)", + dpct(&mins, 0, 1), + dpct(&meds, 0, 1), + dpct(&mins, 2, 3), + dpct(&meds, 2, 3), + ); + println!( + " 48 B absolute: {:+.2} ms/call (min) / {:+.2} ms/call (med)", + (mins[1] - mins[0]) * 1e3, + (meds[1] - meds[0]) * 1e3, + ); + println!( + "imbalance : skewed is {:+.1}% (min) / {:+.1}% (med) vs work-matched uniform", + dpct(&mins, 4, 5), + dpct(&meds, 4, 5), + ); + // Contention check: on an idle node med/min sits near 1.00. Well above that + // and the arms were not sampling the same machine. + let spread: Vec = arms + .iter() + .enumerate() + .map(|(a, (name, _, _))| { + let mut v = times[a].clone(); + v.sort_by(|x, y| x.partial_cmp(y).expect("no NaN in timings")); + format!("{name} {:.2}", v[v.len() / 2] / v[0]) + }) + .collect(); + println!("med/min (1.00 = quiet node): {}", spread.join(" ")); + + println!( + "\nfresh vs reuse is the allocation question (#147 levers A and D);\n\ + uniform vs skewed is the load-imbalance question behind the 86-90%\n\ + map parallel efficiency production reports." + ); +}