The 94.4-Second Verdict: How One Benchmark Confirmed a 5.7-Second Mistake and Isolated the Next Culprit

Introduction

In performance engineering, the most valuable data point is often the one that disproves a hypothesis. Message [msg 983] captures such a moment: a single benchmark run that simultaneously confirmed a costly mistake and revealed the next target for optimization. The message shows the assistant running a 32 GiB PoRep proof through the cuzk pipelined proving engine after reverting the B1 (cudaHostRegister) optimization, yielding a total wall time of 94.4 seconds — a 7-second improvement over the 101.3-second run that included B1, but still 5.5 seconds above the established 88.9-second baseline.

This message is the fulcrum of a systematic regression diagnosis. It is not merely a benchmark result; it is the experimental confirmation that pins the blame on two distinct sources of slowdown, enabling the team to proceed with surgical precision rather than guesswork.

The Message

The assistant executes a memory monitor and then runs the benchmark:

bash /tmp/cuzk-memmon.sh /tmp/cuzk-phase4-mem3.csv 1 > /dev/null 2>&1 &

time /home/theuser/curio/extern/cuzk/target/release/cuzk-bench \
  --addr http://127.0.0.1:9821 \
  single \
  --type porep \
  --c1 /data/32gbench/c1.json 2>&1 | tee /tmp/cuzk-phase4-bench3.log

=== Proof Result ===
status:    COMPLETED
job_id:    6b128bcc-64db-4a82-ab45-f072b9901be7
timings:   total=94423 ms (queue=251 ms, srs=0 ms, synth=60338 ms, gpu=33833 ms)
wall time: 94745 ms
proof:     1920 bytes (hex: b28ec05597...)

The output is deceptively simple. A single JSON-like result block containing five timing fields — total, queue, srs, synth, and gpu — plus a wall time and a proof hex string. But behind these numbers lies a multi-hour diagnostic odyssey involving CUDA instrumentation, build-system archaeology, and disciplined hypothesis testing.

The Context: A Regression That Demanded Rigor

To understand why this particular message matters, one must appreciate the journey that led to it. The cuzk project had successfully implemented Phases 0 through 3 of a pipelined Groth16 proving engine for Filecoin PoRep proofs, establishing a solid baseline of 88.9 seconds for a single 32 GiB sector proof. Phase 4 introduced a suite of compute-level optimizations drawn from a detailed optimization proposal document. Five changes were implemented in parallel:

• A1 (SmallVec): Replace standard Vec with SmallVec in the linear combination indexer to reduce heap allocations during synthesis
• A2 (Pre-sizing): Pre-allocate vectors with known capacities to avoid reallocation overhead
• A4 (Parallel B_G2): Parallelize the B_G2 multi-scalar multiplication across CPU cores
• B1 (cudaHostRegister): Pin host memory pages to enable faster GPU DMA transfers
• D4 (Per-MSM window tuning): Tune MSM window sizes per operation for optimal GPU throughput When these five changes were first applied together, the proof time regressed from 88.9 seconds to 106 seconds — a 19% slowdown. This was a crisis: optimizations intended to improve performance had made things substantially worse. The assistant's response was methodical: add detailed CUDA timing instrumentation (CUZK_TIMING printf's), fix a stdout buffering issue that was hiding the instrumentation output, and collect a phase-level breakdown. That first breakdown (message [msg 964]) was revelatory. It showed: | Phase | Time | Component | |---|---|---| | pin_abc (B1) | 5,733 ms | cudaHostRegister on ~125 GB | | prep_msm | 1,722 ms | Classification + popcount scan | | ntt_msm_h | 21,417 ms | GPU NTT + H-polynomial MSMs | | batch_add | 1,446 ms | Split MSM batch addition | | tail_msm | 1,259 ms | L, A, B_G1 tail MSMs | | b_g2_msm | 22,849 ms | B_G2 MSMs (CPU, parallel) | The B1 optimization — which was supposed to cost an estimated 150–300 milliseconds — was actually costing 5.7 seconds. The proposal had dramatically underestimated the overhead of mlock-ing 125 gigabytes of host memory, which requires the operating system to touch every page, triggering TLB shootdowns, page walks, and massive cache pollution.

What This Message Confirms

The benchmark in message [msg 983] was the first run after reverting B1. The results speak clearly:

1. B1 was the dominant GPU-phase regression: GPU time dropped from 40,087 ms (with B1) to 33,833 ms (without B1). That's a saving of 6.25 seconds, closely matching the 5.7 seconds that pin_abc alone consumed (the extra ~0.5 seconds likely came from the unpin overhead at the end). The GPU phase is now back to near-baseline levels (33.8s vs 34.0s baseline).
2. Synthesis remains the problem: Synthesis time is 60,338 ms, compared to the baseline of ~54,700 ms. That's a 5.6-second gap — almost exactly matching the total 5.5-second regression from the 88.9s baseline to the current 94.4s. Since A2 (pre-sizing) was already fully reverted in the previous round (messages [msg 945] through [msg 948]), the remaining synthesis regression must be caused by A1 (SmallVec).
3. Total proof time is now 94.4 seconds: This is a 7% regression from the 88.9s baseline, entirely attributable to synthesis. The GPU path is essentially neutral.

The Thinking Process Visible in the Reasoning

The assistant's reasoning, visible in the analysis that follows this message (message [msg 968] and subsequent messages), demonstrates several hallmarks of disciplined performance engineering:

Hypothesis-driven experimentation: Rather than blindly reverting all changes, the assistant used instrumentation to isolate the largest contributor (B1, 5.7s), reverted only that change, and re-tested. This preserves the other optimizations (A1, A4, D4) that may still provide value once the synthesis regression is fixed.

Waterfall analysis: The assistant constructs a visual waterfall diagram of the GPU phases, showing how pin_abc (5.7s) and prep_msm (1.7s) precede the main GPU compute (21.4s NTT + 1.4s batch_add + 1.3s tail), while b_g2_msm (22.8s) runs in parallel on the CPU. This visualization reveals that B_G2 MSM finishes before the GPU compute — meaning A4's parallelization has successfully removed B_G2 from the critical path.

Awareness of measurement uncertainty: The assistant notes that the synthesis regression "could be noise or a system load issue" and plans an A/B test with A1 reverted to confirm. This intellectual honesty — acknowledging that a single data point might be confounded — is crucial for reliable performance work.

Build system archaeology: The assistant had to fight with the build system to ensure CUDA files were recompiled after each edit. Messages [msg 945] through [msg 955] show a detailed investigation of build.rs, rerun-if-changed directives, and the location of .a archive files. This is the unglamorous but essential work of ensuring that measurements reflect the intended code.

Assumptions and Their Validity

Several assumptions underpin this message and the diagnostic process:

Assumption: The CUDA timing instrumentation is accurate. The assistant assumed that CUZK_TIMING printf's using fprintf(stderr) with fflush(stderr) would produce reliable timing data. This assumption was validated by the consistency between the GPU timing sum (~31.5s internal) and the bellperson wrapper time (~32.0s), with the difference plausibly explained by overhead.

Assumption: B1's cost is purely the pin/unpin overhead. The assistant assumed that reverting B1 would not affect the GPU compute times (NTT, MSM, batch_add). The data supports this: GPU internal times after reverting B1 are consistent with the previous run's GPU compute portion.

Assumption: The baseline is stable. The 88.9-second baseline was established through multiple runs. The assistant implicitly trusts that the system state (CPU frequency, memory bandwidth, GPU temperature) is comparable. This is reasonable given that the tests are run back-to-back on the same hardware.

Assumption: A1 (SmallVec) is the sole cause of the synthesis regression. Since A2 was reverted and A4/D4 don't affect synthesis, SmallVec is the prime suspect. However, the assistant correctly recognizes that this needs direct verification through a synth-only microbenchmark — an assumption that is later confirmed in the subsequent chunk.

Input Knowledge Required

To fully understand this message, one needs:

1. The baseline: 88.9 seconds for a single 32 GiB PoRep proof, with synthesis ~54.7s and GPU ~34.0s. Without this reference point, the 94.4s result is meaningless.
2. The Phase 4 optimization suite: The five changes (A1, A2, A4, B1, D4) and their intended effects. Understanding that B1 pins ~125 GB of host memory via cudaHostRegister is essential to interpreting why it added 5.7 seconds.
3. The regression history: The initial Phase 4 run at 106 seconds, the addition of CUDA timing instrumentation, the fix for stdout buffering, and the first timing breakdown that identified B1 as the primary GPU culprit.
4. The build system quirks: The fact that CUDA compilation artifacts live outside the standard cargo output directory, managed by build.rs, and that cargo clean -p supraseal-c2 doesn't remove them. This explains why the assistant had to manually rm -rf build directories.
5. The pipeline architecture: Understanding that synthesis and GPU proving are pipelined with async overlap, and that B_G2 MSM runs on the CPU concurrently with GPU compute. This is necessary to interpret the waterfall analysis.

Output Knowledge Created

This message creates several critical pieces of knowledge:

1. B1 is definitively harmful: The 5.7-second overhead of cudaHostRegister on 125 GB of memory is not worth the marginal DMA bandwidth improvement. The optimization proposal's estimate of 150–300 ms was off by a factor of 19–38x. This is a cautionary tale about the dangers of underestimating OS-level overhead for large memory operations.
2. The GPU compute path is healthy: With B1 reverted, GPU time (33.8s) is essentially at baseline (34.0s). The D4 per-MSM window tuning and other GPU-side changes are not causing regressions. This is valuable information — it means the GPU optimization work can proceed independently of the synthesis issue.
3. Synthesis is the sole remaining bottleneck: At 60.3 seconds versus 54.7 seconds baseline, synthesis accounts for the entire 5.5-second gap. This focuses the diagnostic effort on a single change (A1 SmallVec) rather than scattering attention across multiple suspects.
4. A methodological template: The sequence of events — instrument, measure, identify largest outlier, revert, re-measure, isolate next outlier — provides a reusable template for diagnosing performance regressions in complex systems. The assistant's discipline in reverting only one change at a time, rather than batch-reverting everything, preserves the ability to attribute effects to specific causes.

The Path Forward

The message ends with the assistant preparing to build a synth-only microbenchmark subcommand in cuzk-bench. This is the natural next step: by running synthesis in isolation, without GPU proving or SRS loading overhead, the assistant can perform rapid A/B testing of the A1 SmallVec change. The subsequent chunk shows exactly this: four configurations tested (Vec original at 54.5s, SmallVec cap=1 at 59.6s, cap=2 at 60.0s, cap=4 at 60.2s), conclusively proving that SmallVec causes a 5–6 second regression regardless of inline capacity.

The final step — gathering perf stat hardware counters to understand why SmallVec is slower on an AMD Zen4 Threadripper PRO 7995WX — represents the deepest level of diagnostic rigor. The assistant is not satisfied with knowing that SmallVec is slower; it wants to know why. Is it L1/L2/L3 cache misses? Branch mispredicts? Instruction-level parallelism? This level of curiosity is what separates competent performance engineering from exceptional work.

Conclusion

Message [msg 983] is a masterclass in disciplined performance diagnosis. It is the moment when a complex, multi-variable regression is decomposed into its constituent causes through careful instrumentation, targeted reversion, and precise measurement. The 94.4-second result is not just a number — it is a verdict that confirms a 5.7-second mistake (B1) and isolates a 5.6-second mystery (A1 SmallVec). The assistant's methodical approach — reverting one change at a time, verifying each step with instrumented builds, and planning the next diagnostic phase before executing it — provides a template that any performance engineer can learn from.

The message also serves as a humbling reminder that even well-reasoned optimization proposals can be wrong. The B1 cudaHostRegister optimization was backed by solid theory — pinned memory should improve DMA transfer bandwidth — but the practical reality of mlock-ing 125 gigabytes of memory overwhelmed any theoretical benefit. The 19x underestimate of the pinning overhead is a cautionary tale about the gap between microbenchmarks and real-world system behavior. In performance engineering, there is no substitute for measurement.