Skip to main content

Someone wanted to learn this too, so Grasp built them a personal learning path.

You can keep exploring this one or create your own

Optimizing Performance with Profiler Traces

Introduction

In our previous lesson, we established a clear workflow for performance analysis, distinguishing between framework-level profilers like PyTorch Profiler, which tell us what part of our code is slow, and system-level profilers like Nsight Systems, which explain how our application interacts with the hardware.

Today, we will put that knowledge into practice. This lesson focuses on the core analytical skill of interpreting the output of these tools. We will address the learning outcome: Analyze a profiler trace to identify performance limiters like kernel execution time, data movement overhead, and idle time.

Think of yourself as a detective arriving at a crime scene. The profiler trace is your evidence—a detailed timeline of events. Your task is to scrutinize this evidence for patterns and anomalies that reveal the culprit behind poor performance. By the end of this lesson, you will be able to dissect a profiler trace, identify the tell-tale signs of the most common performance bottlenecks, and form hypotheses about their root causes.

The Anatomy of a Profiler Timeline

Before we hunt for bottlenecks, let's establish a common understanding of what a profiler trace shows. Whether you're viewing a trace in Nsight Systems or the Chrome Trace Viewer, you'll see a timeline with several key "rows" or "tracks".

NVIDIA Nsight Systems Profiler Trace Example
The user interface for NVIDIA Nsight Systems. A trace is a timeline that moves from left to right. It typically shows CPU activity, CUDA API calls, and GPU hardware execution, allowing you to correlate events across the system.

A typical trace contains the following elements:

  1. CPU/Thread Rows: These tracks show the activity on CPU cores. For our purposes, the most important events here are the CUDA API calls your application makes, such as cudaLaunchKernel or cudaMemcpy. These represent the CPU requesting work from the GPU. You will also see Python function calls if you've enabled Python sampling.
  2. GPU Hardware Rows: These tracks show what the GPU is actually doing. You'll see rectangular blocks representing:
    • Kernels: These are the computational tasks (e.g., matrix multiplications, convolutions) executing on the GPU's streaming multiprocessors.
    • Memory Copies: These represent data being moved.
  3. NVTX Ranges: As we discussed, these are custom annotations you add to your code (e.g., with torch.cuda.nvtx.range("forward_pass"):). They appear as labeled, colored blocks on the timeline, providing invaluable context by mapping the low-level GPU activity back to logical phases of your algorithm.
  4. Interconnect Rows (e.g., PCIe, NVLink): Nsight Systems can show the throughput on the physical buses connecting the CPU and GPU, or connecting multiple GPUs. This is where you can see the bandwidth utilization of data transfers.

The key to analysis is correlating events between these rows. For example, you will see a cudaLaunchKernel call on a CPU thread row, followed shortly after by the corresponding kernel block appearing on a GPU hardware row. The delay between the two is the kernel launch latency.

Identifying Performance Limiters: A Case-Study Approach

Let's now examine the three major types of performance limiters and how to spot them in a trace.

1. Idle Time (CPU Bottlenecks and Synchronization)

The Symptom: The most obvious red flag in any GPU trace is a "gap"—a period where the GPU hardware rows are empty. This means your expensive accelerator is sitting idle, which directly hurts throughput.

The Diagnosis: When the GPU is idle, your first question should be: "What is the CPU doing?" An idle GPU is often a symptom of a CPU-side bottleneck.

Case Study: The Data-Loading Bottleneck

A common cause of GPU starvation is an inefficient data pipeline. The CPU can't load and preprocess data fast enough to keep the GPU fed.

Debugging and Optimization of PyTorch Models

Let's watch a demonstration from a Sharcnet HPC tutorial that uses the PyTorch Profiler to diagnose exactly this problem.

Watch the clip from 14:53 to 18:20. First, observe the initial trace (around 16:10). Notice the large empty spaces on the GPU timeline (Stream 7). The presenter correctly notes, 'our GPU is not busy at all... we're spending most of our time in the data loader.' Next, see the 'after' trace (around 17:15) where the number of data loader workers was increased. The gaps are much smaller, and the total time for the same number of iterations has dropped significantly (from 16.7s to 4.9s).

This case illustrates a classic CPU-bound scenario. The GPU is faster than the CPU's ability to provide data, leading to idle time. The trace makes this problem visually obvious.

Case Study: Hidden Synchronization Stalls

A more subtle cause of idle time is an unintended CPU-GPU synchronization. This happens when the CPU, which normally submits work asynchronously to the GPU, is forced to stop and wait for the GPU to finish all previously submitted tasks.

Speed Up PyTorch Training by 3x with NVIDIA Nsight

The article 'Speed Up PyTorch Training by 3x with NVIDIA Nsight' provides an excellent real-world example of finding and fixing a synchronization stall caused by a single line of Python code.

Please read the sections 'Deep Dive: Annotating and Sampling Your Training Loop' and 'Hidden Syncs: The Cost of .item()'. Notice how NVTX annotations helped isolate the problem to a 'loss stats' section. The crucial discovery is that the call loss.item() triggers a cudaStreamSynchronize event, which appears as a green block on the CUDA API row and aligns perfectly with the GPU idle gap. Understand the explanation: calling .item() requires moving a single value from the GPU to the CPU, but to guarantee the value is correct, the CPU must wait for the GPU to finish computing it, stalling the entire pipeline.

This is a powerful example of trace analysis. The idle gap on the GPU row is the symptom. The cudaStreamSynchronize event on the CPU row is the direct cause. The Python call stack (linked via sampling) points to loss.item() as the root cause in your code.

2. Data Movement Overhead

The Symptom: Your trace shows a significant portion of time is spent on memory copy operations, not computation. These can be Host-to-Device (HtoD), Device-to-Host (DtoH), or Device-to-Device (DtoD) copies.

The Diagnosis: Look for large blocks corresponding to cudaMemcpy (in Nsight Systems) or collective communication kernels like ncclAllReduce (in distributed training).

Case Study: Inefficient CPU-to-GPU Data Transfer

Just like with synchronization, the way you transfer data can introduce stalls.

Speed Up PyTorch Training by 3x with NVIDIA Nsight

Let's continue with the same article, which finds and fixes another data transfer bottleneck immediately after the first one.

Please read the section 'Fixing Data Transfer Bottlenecks'. The profiler now shows a new bottleneck: a long cudaStreamSynchronize call that overlaps with the aten::to operation, which moves data to the GPU. The article explains that by default, this copy is synchronous. The fix involves two steps: setting pin_memory=True in the DataLoader and non_blocking=True in the .to() call. Observe the 'after' trace: the long aten::to section and the associated synchronization have vanished, allowing computation to start sooner.

Case Study: Multi-GPU Communication

In distributed training, data movement between GPUs for gradient synchronization is a primary concern. The performance here is heavily dependent on the underlying interconnect hardware (e.g., PCIe vs. NVLink). A profiler trace makes the impact of this hardware transparent.

Optimizing Data Transfer in Distributed AI/ML Training Workloads

The article 'Optimizing Data Transfer in Distributed AI/ML Training Workloads' provides a clear comparison of running the same distributed job on two different systems, one with a slower interconnect (PCIe) and one with a faster one (NVLink).

Please read the section 'DDP With Multiple GPUs'. Compare the two profiler traces shown: g6e.48xlarge (PCIe): In this trace, the ncclAllReduce kernel (which performs the gradient synchronization) is a massive block that 'dominates the backward pass, accounting for approximately 84% of the overall step time'. This is a clear communication bottleneck. p4d.24xlarge (NVLink): On this machine, the ncclAllReduce kernel is a much smaller portion of the training step. The faster interconnect has dramatically reduced the data movement overhead.

This example shows how a trace can immediately reveal the performance characteristics of the underlying system architecture, confirming whether your workload is limited by inter-GPU communication bandwidth. The article goes on to show how optimizations like gradient compression or overlapping communication with computation manifest as visible changes in the trace (e.g., smaller ncclAllReduce blocks or multiple, smaller blocks running in parallel with computation).

3. Kernel Execution Time (Compute-Bound)

The Symptom: There are no significant idle gaps, and data movement is a small fraction of the step time. Instead, the GPU is constantly busy, with one or a few specific kernels taking up most of the timeline.

The Diagnosis: This is a compute-bound scenario. The GPU is the bottleneck, and the time is dominated by computation. The profiler's job in this case is to help you identify the most expensive ("hot") kernels.

In a profiler's timeline view, you would identify this by looking for the longest rectangular blocks in the GPU hardware stream. In the summary tables (like the one at the bottom of the Nsight Systems GUI image), you can sort kernels by "Total Time" to get a ranked list of performance hogs.

Once you identify a hot kernel, the analysis moves to the next level—using a kernel-level profiler like Nsight Compute to understand why that kernel is slow (e.g., memory latency, instruction stalls), as we discussed in the previous lesson's workflow.

Conclusion

In this lesson, we transitioned from knowing about profilers to knowing how to use them for analysis. We learned to read a profiler trace as a timeline of system-wide events and to spot the characteristic patterns of the three main performance limiters.

Key Takeaways:

  • A profiler trace allows you to correlate high-level application behavior with low-level hardware execution.
  • Idle Time (gaps on the GPU timeline) is a primary red flag. It often points to a CPU-bound data pipeline or a synchronization stall (e.g., from loss.item()).
  • Data Movement Overhead appears as large memcpy blocks or long-running communication kernels (e.g., ncclAllReduce). This indicates a memory-bound or communication-bound workload.
  • Long Kernel Execution Time, with high GPU utilization, indicates a compute-bound workload. Your goal is to identify the "hot" kernels that dominate the execution time.
  • Profiling is an iterative, evidence-driven process: you profile to gather data, analyze the trace to form a hypothesis, apply an optimization, and then re-profile to verify your hypothesis and measure the impact.

Preview of the Next Lesson:

In this lesson, we analyzed performance within a single training step on one or more GPUs. However, a critical aspect of designing large-scale AI systems is understanding how performance changes as we scale up the hardware or the problem itself. In the next lesson, Explain how to reason about strong vs. weak scaling to evaluate the efficiency of a distributed system, we will explore the formal models used to measure and predict the scalability of our parallel applications.

Can't find a good explanation? Sign up and we'll make it for you

Sign up