fix(instruments): restore the rounds 2-4 phase wall, make the prover timing report honest - #895
Merged
ColoCarletti merged 6 commits intoAug 3, 2026
Conversation
…ng depth Supersedes the approach in #893. Adversarial review showed the depth field was never the defect. `phase_table.py:121` takes its denominator from `max(s["wall_ns"] for _, s in pathed)` — the longest span, not the root of the ancestor stack — so depth-0 records never broke the "% of total" column, and `scripts/profiling/README.md:77` was accurate all along. `prover/src/continuation.rs` has also recorded spans from worker threads since long before this branch (:1146, :1205, :1299, :1328, :1415), with the comment at :1051-1053 saying so. Seeding worker depth was therefore work that bought nothing, and it would have left overlapping siblings looking like a clean tree — a subtler lie. Removed (`instruments::current_depth` / `enter_depth` / `DepthGuard` and the seeding in `run_admitted`). The real defect is label collision under summing. `phase_table.py:129` does `e["wall_ns"] += s["wall_ns"]`, so spans sharing a label are summed. On origin/main `rounds_2to4` was ONE span around the chunk loop (prover.rs:3503) and measured the phase; this branch made it one span per table, so the row became the sum of N concurrent tables — up to k times the real wall, able to exceed 100% — and no span measured the phase at all. `r1_aux_build` and `r1_aux_commit` were phase spans on main too (:3143, :3225). So: reopen `rounds_2to4` on the calling thread around the whole fused region, and rename the per-table spans `*_table` so a per-instance label can never be summed into a phase row. This also repairs `LAMBDA_VM_NSYS_CAPTURE_SPAN=rounds_2to4` (README.md:115), which with the label on the per-table span had N driver threads calling cuProfilerStart/Stop, the first to finish ending the capture. The report follows, and is compile-coupled to the same change. #893 added per-driver aux timers to fill the zeroed `aux_build` / `aux_commit` buckets; the fused stages have no wall-clock phase of their own any more, so reporting one invites exactly the misreading the label summing caused. Both timers and both `MultiProveTiming` fields are gone. The report now shows only the two phases that remain — "Round 1 (main trace commits)" and "Rounds 2-4 (aux build+commit fused in)" — with the aux CPU-time rows grouped under the fused phase behind headers stating they are summed over tables. That still fixes what #893 set out to fix: no row prints a fabricated 0.00s over live children, and "Round 1" no longer duplicates its own child. Verified on fib_iterative_1M: phase spans sum to their parent (r1_prepass 0.148 + r1_main_commit 2.493 + rounds_2to4 8.943 = 11.584 vs proving 11.585).
#893 also repointed four timing regexes in `scripts/bench_prover_scaling.sh` that had gone stale earlier and independently of this branch. That is unrelated churn in a script with no Makefile target and no workflow referencing it, so it is reverted. What stays removed: the two dead heap rows and their `regress` calls (their `snap()` sources no longer exist and cannot be recreated with k tables in flight) and the two aux timing rows, which follow the report. The NOTE explaining why is kept. Nothing here was failing silently, contrary to the original review note: `regress` prints "(insufficient data)" for a missing key and `print_row` prints "-".
MauroToscano
force-pushed
the
gpu-opt-877-review-fixes-v2
branch
from
August 3, 2026 20:57
92a5ea1 to
00f4889
Compare
Replaces the `VramGate` / `run_admitted` / `heaviest_first` unit tests added in #893 (removed in the previous commit). Every assertion they made was guaranteed by construction, already covered end to end, or unreachable from the call sites: `heaviest_first` is `(0..n).collect()` plus `sort_by_key`; a slot mixup in `run_admitted` is schedule independent, so it trips one of the three `.expect("run_admitted fills every slot")` sites or fails `multi_verify` on every PR today; `order.len() == 0` and `workers > order.len()` cannot happen, since `k` is `.max(1)`'d and `order` is always a full permutation. The one property with teeth — an over-budget table admitted alone — HANGS rather than fails if it regresses, which on an 8-10 minute shard burns to the job timeout unless wrapped in a watchdog. That was ~50 lines of permanent maintenance against approximately zero risk. The actual PR-time gap is that the scheduler never runs concurrently. `table_parallelism()` defaults to `(cores / 3).max(1)` and every job in this workflow is `runs-on: ubuntu-latest` with no larger-runner label, so PR CI proves with exactly one driver thread; `VramGate` is additionally inert on non-cuda builds, where `vram_budget` is `u64::MAX` and `acquire`'s condition always holds. `TABLE_PARALLELISM: 6` on shard 1 only is the smallest change that puts several real table closures in flight at once. The other three shards keep default-k coverage — the expression yields an empty string there, which fails to parse and falls back to the default. `prover/Cargo.toml:8` is `default = ["parallel"]`, so the env arm is the live one. Not a substitute for GPU coverage: `gpu-tests.yml` on merge_group rents a >=16-core RTX 5090, taking the cuda arm (`cores * 2 / 3`) with a finite VRAM budget, so both the concurrent and blocking paths already run before merge. This closes the PR-time gap only.
"Round 1 (main trace commits)" is lowercase, so `/Main trace commits/` stopped matching, and the row would have printed "-". It is also now redundant: with the aux stages fused out of round 1, `t_main_commits` and `t_round1` are the same number by construction.
MauroToscano
force-pushed
the
gpu-opt-877-review-fixes-v2
branch
from
August 3, 2026 21:04
86706a5 to
f600bad
Compare
ColoCarletti
approved these changes
Aug 3, 2026
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Review fixes for #877, targeting
gpu-opt-table-schedulerso they land with it. Rebuilt onto the current branch head (5d452853) — merges clean.Context on why there are two PRs: #893 was an earlier version of these fixes that merged at 20:42 with reasoning that later turned out to be wrong. This PR keeps what was right, reverts what wasn't, and corrects two false statements #893 introduced. Net effect of #893 + this PR is the state below.
Adversarial verification killed several of my own findings along the way; what's left is what survived.
1. Restore the rounds 2-4 phase wall
scripts/profiling/phase_table.py:129doese["wall_ns"] += s["wall_ns"]— spans sharing a label are summed. Onmain,rounds_2to4was one span wrapping the chunk loop, giving a true phase wall. #877 made it one span per table, so the row now reports the sum over N concurrent tables — up to k× the real wall, and it can print >100%. Worse, nothing spanned the fused region at all, so the genuine rounds-2-4 wall time was absent from the timeline.Fix: one span on the caller thread wrapping the fused
run_admitted, plus per-table spans renamed to*_tableso they no longer collide with a phase label.r1_aux_build/r1_aux_commithad the identical defect (also phase-level on main, also per-table now) and are renamed too.Evidence it works — phase spans now sum to their parent:
Side effect worth knowing: this also fixes
LAMBDA_VM_NSYS_CAPTURE_SPAN=rounds_2to4, which was genuinely broken — N driver threads each calledcuProfilerStart/Stop, so the first table to finish killed the capture while the rest ran.scripts/profiling/README.md:115andnsys_phase_busy.py:243both name that label and now stay valid unedited.What I got wrong here, for the record: I originally claimed the depth-0 spans broke
phase_table.py's "% of total" column. They don't —:121computes the denominator asmax(wall_ns), not the root of the ancestor stack. I also claimed #877 corrupted a clean tree;continuation.rson main already opens five spans on worker threads at depth 0, and its own comment at:1051-1053says so. Soinstruments.rs:5-14was already inaccurate before #877. #893's depth-plumbing (current_depth/enter_depth/DepthGuard) was built on that wrong premise and is removed here. The module doc is rewritten to describe actual behavior, including the label-summing hazard.2. Make the prover timing report honest
prover/src/instruments.rs:74computesround1 = main_commits + aux_build + aux_commit, butprover.rs:3253/:3605hardcode the two aux buckets toDuration::ZERO. So "Round 1" and " Main trace commits" print the identical number, Round 1 understates by the whole aux stage, and Rounds 2-4 silently absorbs it. The two zero rows (:89,:110) also sat over live children, sinceaccum_r1_auxstill fires atprover.rs:3410/3449/3497.This is in the terminal report every
instrumentsuser sees. Fixed with honest labels — the fused stages genuinely can't be timed separately any more, so the timers aren't resurrected.3. Stale docs
The orphaned
plan_table_chunksdoc was left contiguous withVramGate's, so that struct's rustdoc opened by describing a deleted function returning(start, end)ranges. Plus: the "Split into two passes" block contradicted the FUSED comment two lines below it;table_parallelism's header still claimedcores/3; four chunk/Phase-D comments described removed structure; and Phase D had 7 references with zero definitions after its banner was deleted while A/B/C kept theirs.The one a reviewer would actually be misled by:
3134-3135and3268asserted pairing happens via "Phase D's zip chain", when it's now index-keyed mutex cells (gpu_main_cells).Also corrected the
Ldedoc, which understated the PR's own win: it claimed all N tables' LDE columns are live at once. Only the main LDEs are — each aux LDE is created inaux_stageand consumed by value inrounds_stage, so at mostkcoexist (all N underdebug-checks, where the two-pass split holds them).4. One CI line
TABLE_PARALLELISM: 6on one prover shard.(cores/3).max(1) == 1for any runner under 6 cores, and every job isubuntu-latest, so PR CI was running the scheduler with exactly one driver thread. This is the only change that puts two real table closures concurrently in flight on a PR.It passed — shard 1 green at 7m59s, no OOM. If it ever gets tight, dropping to 2 still buys the concurrency.
Note: the concurrent and blocking paths do run pre-merge —
gpu-testsonmerge_grouprents a ≥16-core 5090, hits the cuda arm at k≈10 with a finite VRAM budget. The gap was PR-time only.5. Bench script
scripts/bench_prover_scaling.shparsed and ran heap-growthregresson two snapshots #877 deleted. It's loud rather than silent ((insufficient data)/-) and the script is unwired — no Makefile target, no workflow — so this is minimal: dead rows dropped, and four regexes #893 had fixed are kept fixed rather than reverted.Deliberately not fixed
prover/src/auto_storage.rsis out of this diff — #877 never touched it. Thetable_parallelism→auto_storage::decide()coupling is real, but my "doubles the transient term" framing was wrong:peak_bytessorts descending and takes the topk, so each extra slot adds the next smallest table. Sub-linear, not proportional.No scheduler unit tests. Every assertion I considered is guaranteed by construction, already covered by the end-to-end
multi_prove+multi_verifysuite, or unreachable from the call sites — and the one with teeth (*used == 0, oversized-runs-alone) would hang rather than fail, which on an 8-10 minute shard burns to the job timeout. The CI line above retires more risk for one line.Also untouched:
TAIL_MAX_PAIRS, the FRI/keccak/NTT kernels,crypto/math-cuda, and any scheduler behavior — the fused chain, gate semantics, heaviest-first, and thecores*2/3constant are all unchanged.Verified
cargo fmt --all --check;cargo check -p stark× {default, instruments, debug-checks, disk-spill, cuda, all-four-combined};cargo check -p lambda-vm-prover --features instruments,cuda,debug-checks,disk-spill;cargo test --release -p stark --lib→ 202 passed; clippy clean in every file touched. Re-verified after merging the current branch head.Not GPU-verified — no CUDA on the machine these were written on, and
gpu-testsdoesn't run on PRs.Two open questions for you, not fixes
cores * 2 / 3. The justification is one parenthetical ("swept flat at ~2/3 of the cores on a 16-core/RTX 5090 box") with no data in the repo. Tying k to host cores sits oddly with the stated premise that in-flight tables "mostly sit in GPU waits" — if they're waiting on the device they aren't consuming cores, so the same 5090 would admit 42 tables on a 64-core host and 5 on an 8-core one. NoteVramGatealready bounds memory independently, so k's only remaining job on a GPU build is latency hiding. Worth publishing the sweep, or deriving k from a device quantity.5d452853's pinned-staging note. Same shape: the measurement behind "per-driver slots cost more than the shared mutex" isn't in the repo. Worth attaching, since a bot flagged the slot-0 collapse as High and the code comment is currently the only rebuttal.One residue this PR can't reach:
8f91e7c7's squash-merge message bakes in the refuted "% of total" reasoning. If #877 squash-merges to main a fresh message is written and it disappears; if history is preserved, that paragraph lands. Not worth rewriting merged history — flagging so you can decide.