Latency as an Operational Signal

Description

So far, this module answered "how long did it take?" — per tool, per run, and per batch, with p50 and p95. This lesson takes the final step: using that figure to make a decision. The question is no longer just "how long did the batch take?" but "what, specifically, is responsible for it taking that long?" — and, with that answer in hand, precisely tracing how far this guide reaches and where a neighboring guide's work begins.

Connection to the module

This lesson reuses lesson 06's same batch of twelve runs, and adds a new dimension: not just each run's total latency, but that latency's breakdown per tool, summed over the entire batch. It's the last conceptual piece before lesson 08 turns it into a reusable artifact — a complete observability/latency_model.py.

Analogy: the electricity bill, broken down by appliance

Module 3 already used the electricity-meter analogy for cost: an insignificant fraction per run, a real bill once multiplied by thousands. This lesson picks that same bill back up, but adds a breakdown a simple meter doesn't give: which specific appliance is responsible for most of the consumption? A household that only sees the monthly total can't decide where to save; a household that sees the breakdown — "the refrigerator is 40% of the bill, even though it's on the same amount of time as everything else" — knows exactly where to focus any change.

A batch of Reservo runs' total latency is that monthly bill. The per-tool breakdown — how many of those total milliseconds belong to list_rooms, how many to get_quote, how many to book_room, how many to cancel_booking — is the per-appliance breakdown. Without it, you know the system "takes whatever it takes"; with it, you know exactly which tool deserves attention if something needs to improve.

Worked example: the batch's breakdown, by tool

Going back to lesson 06's same batch of twelve runs, this time summing each individual tool call's latency — not just the per-run total — and grouping by tool name:

from collections import Counter

TOOL_LATENCY_MS = {
    "list_rooms": 40,
    "get_quote": 25,
    "book_room": 120,
    "cancel_booking": 90,
}


def executed_tool_names(history):
    """Devuelve, en orden, los nombres de las tools que de verdad se
    ejecutaron en un run (tool_result sin is_error)."""
    tool_use_name = {}
    for turn in history:
        if turn["role"] != "assistant" or not isinstance(turn["content"], list):
            continue
        for block in turn["content"]:
            if block["type"] == "tool_use":
                tool_use_name[block["id"]] = block["name"]
    names = []
    for turn in history:
        if turn["role"] != "user" or not isinstance(turn["content"], list):
            continue
        for block in turn["content"]:
            if block["type"] == "tool_result" and not block.get("is_error"):
                names.append(tool_use_name.get(block["tool_use_id"]))
    return names


# batch: la misma lista de (question, script) de la lección 06.
tool_ms_totals = Counter()
tool_call_counts = Counter()
for question, script in batch:
    final, history = ra.run_reservo_agent(question, script)
    for name in executed_tool_names(history):
        tool_ms_totals[name] += TOOL_LATENCY_MS[name]
        tool_call_counts[name] += 1

grand_total_ms = sum(tool_ms_totals.values())
grand_total_calls = sum(tool_call_counts.values())
print(f"{'tool':15} {'llamadas':>9} {'ms totales':>11} {'% del total':>12}")
for name in TOOL_LATENCY_MS:
    calls = tool_call_counts[name]
    ms = tool_ms_totals[name]
    pct = ms / grand_total_ms * 100
    print(f"{name:15} {calls:>9} {ms:>11} {pct:>11.1f}%")
print(f"{'TOTAL':15} {grand_total_calls:>9} {grand_total_ms:>11}")

What to expect:

tool             llamadas  ms totales  % del total
list_rooms              5         200        14.1%
get_quote               9         225        15.9%
book_room               6         720        50.9%
cancel_booking          3         270        19.1%
TOTAL                  23        1415

Read this table carefully, because the number that matters most isn't the most obvious one. get_quote got called more times than any other tool (9 of 23 calls, 39% of all the batch's tool calls) — and yet, it's responsible for barely 15.9% of the total milliseconds. book_room, on the other hand, got called only 6 times (26% of the calls) and is responsible for more than half of the batch's total latency (50.9%). How many times something gets called and how much time it consumes are not the same signal — and confusing them is, precisely, the mistake this lesson exists to prevent.

Reading the signal: what to do with "book_room dominates"

Confirming book_room dominates the batch's total latency isn't, yet, an action — it's an observation, and it's worth being precise about which kind of decision it enables and which it doesn't:

• It does enable: prioritizing book_room as the first candidate if, in the future, someone decides to invest time optimizing latency — the same logic as the refrigerator analogy. It also enables setting a latency threshold in Module 5's regression gate that's specifically sensitive to changes in book_room — a change that doubled it from 120 to 240 ms would move the batch's total much more than an equivalent change in get_quote.
• It does not enable, yet: deciding what to do if book_room fails consistently, not just if it's slow — that's a different question (failures, not latency), and it's exactly Module 6's content, with its per-tool circuit breaker. It also doesn't enable actually optimizing anything — this guide measures latency, it doesn't reduce it; if book_room in a real system needed to be faster (a better-indexed database write, an asynchronous queue), that's an engineering decision outside this guide's scope.

The distinction matters because it's easy, seeing a table like the one above, to jump straight to "we need to fix book_room" — and this guide, deliberately, doesn't go that far. It precisely identifies the signal; the decision of what to do with it belongs to whoever operates the real system, with context this guide doesn't have.

The boundary: where this guide ends, where sre-and-incident-response-guide begins

Everything this module measures is the latency of an agent's steps — how long, in this guide's model, each tool call and each complete run take. That is, precisely, different from infrastructure latency: how long a load balancer takes to route a request, what a service exposed in production's latency SLI/SLO is, what a distributed trace with OpenTelemetry crossing several microservices looks like. That layer — infrastructure, not agent — is sre-and-incident-response-guide's territory, a neighboring guide from a different ecosystem, with Docker, AWS, and Prometheus/Grafana, that this guide never rebuilds.

The distinction has a simple test: if the question is "which of the agent's tools took longest, and why?", it's this guide. If the question is "is the service exposing this agent returning 5xx errors at an acceptable rate, and who responds if it isn't?", it's sre-and-incident-response-guide. And there's one more note, about the stopwatch itself: in real production, every tool call's latency is measured with time.perf_counter() around each real call — trivial instrumentation to code, which this guide names but never executes, for the reproducibility reason lesson 03 already explained in depth. What this guide does teach, that a simple stopwatch doesn't teach on its own, is exactly what you just practiced in these seven lessons: how to sum that measurement per run, how to read it with percentiles, and how to identify which part of the system is responsible for most of the time.

Common mistakes

1. Confusing "the tool called most" with "the tool contributing the most latency." This lesson's worked example disproves it with numbers: get_quote gets called more times, but book_room contributes more total time. Any operational decision based on "which tool shows up most in the logs" instead of "which tool consumes the most total time" risks getting priorities wrong.

2. Jumping from "book_room dominates latency" to "we need to optimize book_room" without going through the rest of the analysis. This guide measures; it doesn't prescribe an optimization. This lesson's "Reading the signal" section is explicit about what this observation enables and what it doesn't.

3. Thinking this module already solved what to do when a tool fails consistently. No — that's latency versus failures, two related but distinct signals. This module measures how long a tool that does respond takes; Module 6 — with its circuit breaker — solves what to do when a tool stops responding reliably, across several runs.

4. Believing the boundary with sre-and-incident-response-guide is "this guide measures a little, that guide measures a lot." It's not a matter of quantity — it's a matter of level: this guide operates the agent (its tool calls, its runs, its prompts); that guide operates the infrastructure exposing any service (load balancers, containers, an incident's lifecycle). A real system needs both layers, and neither replaces the other.

5. Thinking that, because this module's latency is modeled, the "book_room dominates" signal wouldn't apply in a real system. The exact number (50.9%) is specific to this modeled batch and doesn't transfer as-is to production — but the pattern — a write tool consuming disproportionately more time than the read tools, even though it gets called less — is an observation that repeats, quite frequently, in real systems. The lesson isn't the figure; it's the habit of calculating the breakdown before assuming where the problem is.

Exercises

Exercise 1: Calculate get_quote's percentage of total latency (Easy)

Using the worked example's table, confirm with code the exact percentage get_quote represents of the batch's total milliseconds.

pct_get_quote = tool_ms_totals["get_quote"] / grand_total_ms * 100
print(f"get_quote: {tool_ms_totals['get_quote']} ms de {grand_total_ms} ms totales = {pct_get_quote:.1f}%")

get_quote: 225 ms de 1415 ms totales = 15.9%

Exercise 2: Calculate each tool's average latency per call (Medium)

Instead of total latency per tool, calculate how much each tool "weighs" on average per call (total ms / calls), and confirm it matches TOOL_LATENCY_MS.

for name in TOOL_LATENCY_MS:
    promedio = tool_ms_totals[name] / tool_call_counts[name]
    print(f"{name:15} promedio por llamada: {promedio:.1f} ms  (TOOL_LATENCY_MS: {TOOL_LATENCY_MS[name]} ms)")

list_rooms      promedio por llamada: 40.0 ms  (TOOL_LATENCY_MS: 40 ms)
get_quote       promedio por llamada: 25.0 ms  (TOOL_LATENCY_MS: 25 ms)
book_room       promedio por llamada: 120.0 ms  (TOOL_LATENCY_MS: 120 ms)
cancel_booking  promedio por llamada: 90.0 ms  (TOOL_LATENCY_MS: 90 ms)

Exercise 3: Design a hypothetical batch where list_rooms dominates total latency (Hard)

This lesson's batch has book_room as the dominant tool. Without running code yet, describe what kind of task mix — what combinations of tools, in what proportion — would make list_rooms (the cheapest tool per call, after get_quote) end up contributing the most total milliseconds to a batch. Then build a short batch (at least 5 runs) that confirms it.

lote_exploratorio = [
    ("Que salas hay 1", [step(tu("t01", "list_rooms", {})), end("...")]),
    ("Que salas hay 2", [step(tu("t01", "list_rooms", {})), end("...")]),
    ("Que salas hay 3", [step(tu("t01", "list_rooms", {})), end("...")]),
    ("Que salas hay 4", [step(tu("t01", "list_rooms", {})), end("...")]),
    ("Reserva Focus basic 1h para Uno", [
        step(tu("t01", "list_rooms", {})),
        step(tu("t02", "get_quote", {"room": "Focus", "tier": "basic", "hours": 1})),
        step(tu("t03", "book_room", {"room": "Focus", "tier": "basic", "hours": 1, "member": "Uno"})),
        end("...")]),
]
totales = Counter()
for question, script in lote_exploratorio:
    final, history = ra.run_reservo_agent(question, script)
    for name in executed_tool_names(history):
        totales[name] += TOOL_LATENCY_MS[name]
print(dict(totales))

{'list_rooms': 200, 'get_quote': 25, 'book_room': 120}

Summary and next step

• We broke down the batch of twelve runs' total latency by tool, and confirmed book_room — only 26% of the calls — is responsible for 50.9% of all the milliseconds, while get_quote — the most-called tool, 39% of the calls — contributes barely 15.9%.
• We distinguished which decisions this observation enables (prioritizing, setting a regression-gate threshold) and which it doesn't (optimizing the tool, deciding what to do if it starts failing — that's other modules' work).
• We traced the module's final boundary: an agent's step latency (this guide) versus infrastructure latency (sre-and-incident-response-guide) — and named, once more and without executing it, how this would be measured with the real clock in production.

Next lesson: 08 — Mini-Project: A Latency Report. We bring this module's seven lessons together into observability/latency_model.py, run over the same batch of twelve runs, with a comprehensive report: per tool, per run, and the complete batch's percentiles.

Additional resources

1. Anthropic — Building effective agents — On why identifying an agentic system's real bottleneck requires breaking down latency, not just summing it.
2. Python — collections.Counter — The structure used to accumulate the per-tool latency breakdown in this lesson.
3. sre-and-incident-response-guide — The neighboring guide that operates the infrastructure (SLI/SLO, load balancers, an incident's lifecycle) behind the service exposing an agent — territory this lesson names and never rebuilds.
4. Python 3.14 — What's New — The version every calculation in this lesson ran on.