IIntroduction to AI Systems Performance EngineeringTechnical textbook
Chapter 17: Inference Execution and Metrics
17.1

Inference request timeline

Assign every millisecond to a serving phase

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.

  • Time to first token and inter-token latency
  • Queueing delay

Use a concrete service throughout this lesson: one 7-billion-parameter language model runs on one GPU with 80 GiB of device memory. At 10:00:00.000, a client sends a 2048-token prompt and asks for at most 256 output tokens. The client receives the first text bytes at 10:00:00.780 and the final bytes at 10:00:06.200. The two client timestamps do not reveal where the first 780 milliseconds or the later token gaps occurred.

Instrument the gateway, tokenizer, request scheduler, model executor, sampler, and streaming connection with a shared request identifier and monotonic timestamps. The server's event log becomes a request trace: a timestamped record produced by those explicit instrumentation points. Nsight Systems separately records CPU and GPU execution events. Batch and iteration identifiers connect each GPU launch to the requests that received work from that launch.

A request can wait before the GPU ever sees it. A gateway authenticates and routes it; an admission controller may hold it; a scheduler waits for a compatible token batch; tokenization and host logic prepare inputs; prefill produces the first token; decode repeats model and sampling work until completion. Looking only at device time leaves the unexplained intervals where users often wait longest.

A request timeline assigns every interval to a stage and records dependencies among stages. The timeline also separates latency metrics with different meanings. Time to first token reflects queueing, setup, and prefill. Time per output token reflects decode cadence and interruptions. End-to-end latency includes output length and downstream work. Averages across these metrics cannot substitute for their distributions.

The timeline must follow the same request across gateway, scheduler, host workers, GPU batches, and the streaming connection. A GPU trace alone groups work by batch, while the user experiences one request spread across many batches. Request, sequence, batch, and iteration identifiers connect those two views.

Define the request boundaries

Record monotonic timestamps for network arrival, authentication completion, admission decision, scheduler enqueue, first scheduling decision, prefill start and end, first sampled token, first streamed byte, decode intervals, final token, and response completion. Use monotonic time for durations so clock adjustments do not create negative intervals. Distributed services also need synchronized clocks or a trace system that records causal order.

The first streamed byte can occur after the model produces its first token because sampling, detokenization, buffering, or network backpressure adds delay. Time to first token should therefore name its measurement boundary. A server-internal TTFT and a client-observed TTFT are both useful, but they are not interchangeable.

Decode cadence can be recorded per gap or summarized per request. The common TPOT calculation divides the interval after the first token by the remaining output-token count. The per-request average can hide pauses caused by prefill interference or scheduler preemption. Preserve an inter-token gap distribution when smooth streaming matters.

Classify waiting by cause

A capacity queue forms when the serving pool has no execution slot for the request. Batch-formation delay is an intentional wait used to create a more efficient batch. Priority delay occurs when another class is scheduled first. Memory admission delay occurs when the request cannot reserve enough KV blocks. Capacity, batching, priority, and memory delays can all appear as queue time, but they require different changes.

A request can also wait while it is active. Decode work may skip an iteration because another class consumes the token budget. A preempted request may wait and later recompute lost KV state. A distributed worker can wait for another rank. Attribute these intervals to the scheduler or dependency that withheld progress rather than adding them to kernel time.

Queue length alone does not identify the condition. Record the reason for each transition between waiting, running, preempted, blocked, and completed states. The resulting state history lets a slow request be explained without guessing from aggregate utilization.

Analyze distributions without selection bias

Latency depends strongly on prompt length, generated length, cache-hit tokens, request class, and offered load. Report conditional distributions for these dimensions, then weight them by the target workload when a single service summary is needed. A p99 dominated by intentionally long batch requests should not be applied to a short interactive class, and the long class should not be removed from the overall capacity calculation.

Cancellation creates selection bias. If a user abandons a slow request before completion, that request may disappear from a completion-only latency sample. Record admitted, rejected, canceled, timed-out, failed, and completed populations from arrival. Include work performed before cancellation because it consumed capacity.

Tail events often combine mechanisms. A long prompt may miss the prefix cache, occupy a large prefill chunk, trigger KV eviction, and delay decode for other requests. Correlate phase durations and state changes for the same interval. The result should explain both the affected request and the requests that shared its batches.

Worked example: Explaining a slow first token

Median time to first token is 450 ms, but p99 is 3.2 seconds. Prefill kernels for p99 requests take only 600 ms.

  1. Break p99 requests into queue, tokenization, prefill, and streaming intervals. Discover 2.1 seconds of scheduler delay before prefill begins.
  2. Condition on prompt length and arrival time. Many affected requests arrive behind a small number of very long prefills.
  3. Introduce chunked prefill or a scheduling budget that interleaves decode and shorter prefill work. Predict added overhead versus reduced blocking.
  4. Replay the same arrival and length trace. Verify p99 TTFT, ongoing decode TPOT, throughput, and error behavior together.

Conclusion: The 600 ms prefill explains only part of the 3.2 second tail. The request spends 2.1 seconds waiting behind long prefill work. Chunking or a token-budget policy must be evaluated for its effect on that wait, on decode cadence, and on total GPU efficiency.

Common errors

  • Subtracting GPU kernel time from end-to-end latency and calling the remainder CPU overhead. Queueing, network, and asynchronous dependencies need separate attribution.
  • Reporting one TPOT averaged over all tokens. Interruptions and per-request tails matter to streaming experience.
  • Conditioning on output length after completion without considering cancellation and timeout bias. Slow requests may disappear from the sample.

Reference summary

E2E latency = admission + queue + preprocess + prefill + decode steps + postprocess + network

Record a monotonic timestamp at every transition from request arrival to response completion. Use request, sequence, batch, and scheduler-iteration identifiers to join host events with GPU execution. The joined timestamps reveal whether a slow request waited for admission, prompt processing, available KV blocks, a decode iteration, or network delivery.

Define every latency metric by its measurement boundary. Server time to first generated token and client time to first streamed byte differ by sampling, detokenization, buffering, and network delay. Preserve inter-token gaps when a per-request TPOT average would hide pauses.

  • TTFT: arrival to first output token; sensitive to queue and prefill.
  • TPOT/inter-token latency: cadence after first token; sensitive to decode scheduling and batch execution.
  • E2E: user-observed completion; depends on output length and streaming behavior.
  • Goodput: requests, tasks, or tokens that meet declared quality and latency objectives per second; name the numerator explicitly.
  • Queue depth and admission rejection: load signals that explain latency behavior.

Knowledge check

Two systems have equal output tokens/s. What four additional facts do you need before choosing one for an interactive agent?

Show the answer guide
  • First, require the time-to-first-token distribution, including p50, p95, and p99, because an agent cannot act until prompt queueing and prefill finish.
  • Second, require the inter-token or time-per-output-token distribution for individual requests, including stalls, because aggregate output tokens per second can hide slow or irregular streams.
  • Third, require the workload and offered load used to obtain the number: prompt lengths, generated lengths, cache hits, request classes, arrival pattern, concurrency, and whether the service was below or above saturation.
  • Fourth, require goodput and failure information under a declared objective: the fraction of requests that meet TTFT and TPOT limits while completing correctly, plus rejection, cancellation, timeout, and error rates.
  • Compare model quality and response semantics as a separate gate if the two systems do not run the same model and decoding policy; faster incorrect or lower-quality output is not equivalent work.
Practice

Reconstruct an interactive request timeline

Replay a declared trace of 500 requests against one model server with prompt lengths split among 128, 1024, and 8192 tokens and generated lengths of 32 or 256 tokens. Run the trace at 30%, 70%, and 110% of measured maximum arrival rate. Record arrival, admission, prefill start and end, every streamed-token timestamp, completion, cancellation, and error for each request.

Evidence to keep: Submit the workload trace, request-level event log, latency histograms for TTFT and TPOT by load and length class, a throughput-versus-goodput table, and one annotated slow-request trace that attributes time to queueing, prefill, decode gaps, and streaming. State whether aggregate tokens per second would have selected the same operating point.

The request timeline identifies waiting time. The next section calculates how model weights, KV state, workspaces, and fragmentation limit active-request capacity.

References

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.

  1. MLPerf Inference Rules↗
  2. Orca: Iteration-Level Scheduling↗
  3. PagedAttention / vLLM↗
  4. NVIDIA Nsight Systems User Guide↗

    Official reference for capturing and reading CPU, CUDA API, GPU workload, and communication timelines.