Timing asynchronous systems
Measure GPU execution without mistaking command-submission time for completed device work
Before you begin
Follow a linked prerequisite when you cannot explain it from memory. Background skills without links are stated as abilities rather than hidden terminology.
- Benchmark requirements
- Distinction between server code on the CPU and parallel work on the GPU
A program calls a GPU operation and returns twelve microseconds later. The result is not ready for another four milliseconds. Both observations can be correct. The first interval measures host-side dispatch and command submission. The second includes the device work and any delay before the consumer can use the result.
GPU application programming interfaces use asynchronous execution so the central processing unit (CPU) can prepare later work while the GPU executes earlier commands. A launch call usually places a command into an ordered CUDA stream and returns control to the CPU. The returned array object can therefore describe a result whose numerical values are not ready to read.
The lesson records three separate intervals for one PyTorch operation: CPU submission time from a host clock, GPU execution time from timestamped CUDA events, and user-visible completion time from the request path. NVIDIA Nsight Systems supplies a fourth artifact—a timeline of recorded CPU calls, GPU kernels, copies, and waits—that reveals which work lies between each pair of timestamps. Correct measurement names the interval and avoids adding waits that production does not perform.
Separate host submission from device completion
A kernel launch normally places a command in a stream and returns control to the host before the kernel finishes. A host timer that starts before the launch and stops immediately after it measures how long submission took. Repeating this loop can enqueue many kernels and still report a short per-call time while the device queue grows behind it.
To measure host-observed completion, establish a completed starting boundary, start the host timer, submit the intended work, wait for its completion, and stop the timer. The host-observed interval can include submission, queue delay, device execution, and synchronization overhead. Host-observed completion answers a different question from isolated device execution.
Use device events for a device timeline interval
A device event is recorded at a position in a stream. The event receives its timestamp when execution reaches that position after all earlier work in the stream. Place a start event before the target sequence and an end event after the sequence. Synchronize on the end event or device after submission, then query elapsed event time.
The device-event interval excludes much host-side work and can begin after work that was already queued ahead of the start event. Device-event timing is useful for explaining kernel and device-sequence behavior. Device-event timing is not a substitute for user-visible latency when CPU preparation, admission, transfer, or queueing is part of the product.
Reason about streams as dependencies
Operations in one stream execute in stream order. Operations in separate streams can execute concurrently only when dependencies and hardware resources permit it. A copy and a kernel can still serialize if they use the same resource or if an event establishes an ordering constraint.
Two timing events in one stream describe positions in that stream. Work submitted elsewhere is included only when dependencies make the end event wait for it. To time a multi-stream pipeline, place explicit events at the relevant joins or use a synchronized end-to-end boundary that covers the complete dependency graph.
Synchronization changes scheduling
A synchronization call blocks until a specified set of work completes. Placing one inside every loop iteration prevents the host from building a queue and can eliminate overlap across kernels, copies, or requests. The resulting workload differs from an asynchronous production pipeline.
Synchronize before a measured interval when you need a known empty starting state, and after the final boundary when you need confirmed completion. Do not add intermediate waits unless the production dependency graph contains them or the experiment specifically studies serialized execution.
Warm the same path that you measure
Warm-up can trigger graph compilation, library initialization, algorithm selection, allocator growth, page mapping, cache fills, and device clock changes. A warm benchmark should execute the same shapes and control path that the measured phase will use, then synchronize before recording the first event.
Warm-up cannot be applied indiscriminately. Dynamic shapes can compile new variants during production. A cache-sensitive service can alternate hits and misses. Measure these cases according to their frequency or report them separately. A warm kernel microbenchmark supports a mechanism claim, not a universal end-to-end claim.
Worked example: Comparing launch time, device time, and end-to-end time
A host timer reports 12 microseconds around a PyTorch operation. The calling application waits about 4 milliseconds before it can consume the result.
- Confirm that the original host timer stops immediately after the API returns. The returned tensor represents scheduled work; it does not establish that device execution has finished.
- Complete warm-up and synchronize so earlier work cannot enter the interval. Record a CUDA event before the operation and another after it on the same stream. Synchronize after recording the end event and query elapsed time. Suppose the result is 3.2 milliseconds.
- Measure host completion from a known starting state: synchronize, start a host timer, submit the operation, synchronize on completion, and stop the timer. Suppose this controlled interval is 3.45 milliseconds. The difference from event time contains dispatch and host synchronization costs.
- Measure the real request path without adding new intermediate synchronizations. Suppose it remains 4.0 milliseconds. Inspect the trace for queueing behind prior GPU work, data transfer, CPU scheduling, and downstream consumption.
- Check whether the device operation overlaps CPU preprocessing or another stream in production. Its 3.2-millisecond event duration can contribute less than 3.2 milliseconds to request latency when part of it is hidden by independent work.
Conclusion: All three numbers can be correct: 12 microseconds to enqueue, 3.2 milliseconds on the device interval, and 4 milliseconds experienced end to end. The error was not the clock but the unnamed boundary.
Common errors
- Treating API return as operation completion. An asynchronous launch can return before the device begins the submitted work.
- Synchronizing inside every iteration. This serializes the workload and can remove launch overlap, stream concurrency, and batching behavior.
- Using events in one stream to claim timing for a multi-stream application without checking cross-stream dependencies.
- Assuming concurrent execution always reduces critical-path time. Concurrent kernels can slow each other when they contend for the same resource.
Reference summary
Server code on the central processing unit submits a CUDA-kernel command and usually regains control before the graphics processing unit finishes the command. A CPU clock stopped immediately after launch therefore measures submission rather than completion. CUDA events receive GPU timestamps when an ordered stream reaches them. A synchronized CPU timer measures how long the calling path waits for the declared GPU work to finish. Select the timing method whose endpoints match the engineering question.
# PyTorch device-time sketch
start = torch.cuda.Event(enable_timing=True)
end = torch.cuda.Event(enable_timing=True)
for _ in range(warmup):
fn(x)
torch.cuda.synchronize()
start.record()
for _ in range(iters):
fn(x)
end.record()
torch.cuda.synchronize()
ms_per_iter = start.elapsed_time(end) / itersA synchronization operation adds a dependency. The added wait can prevent overlap between kernel launches, memory copies, CPU preparation, or separate CUDA streams. Complete warm-up before the start event, enqueue the production sequence without extra waits, and synchronize after the final event. Measure the real request path separately when scheduler waiting, CPU work, or data transfer contributes to user-visible latency.
Knowledge check
A CUDA-event interval correctly reports 3.2 milliseconds while the request log reports 7.8 milliseconds. Which work can exist outside the CUDA events, and which metric answers what the user experienced?
Show the answer guide
- The 3.2 ms CUDA-event interval contains only work ordered between the two events on the measured device stream. The event interval can correctly exclude earlier queueing, CPU tokenization, scheduler decisions, allocation, and launch preparation.
- Host-to-device copies, work in unrelated CUDA streams, distributed synchronization, or later device operations can also fall outside the event pair unless explicit dependencies place them inside.
- After the end event, sampling, detokenization, response buffering, host processing, and network delivery can add time before the request log records completion.
- The 7.8 ms request-log interval answers what the user-facing request path experienced when its endpoints are request arrival and response delivery. The CUDA-event interval answers how long the selected GPU region took.
- A joined CPU/GPU timeline with request, stream, and batch identifiers is needed to allocate the 4.6 ms difference rather than assigning all of it to launch overhead.
Measure asynchronous submission and completion
Use a thread or process executor to submit a deterministic task that hashes a fixed buffer repeatedly for approximately 50 ms. Measure submission-return time, wait-for-result time, and total caller-observed time across 30 runs while verifying the digest.
Evidence to keep: Keep the raw three-boundary timing log, digest test output, median submission and completion intervals, and a timeline sketch explaining which work continued after submission returned.
An optimization is invalid if its output exceeds the allowed error. Verify timing and numerical correctness for the same implementation.
Sources and further reading
The lesson explanations synthesize primary papers and official references. Follow the originals for proofs, exact APIs, architecture details, and version-sensitive behavior.
- CUDA C++ Best Practices Guide↗
- NVIDIA Nsight Systems User Guide↗
Official reference for capturing and reading CPU, CUDA API, GPU workload, and communication timelines.
- PyTorch Profiler documentation↗
Official reference for recording operator activity, CPU and accelerator events, shapes, stacks, and exported traces.
- MLPerf Inference Rules↗
- MLPerf Training Benchmark↗