Time to success splits into model calls, tool waits and retries

Two measurements of the same agent can both be correct and describe experiences a minute apart. A platform dashboard reporting mean model call duration is measuring one component of one step; a customer waiting for a reply is measuring everything between their message and the answer. Those are different quantities over different intervals, and on a tool-calling agent the second is routinely an order of magnitude larger than the first.

The measure that closes the gap is time to success: the clock from the moment a task becomes available to the system until it is resolved to a fixed criterion, with retried runs, the queueing between attempts and the human handoff all inside the interval. It is the twin of cost per successful task and it resists the same trick for the same reason — a run that fails quickly improves every duration average you have, and it improves nothing about when the customer got their answer. What makes the measure useful rather than merely honest is that a run's share of it comes apart into pieces that different techniques move.

What a run's wall clock is made of#

A tool-calling loop is a strictly alternating conversation: the model emits a call, the process executes it, the result goes back, the model emits the next one. Nothing overlaps unless you make it overlap, so a run's duration is the sum of its parts and the critical path is the whole thing. That is the property that makes a decomposition possible at all, and it is worth checking rather than assuming, because an agent that dispatches tools concurrently has a different arithmetic.

For one resolved shipping-exception ticket — seven model calls and ten tool calls — the p50 successful run takes 71.4 seconds of wall clock, meaning the elapsed time between the customer's message and the reply rather than the time the process spends computing. Of that, 24.6 seconds is model generation, 33.8 seconds is waiting on tools, 4.2 seconds is queueing and rate-limit backoff at the provider, and 8.8 seconds is one in-run correction of the kind topic 10.6 covers. Those four add to the total exactly, which is the property to insist on: segments that are exhaustive and non-overlapping leave no room for a component to hide, and an unexplained residual is then evidence of something real rather than of sloppy accounting.

Backoff belongs in that list because a provider answers a request that exceeds its per-minute allowance with an HTTP 429 and an instruction to wait rather than with a result, and the waiting happens inside the customer's run.

Now put a dashboard's 3.5-second mean model call duration against that breakdown. Seven calls at three and a half seconds each is very close to the 24.6 seconds of generation, so the dashboard figure is not wrong about anything — it is accurate about a component that accounts for a third of the experience. The failure is one of scope rather than of measurement, and no amount of precision on that component would have revealed the other two-thirds.

Fixing the boundaries of the interval takes more care than it sounds like it should. It starts when the task becomes available to the system, not when a worker picks it up, because a five-minute queue in front of the agent is five minutes the customer waited. It ends when the outcome meets the criterion from the previous chapter, which for a ticket means the reply was sent and not reopened within 24 hours. Runs that were attempted and abandoned sit inside the interval, as does the gap between a failed run and its retry, and as does the human desk.

Under that definition the workload reads very differently at different percentiles: p50 is 74 seconds, p90 is 5 minutes 50 seconds, and p99 is 4.1 hours, and the shape of that curve is entirely determined by how often the agent hands off rather than by anything about model speed. The two-part structure is worth naming because it changes what an improvement is worth. Below about p85 the distribution is the agent's own run time and responds to the levers in this topic. Above it, the distribution is the escalation queue, whose median pickup is measured in hours, and it responds only to escalating less often.

Read a proposed change against both halves and its value stops being a matter of opinion. A change that shaves four seconds from every run moves p50 by 5% — four seconds against a seventy-four-second median — and p99 by nothing measurable, since four seconds is invisible against a tail measured in hours. A change that cuts escalations from 9% to 6% leaves p50 untouched, because it does not alter any run's duration, and pulls p99 down by more than an hour, because it moves tasks out of the half of the distribution where hours live. Teams that report a single mean latency number cannot see either effect clearly, which is how an iteration-cap change passes review as a latency improvement.

Where a minute actually goes#

The chart is a sequence, not a set of totals, and that is the reason to draw it. Every bar starts after the one before it ends. Reading it left to right is reading the critical path, and any bar you remove shortens the run by its own length — which is not true of a chart where bars overlap, and is the reason a decomposition of a sequential process is unusually actionable.

Breaking the tool half down by tool is where the actionable detail lives, because the total conceals two very different problems.

The last column is calls multiplied by p50, divided by the 33.8 seconds of tool wait, and checking one row is enough to make the rest readable: policy_retrieval is called twice at 8.2 seconds, which is 16.4 seconds, and 16.4 against 33.8 is a little under half. The six rows sum to the 33.8 exactly, which is the same exhaustiveness property one level down.

That column is why the ranking is not the ranking of the p50 column. carrier_tracking is slower per call than ledger_write by only a little, but it is called twice, so it carries more than twice the share. order_lookup is called three times and still finishes last in the table, because three calls of six tenths of a second is less than one call of anything else. Frequency and duration multiply, and a table sorted by duration alone would send you to the wrong tool.

Read the rows for gaps in the other direction too, between p50 and p95 within a row, because that gap measures something different from the share. policy_retrieval is slow and consistent: it gets called twice for 16.4 seconds — nearly a quarter of the whole run — fetching two sections of a document that changes weekly, and its p95 is under twice its p50. carrier_tracking has a p95 five times its p50, which means it is usually fast and occasionally terrible, so the tail of the run duration distribution is mostly one carrier's API having a bad afternoon. The first is a problem about the median; the second is a problem about p95; and no single column distinguishes them.

order_lookup is called three times per run and is nearly free, so batching it would be tidy engineering and would buy 1.2 seconds. Those three facts suggest three different interventions, and none of them is "parallelise the agent".

Recording the split without a rewrite#

The decomposition needs the loop to emit timings, which is a dozen lines if you are already carrying a span per step. What matters is that the segments are exhaustive and non-overlapping, so that they sum to the run's wall clock with nothing unaccounted; an unexplained residual is usually queueing you did not know you had.

@dataclass
class RunClock:
    model_ms: int = 0        # request sent -> final token received
    tool_ms: int = 0         # tool dispatched -> tool returned
    backoff_ms: int = 0      # 429 sleeps, provider queueing, connection retries
    correction_ms: int = 0   # model calls caused by a rejected tool call
    overhead_ms: int = 0     # serialisation, context assembly, logging

    def total(self) -> int:
        return (self.model_ms + self.tool_ms + self.backoff_ms
                + self.correction_ms + self.overhead_ms)

async def step(state: RunState, clock: RunClock) -> StepResult:
    t0 = perf_counter_ns()
    resp = await client.messages.create(**state.request())
    clock.model_ms += (perf_counter_ns() - t0) // 1_000_000

    for call in resp.tool_calls:
        t1 = perf_counter_ns()
        result = await dispatch(call)
        elapsed = (perf_counter_ns() - t1) // 1_000_000
        if result.rejected:
            clock.correction_ms += elapsed   # this wait bought no progress
        else:
            clock.tool_ms += elapsed
    return StepResult(resp, state)

The overhead_ms field exists so that total() can be compared against the run's measured wall clock and the difference forced to zero. Without a catch-all bucket the four named fields would silently under-report and nobody would know by how much.

Attributing a rejected tool call's wait to correction_ms rather than tool_ms is the other deliberate choice. It separates time spent doing the task from time spent recovering, and the ratio between them is a health signal: when correction time crosses about 15% of a run in this workload, the cause has always been a tool schema the model keeps getting wrong rather than a flaky dependency, and the fix is upstream of anything in this topic.

What the breakdown says about parallelism#

Fan-out only compresses work that can run at the same time, so its ceiling follows from one piece of arithmetic. Take a set of steps that do not depend on each other. Run sequentially they cost the sum of their durations; run concurrently they cost the longest of them, since the others finish inside that window. What concurrency can recover is therefore the sum minus the maximum, and no arrangement of threads improves on it.

Apply that to this run and there are two opportunities. The three order_lookup calls are genuinely independent of each other and total 1.8 seconds, of which concurrency could recover 1.2 — the sum less the longest of the three. The two carrier_tracking calls for a split shipment are independent and total 8.2 seconds, of which concurrency could recover 4.1, one of the two. Everything else is sequenced by data dependency: the eligibility check needs the policy section, the ledger write needs the eligibility verdict, and the reply needs all of it. The honest ceiling for parallelism here is 5.3 seconds out of 71.4, or 7.4%, and that is the ceiling assuming perfect overlap and no rate-limit interaction.

Compare that with what the same breakdown suggests elsewhere. Caching the policy document in the process for its weekly lifetime removes 16.4 seconds. Moving the two policy_retrieval fetches to a single call that returns both sections removes 8.2 seconds. Eliminating the in-run correction by tightening the tool schema removes 8.8 seconds plus a model round trip. Each of those is larger than the entire parallelism budget, and none of them introduces a race or a concurrency ceiling. Parallelism is the lever people reach for first because it is the one that feels like engineering, and on a run shaped like this one it is fourth or fifth in line.

The ordering in that table is specific to this workload and will not transfer. An agent whose tools are all sub-100-millisecond internal RPCs has almost no tool wait to recover and is dominated by generation time, so tiering and shorter outputs move it and caching a document does nothing. An agent that fans out over 40 documents in a research pass is dominated by a step that is embarrassingly parallel, and concurrency is the first lever rather than the fourth. The reason to build the breakdown before choosing is that the three archetypes are indistinguishable from the outside — all three are "the agent takes about a minute" — and the lever that works on one is close to a no-op on the others.

Two levers that show up in both columns#

A cache hit is faster as well as cheaper. When a request reuses a cached prefix, the provider does not re-run attention over those tokens, so time to first token — the delay between sending a request and the first word of the answer coming back — drops in proportion to how much of the prompt was reused; on a 5,300-token stable prefix in this agent, cached requests reached first token in about 380 ms against 1,050 ms uncached.

That per-call saving is small next to a 71-second run, and the reason it matters is that it is charged per call rather than per run. The difference between the two first-token figures is a little under seven tenths of a second, and the run makes seven model calls, so it repeats seven times — which is worth roughly 4.7 seconds of the 24.6 spent generating. The same change removes about 90% of the input token price on those tokens, which is why it appears in both the latency column and the cost column.

A smaller model is usually quicker for the same reason it is cheaper, which is that it does less arithmetic per token. On the summarising step in this agent, the mid-tier model produced its 320-token output in 2.1 seconds against 5.6 seconds for the frontier model, which is the strongest and most expensive rung of that same family and the one this agent runs everywhere by default, and the mechanical steps that emit a short tool call went from 1.4 seconds to 0.5. Tiering, meaning the practice of sending a step to a smaller model where the step can take one, is therefore tempting on a latency budget and not only on a bill, and that doubled incentive is exactly what makes it easy to apply to a step that cannot take it. The next two chapters take these two levers in turn, because both of them look free from a distance and neither is.

Time to success is not time to first token#

Users respond to the second one at least as strongly. An agent that streams an acknowledgement and a running narration at 400 ms feels responsive through a 71-second run; one that returns nothing until the reply is drafted feels broken at 20. Optimising perceived latency is a real and separate exercise, and it can move satisfaction without moving a single number in the breakdown above — which also means a team that only tracks time to success will undervalue streaming work and be unable to explain why complaints fell after a release that changed no timing at all.

It is also a latency measure and not a throughput measure, and the two come apart under load in a way the breakdown makes visible. The 4.2 seconds of backoff in the p50 run is a capacity symptom wearing a latency costume: it appears in a per-run decomposition, so it looks like something a faster step would fix, and it is not caused by any step being slow. It is caused by too many requests arriving in one minute. Making individual steps faster does not reduce it and can increase it, since a faster fleet issues requests sooner. What reduces it is having more headroom against the provider's per-minute limits, or wanting less of that headroom at once, and under load those two measures move in opposite directions — the mechanism that turns a parallelism win into a regression, and the subject of the seventh chapter.

The one segment this chapter has left unexamined is the model half. The largest single item in the breakdown was 16.4 seconds of fetching a document that had not changed, and the same shape appears in generation: seven calls, each resending a system prompt and a set of tool definitions that are byte-identical every time. Topic 2.15 established what prompt caching does with a repeated prefix.

What it did not cover is that an agent loop is unusually good at destroying its own prefix. The 4.7 seconds and the 90% above both assume a prefix that is actually being reused, and whether it is depends on operations the loop performs for reasons that have nothing to do with caching.