The 90% Illusion: When GPU Utilization Metrics Mask the Real Bottleneck

Introduction

In the high-stakes world of Filecoin proof generation, every millisecond counts. The cuzk proving engine, a custom Groth16 implementation for Filecoin's Proof-of-Replication (PoRep), had been through eight optimization phases by the time the conversation reached message 2503. Phase 9 had just delivered a promising 14.2% throughput improvement through PCIe transfer optimization, but the dual-worker mode showed regression, and the single-worker benchmarks revealed a puzzling pattern: the GPU utilization metric hovered around 90%, yet the user's direct observation suggested the GPU was actually computing only about 50% of the time.

Message 2503 captures the moment when the assistant confronts this discrepancy head-on. It is a message of methodological introspection—a pause in the relentless optimization cycle to question whether the metrics being used to guide decisions are actually measuring what they claim to measure. The assistant acknowledges the user's skepticism, enumerates the hidden sources of overhead that the metric obscures, and runs a deeper analysis to uncover the true bottleneck. But in doing so, it inadvertently reveals a subtle tension between different levels of performance measurement that has profound implications for how we interpret GPU utilization data.

The Message: Acknowledging the Gap

The assistant begins by validating the user's intuition:

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 real GPU idle time includes:

>

1. Lock acquisition wait — the worker sits in mutex.lock() while memory accounting runs 2. cudaDeviceSynchronize + pool trim — we added this for Phase 9 and it blocks 3. cudaMemGetInfo + allocation — runs after acquiring the mutex, before GPU_START 4. cudaHostRegister/Unregister — page pinning overhead 5. Memory allocation/deallocation between partitions

>

So the real GPU compute utilization is much lower than 90%. The TIMELINE events only bracket the kernel region, not the full mutex-held period.

The assistant then proposes to instrument the critical path better and runs a bash script that parses the TIMELINE events from the daemon log, computing the wall span between the first GPU_START and the last GPU_END, summing the kernel execution times, and calculating the ratio:

First GPU_START: 274.1s
Last GPU_END:    885.5s
Wall span:       611.4s
Total kernel ms: 550.8s
Kernel utilization: 90.1%
Non-kernel time:    60.6s (9.9%)
Per-partition overhead: 404ms avg

The result: 90.1% kernel utilization. The same number the assistant was just arguing was misleading.

The Context: A Pipeline Under Optimization

To understand why this message matters, we need to trace the path that led here. The cuzk proving engine processes PoRep proofs through a pipeline that synthesizes circuit witnesses on the CPU and then performs Groth16 proving on the GPU. Each proof requires ten partitions, each partition undergoing a sequence of NTT (Number Theoretic Transform) and MSM (Multi-Scalar Multiplication) operations on the GPU.

Phase 9 introduced a critical optimization: pre-staging polynomial data (the a, b, c vectors) onto the GPU using pinned host memory and asynchronous DMA transfers. This reduced the per-partition GPU kernel time from 2.4s to approximately 690ms for NTT/MSM operations—a 71.6% improvement. The overall proof time dropped from 37.4s to 32.1s in single-worker mode.

But the dual-worker mode (gw=2) regressed to 41.0s, and the single-worker benchmarks at higher concurrency (c=15, j=10) showed 42.9s/proof—worse than the small run. The assistant's initial analysis (msg 2497) computed GPU utilization at 90.1% with an average gap of 406ms between partitions. The synthesis times averaged 36.2s for all ten partitions, while the GPU processed them in approximately 37s. They were almost perfectly balanced—any variance caused starvation.

The user's response (msg 2502) cut to the heart of the matter: "90% sounds odd, I saw actual compute and rising memory use maybe 50% of the time, maybe some lock waiting too long for release / memory accounting not refreshing often enough?"

This is the challenge that message 2503 must address.

The Reasoning: Why the Metric Lies

The assistant's reasoning in this message reveals a sophisticated understanding of the gap between what a TIMELINE event measures and what constitutes "real GPU compute." The GPU_START event is placed at the beginning of kernel launch, and GPU_END at kernel completion. The time between them is the kernel execution duration. But this duration includes periods where the GPU is not actually computing—it may be stalled on memory access, waiting for synchronization, or performing overhead operations that are part of the kernel but not productive computation.

More importantly, the assistant identifies that the metric misses entire categories of overhead that occur outside the GPU_START/GPU_END bracket but inside the mutex-held period. The sequence for each partition is:

  1. Acquire the GPU mutex (lock acquisition wait)
  2. Call cudaDeviceSynchronize and cudaMemPoolTrimTo (device-wide synchronization)
  3. Query cudaMemGetInfo and allocate VRAM
  4. Pin host memory with cudaHostRegister
  5. Upload data to GPU (the pre-staged DMA)
  6. Execute kernels (GPU_START to GPU_END)
  7. Free VRAM and unpin host memory with cudaHostUnregister
  8. Release the mutex Only step 6 is captured by GPU_START/GPU_END. Steps 2-5 and 7 all consume time while the mutex is held but the GPU may be idle or underutilized. The assistant's list of five overhead sources is a candid admission that the TIMELINE instrumentation, while useful, provides an incomplete picture.

The Tension: Data That Contradicts the Narrative

Here we encounter the most interesting aspect of this message: the assistant argues that the 90% figure is misleading, then runs an analysis that produces exactly 90.1%. The bash script computes the ratio of total kernel time (sum of gpu_ms from GPU_END events) to wall span (time from first GPU_START to last GPU_END). This is precisely the same metric the assistant just criticized.

Why does the number come out the same? Because the assistant's analysis still uses the same GPU_START/GPU_END events. It computes the gap between GPU_END and the next GPU_START—which is the non-kernel time (60.6s, 9.9%, 404ms per partition). But this gap already includes all the overhead the assistant listed: lock acquisition, pool trim, allocation, host registration, and deallocation. The 90.1% figure already accounts for these overheads—it's saying that 90.1% of the total wall time is spent inside the GPU_START/GPU_END bracket (kernel execution), and only 9.9% is spent on the setup/teardown between partitions.

So the assistant's claim that "the real GPU compute utilization is much lower than 90%" is not supported by the analysis they present. The 90.1% figure is the kernel utilization, and the 9.9% overhead is the setup/teardown. If the user observed ~50% actual compute, the discrepancy must lie elsewhere—perhaps in GPU micro-architecture utilization during kernel execution (memory stalls, pipeline bubbles) rather than in the partition-level overhead.

This tension is not resolved in this message. The assistant seems to accept the 90.1% result without noticing that it contradicts their initial claim. This is a moment where the assistant's reasoning is partially correct but incomplete—they correctly identify that the metric has blind spots, but the analysis they run to investigate doesn't actually address those blind spots.

The Thinking Process: What We Can Infer

The assistant's thinking process in this message is visible through the structure of their response. They move through several stages:

  1. Validation: First, they affirm the user's skepticism. This is important—the assistant recognizes that the user's direct observation of GPU behavior carries weight, even when it contradicts the instrumentation data.
  2. Enumeration: They list the specific sources of overhead that the metric misses. This shows a detailed mental model of the GPU pipeline—the assistant knows exactly what operations happen inside the mutex and can reason about which ones are invisible to the TIMELINE events.
  3. Proposal: They propose to "instrument this better" and run a more detailed analysis. This reflects a debugging mindset—when a metric seems wrong, the response is to dig deeper, not to dismiss the observation.
  4. Execution: They construct a bash/awk script to parse the TIMELINE data and compute the gap breakdown. The script is carefully designed to extract the relevant fields and compute meaningful statistics.
  5. Presentation: They present the results without commentary, letting the data speak for itself. The 90.1% result is shown plainly, and the message ends. What's notably absent is a moment of reflection where the assistant connects the dots: "Wait, the analysis shows 90.1% again—that doesn't explain the user's 50% observation. Let me look deeper." The assistant seems to accept the result and move on, leaving the contradiction unresolved.

Assumptions and Their Consequences

Several assumptions underpin the assistant's analysis in this message:

Assumption 1: GPU_START/GPU_END events accurately bracket kernel execution. This is the foundation of the entire metric. If the events are placed incorrectly (e.g., GPU_START fires before the kernel actually begins executing on the device, or GPU_END fires after the kernel has completed but before the host-side synchronization returns), the metric would be systematically biased. In CUDA, kernel launches are asynchronous—the host-side cudaLaunchKernel returns immediately, and the kernel executes later on the device. If GPU_START fires at launch time rather than at actual execution start, the metric would overcount kernel time.

Assumption 2: The sum of gpu_ms values equals total GPU compute time. The gpu_ms field in GPU_END events is presumably measured on the host side using CUDA events or timers. This measures the elapsed time between kernel launch and completion as observed from the host, which includes any device-side queuing delays, synchronization overhead, and memory transfer time that occurs within the kernel's execution context.

Assumption 3: The gap between GPU_END and the next GPU_START captures all non-kernel overhead. This is the assumption the assistant explicitly questions. The gap includes mutex release, next worker's mutex acquisition, pool trim, allocation, and upload. But it does not include any GPU-idle time that occurs during kernel execution due to memory stalls or pipeline bubbles. The user's observation of ~50% compute utilization suggests this intra-kernel idle time may be significant.

Assumption 4: The TIMELINE events are comprehensive and correctly ordered. The assistant sorts events by timestamp field, assuming the sort order reflects actual temporal order. If timestamps have microsecond precision and events from different threads interleave, the sort could introduce ordering artifacts.

Knowledge Required to Understand This Message

To fully grasp what's happening in message 2503, a reader needs:

  1. CUDA execution model: Understanding that kernel launches are asynchronous, that cudaDeviceSynchronize is a blocking device-wide operation, that cudaMemGetInfo queries available memory, and that cudaHostRegister pins host memory for DMA.
  2. Groth16 proving pipeline: Knowledge that PoRep proof generation involves ten partitions, each requiring NTT and MSM operations on the GPU, with synthesis (witness generation) happening on the CPU.
  3. The Phase 9 optimization: Understanding that pre-staging polynomial data using pinned memory and async DMA was the key change, and that it introduced cudaDeviceSynchronize and pool trim operations inside the mutex.
  4. Performance measurement methodology: Familiarity with the distinction between wall-clock time, kernel execution time, and actual GPU compute utilization, and the pitfalls of each metric.
  5. The cuzk codebase architecture: Knowledge of the TIMELINE instrumentation system, the per-GPU mutex design, and the partition dispatch mechanism.
  6. The conversation history: Understanding that Phase 8 achieved 13-17% throughput improvement with dual-GPU workers, Phase 9 added PCIe optimization, and the current investigation is trying to understand why dual-worker mode regressed.

Output Knowledge Created

This message produces several valuable pieces of knowledge:

  1. A quantified breakdown of kernel vs. non-kernel time: The 90.1% kernel utilization and 9.9% overhead (404ms per partition) provides a baseline for understanding where optimization effort should focus.
  2. A catalog of hidden overhead sources: The five-item list (lock acquisition, sync+trim, allocation, host registration, deallocation) is a concrete enumeration of operations that consume time but are invisible to the GPU_START/GPU_END metric.
  3. A reusable analysis script: The bash/awk pipeline for parsing TIMELINE data and computing utilization statistics is a tool that can be applied to future benchmarks.
  4. Confirmation of the user's intuition: By validating the user's skepticism and investigating, the assistant builds trust and demonstrates that direct observation of system behavior is valued alongside instrumentation data.
  5. An unresolved tension: The discrepancy between the 90.1% metric and the user's ~50% observation remains open, pointing toward the need for deeper instrumentation that measures actual GPU compute unit utilization (e.g., NVIDIA's nvidia-smi compute utilization metric, or profiling with nvprof/Nsight).

Assessment: Strengths and Weaknesses

The strength of this message lies in its methodological honesty. The assistant does not dismiss the user's observation or double down on the metric. Instead, they acknowledge the limitations of the instrumentation, enumerate the blind spots, and run additional analysis. This is the mark of a rigorous engineer who treats all data—even data that contradicts their own metrics—as worthy of investigation.

The weakness is that the analysis doesn't actually address the core question. The user observed ~50% compute utilization; the assistant's analysis confirms 90.1% kernel utilization. These numbers are measuring different things, and the assistant doesn't bridge the gap. The 90.1% figure measures the ratio of time spent in kernel execution regions to total wall time. The user's ~50% observation likely measures actual GPU compute unit activity during those kernel execution regions—a micro-architectural metric that requires different instrumentation (e.g., CUDA profiling counters, occupancy analysis, or memory throughput measurements).

The assistant also misses an opportunity to refine the TIMELINE instrumentation. If the GPU_START/GPU_END events are insufficient, the obvious next step is to add more events: MUTEX_ACQUIRE, ALLOC_START, UPLOAD_END, etc. This would provide a complete picture of where time is spent inside the mutex. The assistant proposes to "instrument this better" but then runs a post-hoc analysis of existing events rather than adding new instrumentation points.

Conclusion

Message 2503 captures a pivotal moment in the optimization journey—the moment when a trusted metric is called into question. The assistant's response is thoughtful and methodical, but it reveals how easily performance analysis can fall into the trap of measuring what's easy to measure rather than what matters. The 90.1% kernel utilization figure is not wrong, but it is incomplete. It tells us that 90% of the wall time is spent inside kernel execution regions, but it doesn't tell us what the GPU is actually doing during those regions.

The unresolved tension between the 90.1% metric and the user's ~50% observation points toward the next phase of investigation: understanding GPU micro-architectural utilization during kernel execution. This would require moving from TIMELINE-based event analysis to CUDA profiling tools that measure instruction throughput, memory bandwidth utilization, and occupancy. The assistant's willingness to question their own metrics, even when the data seems to support them, is the foundation upon which deeper understanding is built.

In the end, this message is a reminder that performance optimization is not just about making things faster—it's about understanding why things are slow. And sometimes, the most important insight is that your measurement tools are showing you the wrong picture.