Measuring TTFT and TPOT with a Local vLLM Server

In the first One Layer Down run, I loaded TinyLlama with vLLM on a Colab T4 and generated 100 tokens. That was useful because it proved the basic path: GPU, CUDA, PyTorch, vLLM, model weights, tokenizer, and one successful generation.

But it was not the latency measurement I actually needed.

When an application calls a model, it can wait for the full answer and show it all at once, or it can stream partial output as the model generates. If I choose streaming, two new questions matter. How long does the chat user wait before seeing that the model has started responding? And once the answer starts, how quickly does the rest of it appear?

For an application engineer, this is the latency that shapes the chat experience: whether the user sees an immediate response, and whether the rest of the answer arrives at a usable pace.

The first run used vLLM’s offline LLM.generate API. That gave me total generation time and aggregate throughput. It proved that the engine could produce 100 tokens, but it collapsed the whole request into one elapsed-time number. It did not separate the wait before the answer started from the pace after generation was underway.

In inference serving, those questions have specific names.

TTFT: time to first token
TPOT: time per output token after the first token

Those definitions sound simple until you try to measure them from outside the engine.

In this experiment, TTFT is client-observed. The timer starts before the HTTP request is sent and stops when the client receives the first non-empty generated text event. That includes request transport, server parsing, queueing, prefill, first-token production, response serialization, flushing, and client receive timing. That is why it maps well to user experience: “How long until I see the model start answering?”

An engine-internal TTFT measurement could start later, for example when the request enters the scheduler, and would exclude some HTTP and client overhead. I care about that later, but the first serving measurement should match what a chat caller can actually observe.

TPOT is narrower. Once the first token has arrived, TPOT asks how quickly the decode loop keeps producing the rest of the answer. That is closer to the steady-state rhythm of generation.

This distinction matters because two systems can have the same total generation time and feel different:

System A: slow first token, fast continuation
System B: fast first token, slow continuation

Aggregate throughput hides that difference. Streaming exposes it.

So the second run changed the shape of the experiment: instead of calling vLLM in-process, I started vLLM as an OpenAI-compatible HTTP server and used a streaming client.

The Setup

I stayed on Google Colab with a Tesla T4. For now, Colab is enough as the remote GPU machine.

The model stayed the same:

TinyLlama/TinyLlama-1.1B-Chat-v1.0

The serving command was:

python -m vllm.entrypoints.openai.api_server \
  --model TinyLlama/TinyLlama-1.1B-Chat-v1.0 \
  --dtype half \
  --max-model-len 1024 \
  --host 127.0.0.1 \
  --port 8000

Then the client sent a streaming completion request to:

http://127.0.0.1:8000/v1/completions

The prompt was unchanged:

KV caching helps inference servers because

Keeping the prompt and model fixed makes this a small step from the first run, not a new experiment hidden inside three other changes.

What Changed

The offline path looked like this:

Python process -> vLLM LLM.generate -> final response

The streaming path looks like this:

HTTP client -> vLLM OpenAI-compatible server -> server-sent event stream

That extra boundary matters. It is closer to how an application would actually call an inference server, and it exposes the timing shape that aggregate throughput hides.

The measurement client timestamps:

request_start: before sending the HTTP request
first_text_event: first streamed event containing generated text
later_text_events: each later streamed event containing generated text
end: end of response stream

Then it computes:

TTFT = first_text_event - request_start
TPOT = (last_text_event - first_text_event) / (text_event_count - 1)

That second formula is intentionally written as text_event_count, not token_count. That distinction became the most useful lesson in the run.

What The Client Has To Observe

If the client waits for the full response body, then the first-token boundary is gone. The client only sees:

request start -> full response received

For this measurement, the client has to observe the response while it is being produced:

request start -> first streamed generated text

In vLLM’s OpenAI-compatible API, that means setting:

{
  "stream": true
}

and reading the server-sent event stream line by line.

The important client behavior is to ignore protocol events that do not contain generated text. Some streaming APIs send setup chunks, role chunks, empty deltas, or completion metadata. Those should not count as the first token.

For this run, TTFT starts at the first non-empty generated text event. TPOT is measured from the spacing between later non-empty generated text events.

The Result

The saved result was:

The first-pass conclusion:

TTFT was about 1 second.
After the first token event, streamed output arrived about every 10 ms.

That is a much more useful serving result than the previous “100 tokens in 3.97 seconds” offline number. The offline number said the engine could generate. The streaming number starts to describe what a user or downstream application would feel.

A Repeat Run Moved TTFT

I reran the same one-command script without changing the prompt, model, endpoint, or requested output length. I did not commit this second result as a benchmark artifact, but the numbers are useful as a reminder:

I would not read too much into a two-run comparison. The useful observation is that the repeated run did not produce identical numbers.

TTFT moved more than TPOT in this pair of runs. That makes intuitive sense, but it is not a conclusion yet. The first-token path includes more than decode: request handling, scheduling, prompt prefill, first-token production, serialization, and stream flushing. Once the response is already flowing, the per-event spacing is closer to the steady decode loop.

The careful takeaway is not “TTFT is noisy and TPOT is stable.” The takeaway is: single-run latency numbers are weak evidence. The next harness should run multiple repetitions and report raw rows plus summary stats like min, median, and p95.

The Token Counting Problem

I initially wanted to write “TPOT was 10 ms per token.” That is probably close for this run, but it is not the most precise claim yet.

The client measured streamed text events. An HTTP streaming event is not guaranteed to equal one tokenizer token.

This is where the measurement gets slightly weird.

The model thinks in tokens. The HTTP client sees bytes, lines, JSON objects, and text fragments. The streaming API bridges those worlds, but it does not necessarily preserve a one-token-per-message boundary.

A server might emit:

event 1: "KV"
event 2: " caching"
event 3: " helps"

That looks like one token per event.

But it might also emit:

event 1: "KV caching"
event 2: " helps inference"

Or even awkward text boundaries:

event 1: " cach"
event 2: "ing"

The stream is a transport interface. The tokenizer is the model interface. Those are related, but they are not the same contract.

That means there are really three things I could report:

time per streamed text event
time per tokenizer-counted output token
exact time per generated token inside the engine

The first one is easiest from a normal HTTP client. The second one is better, but still imperfect if one HTTP event contains multiple tokens. The third one is the cleanest, but it requires engine-level instrumentation or a server contract that emits exactly one token per event with timestamps.

In this specific run, the numbers lined up:

Max tokens requested: 100
Non-empty streamed text events observed: 100

So “10 ms per output event” is a reasonable first approximation for TPOT. But the more careful statement is:

TPOT is currently approximated as time per non-empty streamed text event.

A stricter version of the harness should tokenize the generated output with the same model tokenizer and report both:

streamed text events
tokenizer-counted output tokens
event-based TPOT
token-count-based TPOT

That gives me two useful levels of measurement. From outside the server, I can measure client-observed event spacing: how quickly text appears to the caller after the first chunk. That is the right user-facing serving metric, but it is only exact per-token TPOT if each streamed event carries one generated token.

For exact per-token TPOT, I need either a server contract that streams one token per event or engine-level instrumentation that timestamps generated tokens inside the decode loop.

That is the systems lesson: the metric name lives at the model layer, but this first measurement is taken at the transport layer.

What I Know Now

The first offline run answered one question: can I load the model and generate tokens on a real GPU?

The streaming run answered a different question: what does the serving path look like from the caller’s point of view?

It also exposed the next measurement problem. A chat client observes streamed text events, while the model runtime generates tokens. Those are close enough for a first result, but not identical enough for a careful benchmark.

The Client Observer Script

The useful part of the client is small. It sends a streaming request, ignores empty protocol chunks, and timestamps the non-empty text events:

start = time.perf_counter()

with urllib.request.urlopen(request, timeout=300) as response:
    for raw_line in response:
        line = raw_line.decode("utf-8").strip()
        if not line or not line.startswith("data: "):
            continue

        data = line.removeprefix("data: ").strip()
        if data == "[DONE]":
            break

        payload = json.loads(data)
        text = extract_text(payload)
        if not text:
            continue

        token_times.append(time.perf_counter())
        pieces.append(text)

The metric calculation is also small:

output_events = len(token_times)
ttft = token_times[0] - start
tpot = (token_times[-1] - token_times[0]) / (output_events - 1)

Next

The next version of this measurement needs two improvements.

First, token accounting should be stricter. I want to report both the number of streamed text events and the number of output tokens counted by the model tokenizer. That will make the difference between event-based TPOT and token-count-based TPOT visible instead of implied.

Second, the harness should stop treating one run as evidence. The next result should run several repetitions of the same prompt and report the raw rows alongside min, median, and p95.

After that, I can start varying the inputs: same prompt with different output lengths, then different prompt lengths with the same output length. That should start to separate the latency effects of processing the prompt from the latency effects of generating the answer one token at a time. I will unpack those phases, usually called prefill and decode, in the next note.

That is where the inference papers start to become less abstract. KV cache is no longer just a concept. It shows up as memory, first-token delay, and the rhythm of streamed output.