The Skeptic's Lens: How a Single User Observation Exposed the Blind Spot in GPU Utilization Metrics

In the midst of a deep optimization campaign targeting the SUPRASEAL_C2 Groth16 proof generation pipeline for Filecoin PoRep, a single user message arrived that would fundamentally reshape the investigation. The message was brief, skeptical, and grounded in direct observation:

90% sounds odd, I saw actual compute and rising memony use maybe 50% of the time, maybe some lock waiting too long for release / memory accounting not refreshing often enough?

This was [msg 2502], a response from the user to the assistant's claim that GPU utilization stood at 90.1% during a Phase 9 benchmark run. To understand why this message matters, we must examine the context that produced it, the assumptions it challenged, and the cascade of deeper analysis it triggered.

The Context: A Metric That Looked Too Good

The conversation leading up to this message had been an intensive, multi-session investigation into GPU utilization patterns in the cuzk SNARK proving engine. The assistant had just completed a detailed analysis of TIMELINE events from a benchmark run with 15 concurrent proofs (c=15) and 10 partitions per proof (j=10). Using awk scripts that parsed GPU_START and GPU_END events from the daemon's stderr log, the assistant computed that the GPU was processing partitions for 550.8 seconds out of a 611.4-second span, yielding a utilization figure of 90.1% (see [msg 2497]).

The assistant's analysis in [msg 2501] had gone further, computing an average GPU kernel time of 3.67 seconds per partition and a theoretical minimum throughput of 36.7 seconds per proof. The observed throughput of 42.9 seconds per proof translated to 85.6% effective throughput. The assistant concluded that "synthesis takes ~36s for all 10 partitions (with pw=10), and GPU processes 10 partitions in ~37s. They're almost balanced!" The narrative was one of near-perfect pipeline balance, with only minor variance causing gaps.

But the user had been watching the system too — not through parsed log events, but through direct observation of GPU compute and memory behavior. And what they saw told a different story.

What the User Actually Said

The message contains three distinct claims, each building on the others:

"90% sounds odd" — A direct rejection of the assistant's headline metric. The user doesn't say "wrong" or "incorrect"; they say "odd," which is a softer but more precise judgment. It signals that the number doesn't pass the plausibility test based on what they've observed with their own eyes.
"I saw actual compute and rising memony use maybe 50% of the time" — This is the empirical grounding. The user has been watching GPU compute utilization and memory usage patterns, likely via nvidia-smi, nvtop, or some other monitoring tool. Their observation is that the GPU is actively computing and consuming memory only about half the time. This is a massive discrepancy from the 90.1% figure.
"maybe some lock waiting too long for release / memory accounting not refreshing often enough?" — Here the user offers two specific hypotheses for what might explain the gap. Both are grounded in architectural knowledge of the system. "Lock waiting too long for release" points to the mutex-based GPU worker dispatch mechanism, where a worker must acquire a mutex before it can submit work to the GPU. "Memory accounting not refreshing often enough" points to the cudaMemGetInfo query and pool trim operations that run inside the mutex, potentially delaying the next worker's ability to determine whether sufficient VRAM is available.

The Blind Spot: What TIMELINE Events Don't Measure

The user's skepticism exposed a critical blind spot in the assistant's analysis. The TIMELINE instrumentation in the cuzk engine records GPU_START and GPU_END events that bracket the actual CUDA kernel execution region — the time spent running NTT, MSM, and other GPU computations. But the GPU's time is not fully captured by these events. The full lifecycle of a GPU worker includes:

Mutex acquisition wait: The worker calls mutex.lock() and may block while another worker holds the lock, performing memory management or other CPU-side operations.
cudaDeviceSynchronize + pool trim: Added during Phase 9 to ensure clean state before the next allocation, this device-wide synchronization blocks the calling thread until all pending GPU operations complete, then trims the memory pool.
cudaMemGetInfo + allocation: After acquiring the mutex, the worker queries available VRAM and potentially allocates memory — all while holding the mutex and preventing other workers from accessing the GPU.
cudaHostRegister/Unregister: Page pinning and unpinning operations that involve CPU-side memory management.
Memory deallocation between partitions: Freeing d_a and d_bc buffers, which may involve implicit device synchronization. The TIMELINE GPU_START event fires after all this preamble is complete, when kernel execution actually begins. The GPU_END event fires when kernels complete, before the mutex is released and cleanup begins. So the 90.1% figure measures only the fraction of time spent in actual kernel execution relative to the span between the first kernel start and the last kernel end — but it completely ignores the time workers spend waiting for the mutex, performing memory management, and cleaning up. The user's observational estimate of "maybe 50% of the time" — while approximate — was far closer to the true GPU utilization when accounting for all the non-kernel overhead that the TIMELINE events silently excluded.

The Hypotheses: Lock Contention and Memory Accounting

The user's two hypotheses reveal a sophisticated understanding of the system's architecture.

"Lock waiting too long for release" targets the mutex design. In the Phase 9 architecture, a single mutex protects the entire GPU submission path. A worker acquires this mutex, performs memory allocation and pre-staging (which can take hundreds of milliseconds), releases it only after kernel submission, and then must re-acquire it for cleanup. During this time, other workers — even if they have partitions ready to process — are blocked. At high concurrency (15 concurrent proofs), multiple workers may be waiting for the mutex simultaneously, creating a queue that inflates the gap between successive GPU submissions.

"Memory accounting not refreshing often enough" targets the cudaMemGetInfo call that queries available VRAM. The Phase 9 pre-staging logic checks whether 12 GiB of VRAM is available before attempting allocation. But if the accounting is stale — if it doesn't reflect memory that was recently freed but not yet returned to the pool — the worker may conservatively skip pre-staging and fall back to a slower path. The user's phrasing "not refreshing often enough" suggests they suspect the memory pool trim or accounting interval is too coarse, causing workers to see artificially low free-memory figures and take suboptimal paths.

Why This Message Was Written

The user wrote this message because they recognized a disconnect between the assistant's quantitative analysis and their own qualitative observations. This is a classic pattern in performance engineering: metrics derived from instrumented events can be misleading if the instrumentation boundaries don't align with the actual phenomenon being measured. The assistant had fallen into the trap of trusting the TIMELINE events as a complete picture of GPU utilization, when in fact they only captured a subset of the GPU-related activity.

The user's intervention served as a reality check. They weren't rejecting the data — they were questioning the interpretation. The phrase "90% sounds odd" is a polite way of saying "your numbers don't match what I'm seeing, so one of us is wrong." And in this case, the user was right.

The Impact: A Cascade of Deeper Analysis

The assistant's response in [msg 2503] immediately acknowledged the validity of the user's skepticism. The assistant wrote: "You're right to be skeptical of the 90% number. That metric only measures time between GPU_START and GPU_END events — it doesn't account for what happens inside the mutex but outside kernel execution." The assistant then enumerated the specific overheads the TIMELINE missed: lock acquisition wait, cudaDeviceSynchronize + pool trim, cudaMemGetInfo + allocation, cudaHostRegister/Unregister, and memory deallocation.

This led to a deeper instrumentation effort. The assistant computed that the per-partition overhead (non-kernel time) averaged 404 milliseconds — a significant fraction of the total 3.67-second GPU kernel time. More importantly, this overhead was concentrated in the CPU-side critical path, not in GPU execution. The bottleneck had shifted from GPU kernel performance to CPU-side memory management and lock contention.

This realization directly informed the design of Phase 10, documented in c2-optimization-proposal-10.md. The Phase 10 two-lock architecture — splitting a single mutex into a mem_mtx for VRAM allocation and a compute_mtx for kernel execution — was a direct response to the user's observation that lock waiting and memory accounting were the real bottlenecks. By separating memory management from compute submission, the design aimed to overlap the CPU-side overhead of one worker with the GPU-side execution of another, hiding the 404ms per-partition overhead behind kernel execution.

The Thinking Process Visible in the Message

The user's message is a masterclass in diagnostic reasoning. It moves from observation ("I saw actual compute... maybe 50% of the time") to hypothesis ("maybe some lock waiting... / memory accounting not refreshing?"), all while maintaining appropriate uncertainty ("maybe," "sounds odd"). The user doesn't assert certainty — they offer a plausible alternative explanation and let the assistant verify it.

The phrase "rising memony use" (likely a typo for "memory") is telling. The user is watching not just compute utilization but also memory allocation patterns. They've noticed that memory usage rises and falls in a pattern that doesn't match the 90% utilization claim. If the GPU were truly active 90% of the time, memory usage would be consistently high. The fact that it rises and suggests a stop-and-start pattern — consistent with workers waiting for locks, then bursting work to the GPU, then waiting again.

The two hypotheses are also carefully chosen. "Lock waiting too long for release" targets the synchronization mechanism. "Memory accounting not refreshing often enough" targets the resource management logic. Together, they cover the two most likely sources of GPU starvation in a multi-worker, single-GPU architecture: contention for the GPU itself, and contention for the information needed to decide whether to use the GPU.

Conclusion

The user's message at [msg 2502] is a pivotal moment in the optimization campaign. It exposed a critical blind spot in the assistant's metric interpretation, redirected the investigation toward CPU-side overhead rather than GPU kernel performance, and directly inspired the Phase 10 two-lock architecture that would become the next major optimization step. More broadly, it demonstrates the irreplaceable value of human observation in performance analysis — no automated metric can replace the engineer who watches the system and says "that number doesn't look right." The 90.1% figure was technically correct within the narrow bounds of what the TIMELINE events measured, but it was misleading as a measure of true GPU utilization. The user's skepticism, grounded in direct observation, cut through the numbers to reveal the real bottleneck.