Profile with Nsight Systems

Yesterday I used Locust to find the saturation point of an inference endpoint. That tells you when performance degrades, but not why. To understand why, you need to look inside the GPU execution timeline. NVIDIA Nsight Systems is the tool for this.

Nsight Systems is a system-wide profiler that captures a timeline of CPU threads, CUDA API calls, GPU kernel executions, memory copies, and NCCL communication. Unlike torch.profiler (which instruments PyTorch operations), Nsight Systems works at the CUDA driver level, so it captures everything, including activity from libraries like cuBLAS, FlashAttention, and NCCL that PyTorch's profiler may aggregate or miss.

Capturing a profile

The simplest way to profile an inference server is to use nsys profile to wrap the server process and trigger a few requests while it runs:

# Profile the vLLM server process
nsys profile \
  --trace=cuda,nvtx,osrt,cudnn,cublas \
  --output=vllm_profile \
  --duration=30 \
  --delay=10 \
  python -m vllm.entrypoints.openai.api_server \
    --model meta-llama/Llama-2-13b-hf \
    --dtype float16

The flags:

• --trace=cuda,nvtx,osrt,cudnn,cublas: capture CUDA kernels, NVTX annotations (which vLLM and PyTorch emit), OS runtime calls, cuDNN, and cuBLAS.
• --delay=10: wait 10 seconds before starting capture, giving the server time to load the model.
• --duration=30: capture for 30 seconds.

While the profile runs, I sent a batch of requests from another terminal:

# Send requests during the profiling window
for i in $(seq 1 20); do
  curl -s http://localhost:8000/v1/completions \
    -H "Content-Type: application/json" \
    -d '{"model":"meta-llama/Llama-2-13b-hf","prompt":"Explain transformers","max_tokens":64}' &
done
wait

This produces a .nsys-rep file that you open in the Nsight Systems GUI or analyze with nsys stats.

Reading the timeline

The timeline view shows horizontal lanes for each CPU thread and CUDA stream. The key things to look for:

• Kernel density: are the GPU streams packed with back-to-back kernels, or are there gaps? Gaps mean the GPU is idle waiting for the CPU to enqueue work.
• Kernel duration: which kernels dominate? For LLM inference, the largest kernels are typically cuBLAS GEMM calls (the weight matmuls) and FlashAttention kernels.
• CPU-GPU synchronization: look for cudaStreamSynchronize or cudaDeviceSynchronize calls. Each one forces the CPU to wait for the GPU, creating a bubble.
• Memory copies: cudaMemcpyAsync between host and device. During normal inference, these should be minimal. If you see large H2D transfers per request, something is not cached properly.

What I found

Profiling Llama 2 13B on vLLM revealed a clear pattern in the decode phase. Each decode step consists of:

1. A burst of GEMM kernels (the linear layers in each transformer block): about 60% of wall time.
2. FlashAttention kernels (one per layer): about 15% of wall time.
3. Small element-wise kernels (LayerNorm, SiLU, RoPE): about 5%.
4. Gaps between kernel launches: about 15% of wall time.
5. NCCL all-reduce (if TP > 1): about 5% for TP=2.

That 15% in launch gaps is the interesting finding. The CPU scheduler in vLLM needs to decide which requests to batch, allocate KV cache blocks, and prepare the metadata for each step. This scheduling work happens on the CPU between GPU kernel launches, and the GPU sits idle during it.

Using nsys stats for quick analysis

If you do not have the GUI available (for example, profiling on a remote server), nsys stats gives you a command-line summary:

# Summary of CUDA kernels by time
nsys stats --report cuda_gpu_kern_sum vllm_profile.nsys-rep

# Top 10 kernels by total time
nsys stats --report cuda_gpu_kern_sum \
  --format csv vllm_profile.nsys-rep | \
  sort -t, -k2 -rn | head -10

A typical output shows the cuBLAS GEMM kernels at the top, followed by FlashAttention:

# Kernel Name                              Total Time (ms)  Count
# ampere_fp16_s16816gemm_fp16_...          142.3            960
# void flash_fwd_kernel<...>                38.7            480
# void layernorm_kernel<...>                 8.2            960
# void silu_and_mul_kernel<...>              4.1            480

The counts make sense: a 13B model has 40 transformer layers, and a decode step of 12 tokens in a batch executes each layer once. The GEMM count (960) is 40 layers times 3 linear projections (Q, K, V) per attention block times ~8 from the MLP layers, and the attention kernel count (480) is 40 layers times 12 batch entries.

Nsight Systems vs. torch.profiler

Both tools have their place:

• torch.profiler: easier to set up, integrates with TensorBoard, shows PyTorch-level operations. Great for understanding model-level behavior. See my earlier post on torch.profiler.
• Nsight Systems: lower level, shows actual CUDA kernel timelines, memory transfers, and driver-level events. Essential for finding launch overhead, stream synchronization issues, and NCCL communication patterns.

I typically start with torch.profiler to identify which operations are slow, then switch to Nsight Systems when I need to understand why a particular operation is slow (is the kernel itself slow, or is the GPU idle between kernel launches?).

Practical tips

• Keep profiles short (10 to 30 seconds). Nsight Systems captures everything at high resolution, and long profiles produce multi-gigabyte files that are slow to open.
• Use NVTX annotations to mark request boundaries. vLLM and PyTorch already emit NVTX ranges, but you can add custom ones to mark specific requests or batches.
• Profile under realistic load. A profile of a single request in isolation will not show the scheduling overhead that appears under concurrent load.
• Compare profiles before and after an optimization. The timeline makes it visually obvious whether a change actually helped or just moved the bottleneck.

The profile never lies. When you are guessing about performance, you are wrong about half the time. When you are profiling, you are learning every time.

Next: building an SSE streaming client to consume tokens as they are generated, rather than waiting for the full response.