The Moment of Truth: Diagnosing Phase 10's Two-Lock GPU Interlock Failure

In the high-stakes world of GPU-accelerated SNARK proving, where every millisecond counts and architectural decisions cascade through hundreds of lines of CUDA code, there comes a moment when theory meets reality. Message 2645 captures precisely such a moment: the instant when the assistant, having just completed a benchmark of the Phase 10 two-lock GPU interlock design, confronts the devastating evidence that the design is fundamentally broken. The message is short — a single diagnostic grep command and its output — but it carries the weight of an entire optimization phase collapsing under the weight of empirical evidence.

The Message Itself

The assistant writes:

Proof passes correctness (completed, not failed). But 73.8s is very slow — let me check the daemon logs to understand what happened.

Then executes a targeted grep against the daemon log:

grep -E "(CUZK_TIMING|prestage|gpu_total|PROOF|partition_ms|GPU_START|GPU_END)" /home/theuser/cuzk-p10-daemon.log | tail -60

The output reveals the internal timing of the Phase 10 proving pipeline:

CUZK_TIMING: gpu_tid=0 tail_msm_ms=126 gpu_total_ms=3770
CUZK_TIMING: epilogue_ms=1 pre_destructor_ms=11444
TIMELINE,177264,GPU_END,807490ec-00c3-4cb7-bd30-2991f5671fcd,worker=1,partition=4,gpu_ms=11444
TIMELINE,177277,GPU_START,807490ec-00c3-4cb7-bd30-2991f5671fcd,worker=1,partition=9
CUZK_TIMING: split_vectors_ms=585 setup_to_split_ms=585
CUZK_TIMING: async_dealloc_ms=824
CUZK_TIMING: prestage_setup=skip_vram
CUZK_TIMING: prep_msm_ms=1744
CUZK_TIMING: b_g2_msm_ms=371 num_circuits=1
CUZK_TIMING...

The output is truncated with ..., but the visible lines contain the critical diagnosis.

The Context: Phase 10's Ambitious Design

To understand why this message matters, one must understand what Phase 10 attempted to achieve. The Phase 9 optimization had successfully reduced GPU kernel time from 3.75s to 1.82s per partition through PCIe transfer optimization with pre-staged NTT uploads. However, this exposed a new bottleneck: DDR5 memory bandwidth contention. With 10 synthesis workers and prep_msm all performing heavy memory reads simultaneously, the 8-channel DDR5 memory subsystem saturated. GPU utilization was only 48.5% — the GPU spent half its time waiting for the CPU to prepare data.

The Phase 10 design, documented in c2-optimization-proposal-10.md, proposed splitting the single GPU mutex into two locks: compute_mtx for GPU kernel execution and mem_mtx for VRAM allocation. The idea was that with gpu_workers_per_device = 3, three workers could overlap their work — one running GPU kernels under compute_mtx, another pre-allocating VRAM buffers under mem_mtx, and a third performing CPU-side preparation (b_g2_msm, epilogue) outside any lock. The hoped-for benefit was hiding the ~0.5s b_g2_msm and ~1.9s prep_msm behind GPU kernel execution, bringing per-partition time close to the 1.82s GPU kernel duration.

But even as the code was written, warning signs emerged. The assistant's own design document (msg 2628) listed Discovery #8: "cudaDeviceSynchronize in mem_mtx causes serialization" because it is a device-global operation. Discovery #9: "cudaMemPoolTrimTo is also device-global." Discovery #11: "Pre-staging will almost always fail with gw≥2" because on a 16 GiB GPU, peak VRAM during H-MSM is ~13.8 GiB, leaving no room for a second worker's pre-staged buffers.

Despite these warnings, the assistant pressed forward with implementation, hoping that even if pre-staging failed, the fallback path (allocating inside compute_mtx) would still provide some benefit by allowing b_g2_msm to run outside the lock.

The Benchmark That Triggered the Diagnosis

Message 2644 recorded the first benchmark of the Phase 10 implementation. The result was stark:

=== Batch Summary ===
total time:    73.8s
completed:     1
failed:        0
prove time:    avg=102.4s
throughput:    0.813 proofs/min (73.8s/proof)

This was more than double Phase 9's single-proof baseline of ~32 seconds. The proof passed correctness — the mathematics were sound — but the performance was catastrophic. This brings us to message 2645, where the assistant investigates why.

The Diagnostic Grep: What the Assistant Was Looking For

The grep pattern is itself revealing of the assistant's thinking process. The pattern (CUZK_TIMING|prestage|gpu_total|PROOF|partition_ms|GPU_START|GPU_END) targets every timing instrumentation point that was carefully placed during Phase 9's instrumentation work. The CUZK_TIMING prefix marks fine-grained internal timing events. The prestage keyword targets the pre-staging logic that is the heart of Phase 10's two-lock design. The GPU_START/GPU_END TIMELINE markers track GPU occupancy. The gpu_total and partition_ms entries capture per-partition breakdowns.

The assistant is not reading the log blindly — it is querying specific instrumentation that was designed for exactly this kind of rapid diagnosis. This reflects a disciplined engineering approach: instrument first, then diagnose with precision.

The Smoking Gun: prestage_setup=skip_vram

The grep output contains one line that explains everything:

CUZK_TIMING: prestage_setup=skip_vram

This single line confirms the worst fear: every partition's pre-staging attempt was skipped because VRAM was insufficient. The 16 GiB GPU, already occupied with one worker's compute workload (~12-14 GiB for H-MSM buffers), had no room to pre-allocate buffers for another worker. The fallback path — the safety net — became the only path.

And the fallback path is punishing. The line pre_destructor_ms=11444 shows that the pre-destructor phase (which includes cudaDeviceSynchronize and pool trim inside compute_mtx) takes 11.4 seconds per partition. Compare this to Phase 9's GPU kernel time of 1.82 seconds. The two-lock design, far from improving throughput, has made things 6x worse because every partition now executes a full device-wide synchronization inside the critical section.

The TIMELINE events reveal the serialization pattern. GPU_END for worker 1, partition 4 shows gpu_ms=11444 — 11.4 seconds of GPU-claimed time for a single partition. The GPU_START for partition 9 (with a gap in partition numbering suggesting some partitions completed without TIMELINE events) shows the pipeline is completely serialized. The two-lock split has not created overlap; it has added overhead.

Other timing lines confirm that individual operations are healthy:

• prep_msm_ms=1744 — 1.74s for preparation, within normal range
• b_g2_msm_ms=371 — 0.37s for b_g2_msm, normal
• async_dealloc_ms=824 — 0.82s for async deallocation
• split_vectors_ms=585 — 0.58s for vector splitting None of these are pathological individually. The problem is structural: they all execute sequentially under compute_mtx because the mem_mtx path (pre-staging) always fails.

The Knowledge Created by This Message

Before message 2645, the assistant had theoretical knowledge that pre-staging might fail. Discovery #11 in the design document stated the concern, but it was speculative — based on memory accounting, not measurement. After message 2645, there is empirical proof. The prestage_setup=skip_vram log line transforms a theoretical concern into a measured reality.

More fundamentally, this message creates the knowledge that Phase 10's two-lock approach is not salvageable through tuning. The problem is not a bug, a misconfiguration, or a suboptimal parameter choice. It is a fundamental mismatch between the design's assumptions (that VRAM can be shared between workers for pre-staging) and the hardware reality (16 GiB is insufficient for dual-worker buffer allocation on a GPU that peaks at 13.8 GiB during H-MSM).

The message also validates the instrumentation investment from Phase 9. Without the CUZK_TIMING and prestage_setup log points, diagnosing the root cause would have required extensive code tracing and guesswork. Instead, a single grep reveals the answer in seconds.

The Assumptions That Failed

Several assumptions underlying Phase 10 are challenged by this message:

1. That VRAM could accommodate pre-staged buffers from multiple workers. The skip_vram flag proves this wrong. On a 16 GiB GPU, peak H-MSM usage of ~13.8 GiB leaves only ~2.2 GiB of headroom — insufficient for another worker's d_a (4 GiB) and d_bc (8 GiB) buffers.
2. That the fallback path would be fast. The 11.4s pre_destructor_ms proves the fallback is catastrophically slow. The cudaDeviceSynchronize call inside the fallback serializes all GPU work across all streams, turning the two-lock design into a single-lock design with extra overhead.
3. That CUDA memory management APIs could be isolated per-lock. The device-global nature of cudaDeviceSynchronize, cudaMemPoolTrimTo, and cudaMemGetInfo means any CUDA API call in mem_mtx interacts with kernels running under compute_mtx. The two-lock split is semantically meaningless on a single GPU device.

The Path Forward

This message sets the stage for the next phase of the project. With Phase 10 proven ineffective, the assistant will need to revert the two-lock changes, restore Phase 9's proven single-lock design, and conduct comprehensive benchmarking to understand the actual bottleneck. The knowledge created here — that device-global CUDA APIs defeat lock-splitting on consumer GPUs — becomes a foundational insight that shapes all subsequent optimization.

The 73.8-second benchmark and the prestage_setup=skip_vram log line are not failures in the scientific sense. They are data points that falsify a hypothesis and guide the next iteration. Message 2645 is the precise moment that falsification occurs — the instant when the evidence becomes undeniable.