Latency assertions

Latency is the one property in this topic that an eval suite cannot read off the response. Token counts arrive in the usage block, tool calls arrive as blocks, and both come out the same however you ran the case. A duration has to be measured, and a measurement taken on a shared machine under uncontrolled load is partly a measurement of the machine: the thing being benchmarked contributes some unknown fraction of the number, and nothing in the number says which fraction. Engineers who have written microbenchmarks recognise the shape immediately, and the usual response there — pin the CPU, warm the JIT, the just-in-time compiler that runs a code path slowly until it has seen it a few times and quickly afterwards, repeat until the variance is small enough to make claims from — transfers with one amendment: the shared machine belongs to somebody else and you cannot pin it.

A single four-second number comes apart into seven things, some of which your own harness created and some of which the provider contributed. A per-case threshold on the total fails whatever value you set — the arithmetic of a long-tailed distribution across fifty cases guarantees it. What replaces it is two assertions with different properties: deterministic bounds on token counts and call counts, which carry most of the value and cannot be contaminated, and a median over repeats in a deliberately quiet lane for the part that genuinely belongs to the provider. The number such a lane produces is not what a user will experience and gets quoted as though it were.

What is in a 4.12 second measurement#

A suite firing fifty cases concurrently from one CI runner produced this on a weekday afternoon:

FAILED refund_partial_damaged     - latency 4.12s exceeded 3.00s
FAILED order_lookup_happy_path    - latency 3.88s exceeded 3.00s
FAILED address_change_in_transit  - latency 6.41s exceeded 3.00s
FAILED policy_question_returns    - latency 3.31s exceeded 3.00s
... 4 more

That measurement was taken with a stopwatch around the whole call, which is to say around several things that are not generation. Here it is beside the same cases on a quiet weekday morning:

Two rows account for almost the whole difference, and both are consequences of running fifty requests at once from a single process. The retry sleep is the larger of the two: an organisation with a rate limit expressed in tokens per minute will start returning 429s when fifty cases each carrying a 3,400-token prompt arrive within a second of each other, and a well-behaved client responds by sleeping for the interval the retry-after header names. That sleep is your suite waiting for your own burst to clear, and counting it as the model's latency is a category error. The connection-pool row is the same phenomenon one layer down — a default httpx client keeps twenty keep-alive connections, so the requests beyond the twentieth queue behind them.

The provider-queueing row is real, outside your control, and time-of-day dependent, which is what makes a single-threshold assertion on wall-clock unfixable rather than merely noisy.

Reading that table as a subtraction — total minus the rows you caused — is only legitimate because of a property of the measurement that is easy to assume without noticing. The seven rows are consecutive spans of one timeline rather than seven activities happening alongside each other. A request cannot be waiting for a free connection and in flight at the same time, it cannot be asleep in backoff and generating at the same time, and the client cannot parse a body it has not received yet. Disjoint spans laid end to end sum to the interval they cover, which is why each column adds to its own total and why striking out a row leaves a duration that is still a span of something. Two overlapping rows would break both properties at once: the column would double-count the overlap, and the remainder after subtraction would not correspond to any stretch of clock. The same property is what makes provider_ms further down this chapter a legal addition of two numbers rather than an estimate.

Getting the retry row into that table at all requires a hook, because the official SDKs retry transparently by default — typically two attempts with exponential backoff and jitter — and the caller sees one method call that took 2.9 seconds with no indication that 1.4 of them were spent asleep. That is the correct behaviour for a production client, and it is why the run record of chapter 3 carries retries and retry_sleep_ms as fields you have to populate deliberately, usually via the client's event hooks or by disabling built-in retries and running your own loop. A team that has never separated these numbers will look at their timing failures and conclude the model got slower, because from inside the SDK that is exactly what it looks like.

Why one sample against a threshold fails whatever you set#

Even with the self-inflicted components removed, provider latency is a long-tailed distribution rather than a number. A representative shape for a 350-token completion on a mid-sized model is a median around 1.9 seconds, a p95 around 4.4 seconds, and a p99 that runs past 9 seconds during regional incidents. Set the threshold at 3 seconds and roughly one call in twelve exceeds it on a normal day.

Those three figures are not properties a provider publishes. They are statistics computed from a pile of measurements you took, and how they are computed is what makes them behave so differently from one another. Take the durations of however many calls you made, sort them from fastest to slowest, and read off the value standing a given fraction of the way up the sorted list. The median is the value with half the list at or below it: with an odd number of measurements it is the middle one, and with an even number it is conventionally the midpoint of the two in the middle. The p95 is the value with ninety-five percent of the list at or below it, and the p99 the value with ninety-nine percent below. Beyond that midpoint convention nothing is averaged at any point, and no value outside the one position being read contributes to the answer at all. A percentile is a position in an ordering, so one absurd measurement can push every other value one place along the list and cannot drag the reported number the way it would drag a mean.

Positions in a sorted list are also what turn a threshold into a failure rate, and that step is the link between the shape of the distribution and the colour of the suite. The 3-second threshold sits between the median of 1.9 seconds and the p95 of 4.4, so by construction more than five percent of calls exceed it and fewer than half do. Where in that band this particular distribution lands is the one call in twelve quoted above, because the fraction of the sorted list above the threshold is the fraction of calls that fail the assertion. One divided by twelve is a bit over eight in a hundred, which is where the 8% in the next paragraph comes from; the rate and the probability are the same fact stated twice.

That per-call probability is where the flakiness comes from, and the arithmetic is unforgiving. With a per-case exceedance probability of 8% and fifty timed cases in a suite, the chance that at least one fails is one minus 0.92 to the fiftieth, which is 98.5%. Such a suite is not occasionally flaky; it is essentially guaranteed to be red, and the only reason it is ever green is that off-peak conditions move the whole distribution left. Raising the threshold to 6 seconds drops the per-call probability to about 1% and the per-suite probability to 40%, which is still a coin flip, and by then the assertion is so loose that a genuine doubling of latency passes it.

That expression is worth building rather than accepting, because every term in it corresponds to a decision somebody made. If a case exceeds the threshold eight times in a hundred it comes in under the threshold the other ninety-two, and ninety-two in a hundred written as a fraction of one is the 0.92. A run is green only when the first case comes in under the threshold, and the second, and so on through the fiftieth, so the probability of a green run is the probability of that whole conjunction. Multiplying the fifty per-case probabilities together is the step that needs a licence, and the licence is independence: a product gives the probability that several things all happen only when knowing how one turned out tells you nothing about the others. Fifty identical factors multiply to 0.92 raised to the fiftieth power, which is around one and a half in a hundred, and everything else — the 98.5% — is the chance of at least one failure. Raising the threshold to 6 seconds changes one input and nothing else: a per-call probability of about 1% leaves ninety-nine in a hundred per case, and the fiftieth power of that is around three chances in five of a clean run, which is the 40% failure figure from the other side.

The number of timed cases is doing as much work in that result as the threshold is, and this is the part teams miss when they read the suite as a measurement of the model. The exponent is the case count. Time ten cases instead of fifty and the chance of a red run falls to something nearer a coin toss on a system that has not changed speed at all; add twenty more cases and the suite gets redder the same way. That is the signature of an assertion about a maximum. It claims that every draw is under the bound, so every additional draw is another chance to refute it, and a suite that grows becomes a suite that fails.

Independence is also the assumption this particular suite violates, which is worth saying rather than quietly relying on. The fifty cases go out at once, through one connection pool, to one provider, under one rate limit. When the provider queues it queues all of them, and when the runner is starved it starves all of them, so the outcomes move together rather than separately. Outcomes that move together make a fully green run more likely than the multiplication says, since the fifty are more often good together or bad together than fifty independent draws would be. That does not rescue the assertion; it changes the texture of the failure. Instead of a steady 98.5% it produces runs that are either clean or catastrophically red, which is the pattern most likely to convince a team that timing failures are weather and should be re-run. Read the figure as what the flake rate would be if the cases were independent, and as a bound on the trouble rather than a forecast of it.

Two kinds of claim are available here, and they are not a strong and a weak version of the same thing. total_ms <= 3000 on every case is a claim about a maximum: no draw exceeds the bound, and a single draw refutes it. A claim about a percentile — median(provider_ms) <= 3500 in the table further down — says that when enough draws are collected and sorted, the value in the middle sits under the bound. One slow draw cannot refute that, because moving one value in a sorted list moves the middle of the list by at most one position, and the neighbours of the middle are close together. Refuting it takes a shift in a large share of the draws, which is a statement about the system rather than about an afternoon. The price is exactly what the maximum claim was good at: a percentile assertion will never tell you that one request took several times the median, and if that matters it has to be asserted separately and accepted as the flakier of the two.

The escape is to stop treating latency as a per-case pass/fail on one sample and to split it into two assertions with different properties. One is a claim about figures you control and that do not move with load. The other is a claim about the provider's contribution, measured under conditions you have deliberately made quiet, aggregated over repeats.

The measurement that holds still#

Start by measuring a span that excludes your own waiting:

@dataclass
class CallTiming:
    queued_ms: int          # time waiting on the semaphore / pool
    retry_sleep_ms: int     # summed sleeps between attempts
    ttft_ms: int            # request sent -> first stream event
    decode_ms: int          # first event -> last event
    total_ms: int

    @property
    def provider_ms(self) -> int:
        return self.ttft_ms + self.decode_ms

    @property
    def tokens_per_second(self) -> float:
        return self.output_tokens / (self.decode_ms / 1000)

provider_ms is the number worth asserting on, and it is only trustworthy if the request was not queued behind your own traffic — which is why the fix is procedural as well as arithmetical. Timing cases run in their own lane:

TIMED = [c for c in cases if c.timing]        # ~20 of 300

async def run_timing_lane(client, cases, repeats=5):
    sem = asyncio.Semaphore(2)                # not 50
    results = defaultdict(list)
    for _ in range(repeats):
        for case in cases:
            async with sem:
                t = await run_case(client, case, retries=0)
                results[case.case_id].append(t)
    return {cid: statistics.median(ts) for cid, ts in results.items()}

Three choices in twelve lines. Concurrency is capped at two rather than fifty by the semaphore, a counter that admits only that many requests at a time and makes the rest wait, which removes the 429s and the pool queueing and costs about ninety seconds of wall time for twenty cases at five repeats. Retries are disabled rather than excluded, so a rate-limited attempt is an error the lane reports rather than a sleep folded into a duration. And each case is measured five times and reduced to a median, which takes a draw from a long-tailed distribution and turns it into a statistic that moves when the system changes and mostly does not move when it does not.

The third of those choices is the one most often written as a mean instead, and at this sample size the difference is the whole point of the lane. Five repeats of one case produce five durations, and sorted, the median is the third of them whatever the other four are. Suppose one repeat lands in the tail quoted earlier, at the p99 that runs past 9 seconds — more than four times the median of the distribution it was drawn from. A mean over five absorbs a fifth of that excess and rises by well over a second, which is enough on its own to cross a bound set anywhere near the median. The third-largest value does not move at all, because a tail draw sorts to the end of the list and the middle of the list is decided by the values on either side of it. The median is not a better estimate in general. It is the estimate that does not inherit the tail, and a long-tailed distribution is precisely the case where that is the difference between a statistic and a rumour.

Five repeats also settle which percentiles the lane is entitled to report at all, and this is where a suite most often overclaims. A percentile is pinned by the draws that fall above it, and by construction one draw in twenty falls above a p95. Five repeats therefore put an expected quarter of a draw above the p95: there is nothing in the sample holding that value in place, and any formula asked for it will hand back the largest of the five wearing a percentile's name. Collecting even five draws above a p95 needs twenty times as many repeats, and at ninety seconds of wall time for twenty cases at five repeats, multiplying the repeats by twenty is a different budget rather than a tweak. A median survives five repeats because half the sample sits on each side of it and the values around the middle of a sorted list are close together, so which draw happens to land third barely moves the number. That asymmetry is why the table below asserts on a median and a p50 and never on a p95: a lane may only assert the statistics its sample can support.

Pooling every measurement across cases to get a bigger sample looks like the way out of that and quietly changes the subject. The durations of twenty different cases are draws from twenty different distributions, because the case that decodes 350 output tokens and the case that answers in a sentence are not measuring the same thing. A percentile over the pool is therefore a percentile of the case mix as much as of the provider, and adding three long cases to the suite moves it without a single request having got slower. Per-case medians compared against their own history keep the question the same question from run to run.

Which twenty cases get the tag is a product question rather than a technical one, and the useful selection rule is to time the paths where a user is waiting. A support reply streamed into a chat widget is one; a batch classification job that runs overnight is not, however slow it gets, because nothing about its latency is visible to anyone. Timing every case is the instinct and it is wasteful in both directions, since five repeats at concurrency two across 300 cases costs about twenty-five minutes of CI and buys nothing on the 280 cases where the number has no consumer.

The ninety seconds and the twenty-five minutes come out of one division, and doing it makes the cost of a lane predictable before anybody runs it. Twenty cases at five repeats are a hundred requests, and at concurrency two they occupy fifty sequential slots; ninety seconds spread over fifty slots is under two seconds each, which is about what the Wednesday column of the first table says one request costs. Three hundred cases at the same repeats and the same concurrency occupy fifteen times as many slots, and fifteen times ninety seconds is the twenty-five minutes. Nothing about the second figure is a guess: the per-slot time is the same measurement, and only the count of slots changed.

The lane also needs a warmup call that is discarded, for the same reason a microbenchmark discards its first iterations. The first request pays a TLS handshake on a cold connection, the first request against a new JSON schema pays the grammar compilation described in chapter 2, and both land on whichever case happens to sort first — which is how a suite acquires one case that is mysteriously slower than its neighbours and stays that way through three refactors of its prompt.

What you assert then falls into two groups:

The first three rows are where most of the value sits, and they are the reason this chapter belongs beside the cost one. Decoding is sequential, so output length is the single largest term in latency that you control; a change that adds 400 tokens to the average answer adds roughly 1.5 seconds at typical throughput, and output_tokens reports that exactly, from the usage block, with no timing involved. Asserting on token counts is a latency assertion in a form that cannot be contaminated by your own concurrency.

The roughly 1.5 seconds in that paragraph is not a rule of thumb borrowed from somewhere else; it is the table at the top of this chapter divided through, and the division is worth watching. Decoding 350 output tokens took 1,310 milliseconds on the Tuesday and 1,240 on the Wednesday, so each token cost a little under four milliseconds on both days — the one row that barely moved while the total more than doubled. Four hundred further tokens at a little under four milliseconds each is around a second and a half. Dividing a duration by a token count is allowed here because the tokens are produced strictly one after another: each one is chosen, appended to the text, and only then does the model run again on the slightly longer text, so no two output tokens are generated at the same time and their times add. Turn the same figure the other way up and a little under four milliseconds a token is a couple of hundred tokens a second, which is what tokens_per_second on the dataclass above computes and why that property is worth recording per run.

The input side does not behave that way at all, and the asymmetry is why input_tokens and output_tokens protect against different things despite looking like the same assertion. The prompt is processed in one pass over all of its tokens together rather than one at a time, so doubling the prompt adds far less time than doubling the answer does. What a growing prompt costs you is money, cache pressure and room in the context window, which is the subject of chapter 5 on per-case token and cost ceilings. What a growing answer costs is wall-clock time in direct proportion. A suite that wants a latency assertion it can trust wants a ceiling on output length ahead of almost anything else, and that is the sense in which the first three rows carry the value.

"Fully deterministic given the run" in that table is carrying a qualifier that repays reading, because the unqualified version is the sentence a reader would write afterwards and it is not true. The count is a deterministic function of the bytes: the same request and the same response tokenise to the same numbers on any machine, at any hour, under any concurrency, since counting the items in a list consults no clock and competes for no shared resource. What is not fixed is which bytes come back. The picking step inside the model samples, so a second run of the same case can produce a longer answer, and a case whose output usually sits just under a 500-token ceiling will cross it eventually with nothing having changed. The assertion is a ceiling on a distribution of lengths rather than on a constant. What keeps it from flaking is where the ceiling is set: a bound a hair above today's value is a tripwire for sampling noise, while one that would only be crossed by an answer half as long again is a tripwire for a prompt change, which is the thing you wanted to catch.

Where a provider exposes its own processing time in a response header — openai-processing-ms is the common example — record it, because it is the cleanest available separation of their time from yours. Where none is exposed, the streaming-derived ttft_ms and decode_ms are the nearest equivalent, and they are honest only under the low-concurrency lane, since a request stuck in your connection pool has not been sent yet and its first token cannot arrive.

The gap between the lane and production#

The number the lane produces is not what a user will experience, and treating it as such is the second-order version of the same mistake. Production streams to a browser, so the user-visible latency is time to first token plus reading speed, and total generation time barely matters; the lane measures completion of the whole response. Production has a warm prompt cache at real traffic rates, which cuts input processing substantially; the lane runs cold. Production runs in one region against a provisioned throughput commitment; CI runs wherever the runner is. Each of those differences is worth a factor rather than a percentage.

The size of the first one is legible in the table this chapter opened with. Time to first token was 340 milliseconds once the request was scheduled, while decoding the answer took 1,310, so a reader watching a streamed reply starts reading after a duration several times smaller than the one the lane records for that same request, and the rest of the generation happens under their eyes rather than in front of a spinner. A lane median of three and a half seconds and a user who waits about a third of a second are compatible descriptions of one system. Quoting the lane's figure in a conversation about user-visible speed is not a conservative estimate; it is a different quantity with the same units.

What the lane gives you is a regression signal: the same measurement, taken the same way, before and after a change, so that a doubling shows up as a doubling. Answering whether the system will be fast enough for users at peak needs a load test against the real path at realistic concurrency, and that is a different instrument with a different budget. An eval suite's job is to notice that a diff made things slower and to say so during review; it cannot certify a latency SLO — a service level objective, the response time the product commits to and is measured against — and a team that believes it can will be surprised at the first traffic spike.

The honest limitation is that the provider's contribution stays outside your control no matter how carefully you measure it. That is what makes the split worth the trouble rather than a refinement: the assertions that block a merge are the ones whose inputs are entirely yours — how many tokens the prompt carries, how long the answer is, how many round trips the loop makes — and every one of them is read from the usage block with no clock involved. The timed lane is a diagnostic that reports to a dashboard, and it is honest only because it was made quiet on purpose and repeated enough times to have a median.

Every check across these six chapters now has a definition and a place to run. None of them has yet been shown to be capable of failing, and a green suite looks identical whether its assertions are protecting behaviour or merely executing.