diff --git a/.github/workflows/pr_main.yaml b/.github/workflows/pr_main.yaml index 08879ec3f..1ff124048 100644 --- a/.github/workflows/pr_main.yaml +++ b/.github/workflows/pr_main.yaml @@ -406,6 +406,15 @@ jobs: name: prover-tests - name: Run prover tests (shard ${{ matrix.partition }}/4) + # Shard 1 only: force k > 1 so the per-table admission scheduler really + # runs several table closures concurrently. ubuntu-latest has 2-4 vCPU + # and table_parallelism() defaults to (cores / 3).max(1), so every + # other shard proves with a single driver thread and never exercises + # the concurrent path or VramGate's blocking path on a PR. The other + # three shards keep the default-k coverage. An empty value on those + # fails to parse and falls back to the default, so this is inert there. + env: + TABLE_PARALLELISM: ${{ matrix.partition == 1 && '6' || '' }} run: | cargo nextest run \ --archive-file prover-tests.tar.zst \ diff --git a/crypto/stark/src/instruments.rs b/crypto/stark/src/instruments.rs index 790c06cb0..796aaf46f 100644 --- a/crypto/stark/src/instruments.rs +++ b/crypto/stark/src/instruments.rs @@ -4,22 +4,26 @@ use std::sync::OnceLock; use std::sync::atomic::{AtomicU64, Ordering}; use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH}; -// Wall clock span timeline: the trustworthy per step latency breakdown. +// Wall clock span timeline: the per step latency breakdown. // -// Top level phase spans open and close on the main thread at phase boundaries. -// They do not overlap and sum to their parent, so that part of the tree is a -// true latency breakdown (unlike the accum_* thread local sub timers below, -// which sum per worker CPU time across rayon threads and can exceed 100%). A -// parallel region is one span around the blocking call; its internal split is -// reported separately as CPU time, never mixed into the wall tree. +// Phase spans open and close on the thread that drives the phase, at phase +// boundaries. Those are a true latency breakdown: they do not overlap and they +// sum to their parent, unlike the accum_* thread local sub timers below, which +// sum per worker CPU time across rayon threads and can exceed 100%. A parallel +// region is one span around the blocking call; its internal split is reported +// separately as CPU time, never mixed into the wall tree. // -// Per table spans are the exception. `multi_prove` runs one driver thread per -// in flight table (`r1_aux_build`, `r1_aux_commit`, `rounds_2to4`), so up to -// `table_parallelism()` of them are open at once: they DO overlap in wall time -// and their sum exceeds their parent. They still nest correctly, because each -// driver seeds its span depth from the spawning thread (`current_depth` / -// `enter_depth`) instead of starting a fresh thread at depth 0 — but read them -// as per table wall time, not as a share of the enclosing phase. +// Two properties of the recorded data are easy to misread: +// +// - Spans are ALSO opened on worker threads, not only on the main thread — +// the per table drivers in `multi_prove` (`*_table` labels) and the +// per stage workers in `continuation.rs`. `SPAN_DEPTH` is thread local and +// a fresh thread starts at 0, so those records carry depth 0 and their +// siblings overlap in wall time. Read them as per instance wall time. +// - `scripts/profiling/phase_table.py` SUMS spans that share a label, so a +// label used once per table reports the sum over all tables, which can +// exceed the enclosing phase's wall clock by up to `table_parallelism()`. +// Give a per instance span its own label; never reuse a phase label for it. // // let _s = instruments::span("trace_build"); // RAII, stops on drop // @@ -44,32 +48,6 @@ thread_local! { static SPAN_DEPTH: std::cell::Cell = const { std::cell::Cell::new(0) }; } -/// Depth the next span opened on this thread would be stamped with. -/// -/// Read this on the thread that spawns workers and hand the value to -/// [`enter_depth`] inside each worker: a freshly spawned OS thread starts at -/// depth 0, so without it every span opened off the main thread is recorded as -/// a root sibling of `prove_total` and the tree stops being a breakdown. -pub fn current_depth() -> u16 { - SPAN_DEPTH.with(|d| d.get()) -} - -/// Restores the span depth this thread had before [`enter_depth`]. -#[must_use] -pub struct DepthGuard(u16); - -/// Seed this thread's span depth from a parent thread, restoring the previous -/// value when the returned guard drops. -pub fn enter_depth(depth: u16) -> DepthGuard { - DepthGuard(SPAN_DEPTH.with(|d| d.replace(depth))) -} - -impl Drop for DepthGuard { - fn drop(&mut self) { - SPAN_DEPTH.with(|d| d.set(self.0)); - } -} - #[must_use] pub struct SpanGuard { label: &'static str, @@ -296,16 +274,13 @@ pub struct Round1SubOps { /// Timing data collected inside `multi_prove`. pub struct MultiProveTiming { pub prepass: Duration, + /// Round 1 main trace commits. The last phase-wide barrier — every main + /// root must be absorbed before the shared LogUp challenges are sampled. pub main_commits: Duration, - /// Aux build wall time summed over the concurrent per-table drivers. It is - /// no longer a phase of its own — the fused chain runs it inside - /// `rounds_2_4`, so it overlaps itself and is a subset of that wall time, - /// not an addend. - pub aux_build: Duration, - /// Aux commit, same accounting as `aux_build`. - pub aux_commit: Duration, - /// Wall clock of the fused per-table region: aux build + aux commit + - /// rounds 2-4, all of it concurrent across `table_parallelism()` drivers. + /// Wall clock of the fused per-table region: aux build, aux commit and + /// rounds 2-4, which run as one task per table across `table_parallelism()` + /// drivers. There is no phase-level wall for the aux stages on their own + /// any more; their CPU time shows up in `round1_sub`. pub rounds_2_4: Duration, /// Sub-op breakdown for Round 1 (main + aux LDE vs Merkle). pub round1_sub: Round1SubOps, @@ -319,11 +294,6 @@ static R1_MAIN_LDE_US: AtomicU64 = AtomicU64::new(0); static R1_MAIN_MERKLE_US: AtomicU64 = AtomicU64::new(0); static R1_AUX_LDE_US: AtomicU64 = AtomicU64::new(0); static R1_AUX_MERKLE_US: AtomicU64 = AtomicU64::new(0); -// Aux build / aux commit wall time per table, summed across the concurrent -// per-table drivers of the fused chain (so, like the sub-timers, this is a -// CPU-style total that can exceed the fused region's wall clock). -static AUX_BUILD_US: AtomicU64 = AtomicU64::new(0); -static AUX_COMMIT_US: AtomicU64 = AtomicU64::new(0); // Aux build (LogUp) sub-phases, CPU time accumulated across tables/chunks. static AUX_FINGERPRINT_US: AtomicU64 = AtomicU64::new(0); static AUX_INVERT_US: AtomicU64 = AtomicU64::new(0); @@ -372,20 +342,6 @@ pub fn accum_aux_accumulate(d: Duration) { AUX_ACCUM_US.fetch_add(d.as_micros() as u64, Ordering::Relaxed); } -/// One table's aux build and aux commit wall time, from its fused-chain driver. -pub fn accum_aux_phases(build: Duration, commit: Duration) { - AUX_BUILD_US.fetch_add(build.as_micros() as u64, Ordering::Relaxed); - AUX_COMMIT_US.fetch_add(commit.as_micros() as u64, Ordering::Relaxed); -} - -/// Drain the summed per-table aux build / aux commit times. -pub fn take_aux_phases() -> (Duration, Duration) { - ( - Duration::from_micros(AUX_BUILD_US.swap(0, Ordering::Relaxed)), - Duration::from_micros(AUX_COMMIT_US.swap(0, Ordering::Relaxed)), - ) -} - pub fn take_r1_sub() -> Round1SubOps { Round1SubOps { main_lde: Duration::from_micros(R1_MAIN_LDE_US.swap(0, Ordering::Relaxed)), @@ -412,8 +368,6 @@ pub fn reset_all() { R1_MAIN_MERKLE_US.store(0, Ordering::Relaxed); R1_AUX_LDE_US.store(0, Ordering::Relaxed); R1_AUX_MERKLE_US.store(0, Ordering::Relaxed); - AUX_BUILD_US.store(0, Ordering::Relaxed); - AUX_COMMIT_US.store(0, Ordering::Relaxed); AUX_FINGERPRINT_US.store(0, Ordering::Relaxed); AUX_INVERT_US.store(0, Ordering::Relaxed); AUX_TERM_US.store(0, Ordering::Relaxed); diff --git a/crypto/stark/src/prover.rs b/crypto/stark/src/prover.rs index 4199d0a80..4047458bc 100644 --- a/crypto/stark/src/prover.rs +++ b/crypto/stark/src/prover.rs @@ -698,17 +698,9 @@ fn run_admitted( .map(|_| std::sync::Mutex::new(None)) .collect(); let cursor = std::sync::atomic::AtomicUsize::new(0); - // Spans opened inside `task` run on these worker threads, and a fresh OS - // thread's span depth starts at 0 — which would record every per-table - // span as a root instead of a child of the phase that spawned it. Carry - // the spawning thread's depth across the scope boundary. - #[cfg(feature = "instruments")] - let parent_depth = crate::instruments::current_depth(); std::thread::scope(|scope| { for _ in 0..workers.max(1).min(order.len().max(1)) { scope.spawn(|| { - #[cfg(feature = "instruments")] - let _depth = crate::instruments::enter_depth(parent_depth); loop { let pos = cursor.fetch_add(1, std::sync::atomic::Ordering::Relaxed); if pos >= order.len() { @@ -1417,15 +1409,9 @@ pub trait IsStarkProver< } /// Reconstruct Round1 for every table, print the bus balance report, and - /// validate each trace. - /// - /// Cross-table (bus balance) checks need every table's commitments at once, - /// so under `debug-checks` the fused per-table chain is split into two - /// admitted passes and this runs once, on the main thread, between them. - /// - /// `pair_cells` is the same per-table slot vector the drivers use. Each - /// driver only ever locks its own index, so locking them here — after the - /// aux pass has joined and before the rounds pass starts — is uncontended. + /// validate each trace. Called once after every table's aux commit, which + /// under `debug-checks` means between the fused chain's two admitted + /// passes — cross-table bus balance needs all the commitments at once. #[cfg(feature = "debug-checks")] fn run_debug_checks( pair_cells: &[std::sync::Mutex>], @@ -3158,9 +3144,10 @@ pub trait IsStarkProver< let mut main_commits: Vec> = Vec::with_capacity(num_airs); let mut main_ldes: Vec<(Vec>, usize)> = Vec::with_capacity(num_airs); // Optional device-side LDE handle per table, populated only when the - // R1 fused GPU pipeline produced one. Indexed by table, and moved into - // the per-table `gpu_main_cells` slots below so each handle stays - // paired with its table across the fused chain. + // R1 fused GPU pipeline produced one. Pairing is by index: this vector + // is moved into the per-table `gpu_main_cells` mutex slots below, and + // each driver only ever touches `gpu_main_cells[idx]` for its own + // table. (It used to ride a zip chain through the old phase D.) #[cfg(feature = "cuda")] let mut main_gpu_handles: Vec> = Vec::with_capacity(num_airs); @@ -3359,9 +3346,7 @@ pub trait IsStarkProver< let twiddles = &twiddle_caches[idx]; #[cfg(feature = "instruments")] - let __sp = crate::instruments::span("r1_aux_build"); - #[cfg(feature = "instruments")] - let t_aux_build = Instant::now(); + let __sp = crate::instruments::span("r1_aux_build_table"); let bus_public_inputs = if air.has_aux_trace() { air.build_auxiliary_trace(*trace, &lookup_challenges) } else { @@ -3385,14 +3370,10 @@ pub trait IsStarkProver< .map_err(|e| ProvingError::DiskSpill(format!("aux trace: {e}")))?; } #[cfg(feature = "instruments")] - let aux_build_dur = t_aux_build.elapsed(); - #[cfg(feature = "instruments")] drop(__sp); #[cfg(feature = "instruments")] - let __sp = crate::instruments::span("r1_aux_commit"); - #[cfg(feature = "instruments")] - let t_aux_commit = Instant::now(); + let __sp = crate::instruments::span("r1_aux_commit_table"); let aux_full: AuxResult = (|| -> Result, ProvingError> { if air.has_aux_trace() { @@ -3540,8 +3521,6 @@ pub trait IsStarkProver< transcript_cells[idx].lock().unwrap().append_bytes(&c.root); } #[cfg(feature = "instruments")] - crate::instruments::accum_aux_phases(aux_build_dur, t_aux_commit.elapsed()); - #[cfg(feature = "instruments")] drop(__sp); #[cfg(feature = "cuda")] @@ -3593,7 +3572,7 @@ pub trait IsStarkProver< let domain = &domains[idx]; #[cfg(feature = "instruments")] - let __sp = crate::instruments::span("rounds_2to4"); + let __sp = crate::instruments::span("rounds_2to4_table"); #[cfg(feature = "instruments")] let table_start = Instant::now(); @@ -3629,6 +3608,15 @@ pub trait IsStarkProver< #[cfg(feature = "instruments")] let phase_start = Instant::now(); + // Phase-level span for the whole fused region, opened here on the + // calling thread. The per-table spans inside it (`*_table`) are one + // instance per table and `phase_table.py` sums same-label spans, so + // they cannot stand in for the phase wall: their sum runs up to `k` + // times over it. This is also the span `LAMBDA_VM_NSYS_CAPTURE_SPAN` + // brackets, which needs exactly one instance to start/stop the + // profiler around. + #[cfg(feature = "instruments")] + let __sp = crate::instruments::span("rounds_2to4"); let peak_order = heaviest_first(&peak_estimates); @@ -3680,20 +3668,16 @@ pub trait IsStarkProver< proofs.push(result.expect("run_admitted fills every slot")?); } #[cfg(feature = "instruments")] + drop(__sp); + #[cfg(feature = "instruments")] let table_timings = table_timings_mx.into_inner().unwrap(); #[cfg(feature = "instruments")] { - // Aux build/commit are no longer phases of their own: each table's - // driver runs them inside the fused region, so these are sums over - // concurrent drivers and are a subset of `rounds_2_4`, not addends. - let (aux_build_elapsed, aux_commit_elapsed) = crate::instruments::take_aux_phases(); // Store timing data for the top-level report in prove_with_options. // Uses a thread-local to avoid changing multi_prove's return type. crate::instruments::store(crate::instruments::MultiProveTiming { prepass: prepass_elapsed, main_commits: main_commits_elapsed, - aux_build: aux_build_elapsed, - aux_commit: aux_commit_elapsed, rounds_2_4: phase_start.elapsed(), round1_sub: crate::instruments::take_r1_sub(), table_timings, @@ -4012,198 +3996,3 @@ fn print_bus_balance_report( } } } - -/// Scheduling primitives only. These are free functions over `&[u64]` with no -/// AIR, field or device dependency, so they are testable without a GPU — which -/// matters because CI never exercises them concurrently: `ubuntu-latest` has -/// 2-4 vCPU, so `table_parallelism()` floors to 1, and on non-cuda builds the -/// budget is `u64::MAX`, which makes `VramGate` inert. -#[cfg(test)] -mod scheduler_tests { - use super::{VramGate, heaviest_first, run_admitted}; - use std::sync::atomic::{AtomicUsize, Ordering}; - use std::time::Duration; - - /// Bound on how long a correct implementation may take to wake a waiter. - /// Only a failure deadline — never used to sequence the test. - const WAKE_DEADLINE: Duration = Duration::from_secs(10); - - #[test] - fn heaviest_first_is_a_descending_permutation() { - let empty: [u64; 0] = []; - assert!(heaviest_first(&empty).is_empty()); - assert_eq!(heaviest_first(&[3, 1, 2]), vec![0, 2, 1]); - - let estimates = [7u64, 0, 7, 3, 100, 1]; - let order = heaviest_first(&estimates); - let mut seen = order.clone(); - seen.sort_unstable(); - assert_eq!( - seen, - (0..estimates.len()).collect::>(), - "must be a permutation of 0..n" - ); - for w in order.windows(2) { - assert!( - estimates[w[0]] >= estimates[w[1]], - "must be descending by estimate, got {order:?}" - ); - } - } - - #[test] - fn heaviest_first_breaks_ties_by_index() { - // `sort_by_key` is stable, so equal estimates keep ascending index - // order: the admission order is a pure function of the estimates, and - // does not vary run to run. - assert_eq!(heaviest_first(&[5, 5, 5]), vec![0, 1, 2]); - assert_eq!(heaviest_first(&[1, 5, 5, 1]), vec![1, 2, 0, 3]); - } - - #[test] - fn run_admitted_fills_every_slot_exactly_once() { - // Includes the degenerate shapes: no work, one worker, more workers - // than tables, and `workers == 0` (clamped to 1 inside). - for (n, workers) in [(0, 4), (1, 1), (1, 8), (5, 0), (5, 1), (5, 8), (9, 4)] { - let estimates: Vec = (0..n).map(|i| i as u64 + 1).collect(); - let runs: Vec = (0..n).map(|_| AtomicUsize::new(0)).collect(); - let gate = VramGate::new(u64::MAX); - let out = run_admitted( - &heaviest_first(&estimates), - &estimates, - &gate, - workers, - |idx| { - runs[idx].fetch_add(1, Ordering::SeqCst); - idx * 10 - }, - ); - assert_eq!(out.len(), n, "one slot per table (n={n})"); - for i in 0..n { - assert_eq!( - runs[i].load(Ordering::SeqCst), - 1, - "table {i} ran exactly once (n={n}, workers={workers})" - ); - assert_eq!( - out[i], - Some(i * 10), - "slot {i} holds its own result (n={n}, workers={workers})" - ); - } - assert_eq!(*gate.used.lock().unwrap(), 0, "all permits released"); - } - } - - #[test] - fn concurrent_admissions_stay_under_budget() { - const BUDGET: u64 = 100; - const EACH: u64 = 40; // 2 fit, 3 do not - let estimates = vec![EACH; 16]; - let gate = VramGate::new(BUDGET); - let in_flight = AtomicUsize::new(0); - let max_in_flight = AtomicUsize::new(0); - run_admitted(&heaviest_first(&estimates), &estimates, &gate, 8, |_| { - let now = in_flight.fetch_add(1, Ordering::SeqCst) + 1; - max_in_flight.fetch_max(now, Ordering::SeqCst); - // Read under a held permit: the gate's own counter must never - // exceed the budget while anything is admitted. - assert!( - *gate.used.lock().unwrap() <= BUDGET, - "admitted bytes exceeded the budget" - ); - in_flight.fetch_sub(1, Ordering::SeqCst); - }); - assert!( - max_in_flight.load(Ordering::SeqCst) <= (BUDGET / EACH) as usize, - "more tables were in flight than the budget allows" - ); - assert_eq!(*gate.used.lock().unwrap(), 0); - } - - #[test] - fn oversized_request_is_admitted_alone_and_wakes_waiters() { - // A table bigger than the whole budget must still prove: it is admitted - // when nothing else holds bytes, rather than deadlocking forever. - let gate = VramGate::new(10); - let big = gate.acquire(100); - assert_eq!( - *gate.used.lock().unwrap(), - 100, - "oversized request admitted alone" - ); - - let (ready_tx, ready_rx) = std::sync::mpsc::channel(); - let (done_tx, done_rx) = std::sync::mpsc::channel(); - std::thread::scope(|s| { - s.spawn(|| { - ready_tx.send(()).unwrap(); - let permit = gate.acquire(5); - done_tx.send(()).unwrap(); - drop(permit); - }); - ready_rx.recv().unwrap(); - drop(big); - assert!( - done_rx.recv_timeout(WAKE_DEADLINE).is_ok(), - "dropping a permit must wake a waiter" - ); - }); - assert_eq!( - *gate.used.lock().unwrap(), - 0, - "permits release their bytes on drop" - ); - } - - /// Guards the instruments span tree: a driver thread starts at span depth - /// 0, so without the seeding in `run_admitted` every per-table span is - /// recorded as a root sibling of `prove_total` and the "% of total" column - /// stops meaning anything. Reads the depth directly instead of the global - /// span timeline, which other tests in this binary also write to. - #[cfg(feature = "instruments")] - #[test] - fn run_admitted_seeds_worker_span_depth() { - const PARENT_DEPTH: u16 = 3; - let outer = crate::instruments::enter_depth(PARENT_DEPTH); - let n = 6; - let estimates = vec![1u64; n]; - let gate = VramGate::new(u64::MAX); - let seen = run_admitted(&heaviest_first(&estimates), &estimates, &gate, 4, |_| { - crate::instruments::current_depth() - }); - for (i, depth) in seen.iter().enumerate() { - assert_eq!( - *depth, - Some(PARENT_DEPTH), - "table {i}'s driver must inherit the spawning thread's span depth" - ); - } - drop(outer); - assert_eq!( - crate::instruments::current_depth(), - 0, - "the calling thread's depth is restored" - ); - } - - #[test] - fn max_budget_gate_never_blocks() { - // The non-cuda / unqueryable-VRAM configuration. Two acquires that - // saturate `u64` must both be admitted. - let gate = VramGate::new(u64::MAX); - let held = gate.acquire(u64::MAX / 2); - let (tx, rx) = std::sync::mpsc::channel(); - std::thread::scope(|s| { - s.spawn(|| { - let _permit = gate.acquire(u64::MAX / 2 + 1000); - tx.send(()).unwrap(); - }); - assert!( - rx.recv_timeout(WAKE_DEADLINE).is_ok(), - "a u64::MAX budget must never block an acquire" - ); - }); - drop(held); - } -} diff --git a/prover/src/instruments.rs b/prover/src/instruments.rs index 4663f092c..f15a8a824 100644 --- a/prover/src/instruments.rs +++ b/prover/src/instruments.rs @@ -71,11 +71,12 @@ pub fn print_report( row_top("AIR construction", air_construction, total); if let Some(ref mp) = mp { - // Round 1's main commits are the last phase-level barrier: every main - // root must be in the transcript before the shared LogUp challenges are - // sampled. Aux build, aux commit and rounds 2-4 are fused per table, so - // they are reported under one wall-clock parent below, with their - // components as concurrent (summed-over-drivers) sub-rows. + // Only two wall-clock phases are left. Round 1's main commits are the + // last phase-wide barrier (every main root must be absorbed before the + // shared LogUp challenges are sampled); everything after it — aux + // build, aux commit, rounds 2-4 — runs as one fused task per table, so + // those three have no wall-clock phase of their own to report. Their + // CPU time is listed under the fused phase instead. row_top("Pre-pass (domains/twiddles)", mp.prepass, total); row_top("Round 1 (main trace commits)", mp.main_commits, total); row_sub( @@ -89,14 +90,11 @@ pub fn print_report( total, ); row_top( - "Rounds 2\u{2013}4 (aux build+commit fused)", + "Rounds 2\u{2013}4 (aux build+commit fused in)", mp.rounds_2_4, total, ); - eprintln!( - " \u{2500}\u{2500} below: summed across concurrent drivers \u{2500}\u{2500}" - ); - row_sub(" Aux trace build", mp.aux_build, total); + eprintln!(" \u{2500}\u{2500} aux build (CPU, summed over tables) \u{2500}\u{2500}"); row_sub( " LogUp fingerprint (CPU)", mp.round1_sub.aux_fingerprint, @@ -117,7 +115,7 @@ pub fn print_report( mp.round1_sub.aux_accumulate, total, ); - row_sub(" Aux trace commit", mp.aux_commit, total); + eprintln!(" \u{2500}\u{2500} aux commit (CPU, summed over tables) \u{2500}\u{2500}"); row_sub( " Aux LDE (fused GPU: LDE+Keccak+Merkle / CPU: LDE only)", mp.round1_sub.aux_lde, @@ -128,7 +126,7 @@ pub fn print_report( mp.round1_sub.aux_merkle, total, ); - eprintln!(" \u{2500}\u{2500} per table (R2\u{2013}4) \u{2500}\u{2500}"); + eprintln!(" \u{2500}\u{2500} per table (R2\u{2013}4 wall) \u{2500}\u{2500}"); // Merge split tables: MEMW[0..4] → MEMW x5 let mut merged: BTreeMap = BTreeMap::new(); diff --git a/scripts/bench_prover_scaling.sh b/scripts/bench_prover_scaling.sh index 520d13492..88824729c 100755 --- a/scripts/bench_prover_scaling.sh +++ b/scripts/bench_prover_scaling.sh @@ -74,17 +74,12 @@ parse_run() { /^ Trace build/ { v = secs(); if (v) print "t_trace_build=" v } /^ AIR construction/ { v = secs(); if (v) print "t_air=" v } /^ Pre-pass/ { v = secs(); if (v) print "t_prepass=" v } - # "Round 1 (main trace commits)" is the whole of round 1 now; aux build and - # aux commit are fused into the per-table region and reported under - # "Rounds 2-4" as sums over the concurrent drivers, so they can exceed it. /^ Round 1 / { v = secs(); if (v) print "t_round1=" v } - /Aux trace build/ { v = secs(); if (v) print "t_aux_build=" v } - /Aux trace commit/ { v = secs(); if (v) print "t_aux_commit=" v } /Rounds 2/ { v = secs(); if (v) print "t_rounds24=" v } - /Main LDE/ { v = secs(); if (v) print "t_main_lde=" v } - /Aux LDE/ { v = secs(); if (v) print "t_aux_lde=" v } - /Main commit \(Merkle/ { v = secs(); if (v) print "t_main_merkle=" v } - /Aux commit \(Merkle/ { v = secs(); if (v) print "t_aux_merkle=" v } + /Main expand_columns_to_lde/{ v = secs(); if (v) print "t_main_lde=" v } + /Aux expand_columns_to_lde/ { v = secs(); if (v) print "t_aux_lde=" v } + /Main commit \(Merkle\)/ { v = secs(); if (v) print "t_main_merkle=" v } + /Aux commit \(Merkle\)/ { v = secs(); if (v) print "t_aux_merkle=" v } /^ Total FFT/ { v = secs(); if (v) print "t_total_fft=" v } /^ Total Merkle/ { v = secs(); if (v) print "t_total_merkle="v } /^ TOTAL / { v = secs(); if (v) print "t_total=" v } @@ -92,13 +87,13 @@ parse_run() { /After trace build/ { print "h_trace_build=" $(NF-1) } /After AIR/ { print "h_air=" $(NF-1) } /After pool alloc/ { print "h_pool_alloc=" $(NF-1) } - # NOTE: the "After aux build" / "After aux commit" heap snapshots were - # removed when aux build/commit were fused into the per-table scheduler -- - # with k tables in flight there is no single moment at which either has - # finished, so the snapshot had no meaning. "After main commits" is the - # last phase-wide barrier, and "Peak heap" still guards the region below - # it, so the heap-growth regressions keep coverage of the fused region. /After main commits/ { print "h_main_commits=" $(NF-1) } + # No "After aux build"/"After aux commit" rows: aux build and aux commit are + # fused into the per-table scheduler, so with k tables in flight there is no + # single moment at which either has finished, and the prover no longer takes + # those snapshots. "Aux trace build"/"Aux trace commit" timing rows are gone + # for the same reason. "After main commits" and "Peak heap" still bracket + # the fused region. ' "$stderr" grep -o 'Peak heap: [0-9]*' "$stdout" | awk '{print "peak=" $3}' @@ -190,14 +185,12 @@ print_row "Execute" t_execute s print_row "Trace build" t_trace_build s print_row "AIR construction" t_air s print_row "Pre-pass" t_prepass s -print_row "Round 1 (main commits)" t_round1 s +print_row "Round 1" t_round1 s print_row " Main LDE" t_main_lde s print_row " Main Merkle" t_main_merkle s -print_row "Rounds 2-4 (fused)" t_rounds24 s -print_row " Aux trace build" t_aux_build s -print_row " Aux trace commit" t_aux_commit s print_row " Aux LDE" t_aux_lde s print_row " Aux Merkle" t_aux_merkle s +print_row "Rounds 2-4" t_rounds24 s print_row "Total FFT (all rounds)" t_total_fft s print_row "Total Merkle" t_total_merkle s print_row "TOTAL" t_total s @@ -211,8 +204,6 @@ if [[ "$MODE" == "heap" ]]; then print_row "After AIR construction" h_air mb print_row "After pool alloc" h_pool_alloc mb print_row "After main commits" h_main_commits mb - # "After aux build" / "After aux commit" intentionally absent: see the NOTE - # in parse_run. Peak heap covers the fused region they used to bracket. print_row "Peak heap" peak mb fi @@ -275,9 +266,6 @@ if [[ "$MODE" == "heap" ]]; then regress "After AIR construction" h_air mb regress "After pool alloc" h_pool_alloc mb regress "After main commits" h_main_commits mb - # The "After aux build" / "After aux commit" heap-growth guards were dropped - # with their snapshots (see the NOTE in parse_run). "Peak heap" is the - # remaining regression guard over the fused per-table region. regress "Peak heap" peak mb fi