Observability: the trajectory is the unit
A defensible platform (Part 8) still has to be runnable, and running it starts with seeing it. Part 9 turns the platform operable, and the first requirement is observability, because you cannot budget, evaluate, or debug what you cannot see. Agent observability has one structural difference from ordinary service monitoring that reshapes everything: the interesting unit is not the request but the trajectory, the whole multi-turn arc of a run. This chapter builds a trace from scratch, reads a run from it, and maps the result onto the OpenTelemetry-and-CloudWatch stack the decoder ring named.
Why requests are the wrong unit
Classic service monitoring watches requests: latency histograms, error rates, throughput. Point that at an agent and it lies by omission. A request-level dashboard shows "the model call took 3 seconds and returned 200 OK" and cannot show that the agent made that same call nine times in a useless loop, or that it burned forty thousand tokens re-reading context it already had, or that turn seventeen is where a good run went wrong. Those pathologies live in the shape of the run, across turns, and a per-request view has no place to put them.
The unit that does is the trajectory: a run, containing its units, containing their turns, each turn containing the model and tool calls that make it up, with tokens and durations attached. The industry represents this as a distributed trace, a tree of spans where each span is one operation with a start, a duration, a parent, and attributes. A run is the root span; everything it did hangs beneath it; and reading the tree is understanding the run.
Lab 9.1: a run, read from its trace
A tracer is small enough to build in full: a span has an id, a parent, a name, a start time, a duration, and an attribute bag, and a run is instrumented by opening a span around each operation and recording tokens as attributes. The lab does exactly that over a mini fleet run and then renders the tree:
python3 trace_swarm.py
--- the trajectory, read from the trace ---
run 23089 ms
unit#0 8105 ms
turn 0 3468 ms
model.call 3294 ms [in 6445, out 241, cache 4128]
tool.call 174 ms [query_metrics]
turn 1 2865 ms
model.call 2666 ms [in 6317, out 510, cache 5614]
tool.call 199 ms [query_metrics]
turn 2 1772 ms
model.call 1772 ms [in 4789, out 716, cache 2867]
unit#1 5113 ms
turn 0 3611 ms
model.call 3381 ms [in 8065, out 456, cache 7222]
tool.call 230 ms [query_metrics]
turn 1 1502 ms
model.call 1502 ms [in 7930, out 350, cache 5222]
unit#2 9871 ms
...
--- token ledger, rolled up from the same spans ---
model calls : 8 tool calls: 5
input tokens : 55,687 (40,337 served from cache, 15,350 billed fresh)
output tokens : 3,921
run wall clock : 23,089 ms
cache hit ratio : 72% of input
Read the tree the way an operator reads a trace. The indentation is the run's structure: three units, each a few turns, each turn a model call and usually a tool call. The per-span durations answer "where did the time go" at a glance, model calls, every time, which is the prefill/decode reality showing up in your own telemetry: the tool calls are noise next to the model latency. And the attributes carry the tokens, so the same spans that explain the time also explain the cost.
The token ledger is a first-class metric
That last point is the chapter's second theme. In ordinary services, cost is a monthly finance concern computed elsewhere; in an agent platform, tokens are a metric stream you emit per call, and the ledger rolled up from the trace is as operational as latency. The lab's ledger is computed from nothing but the span attributes: model calls, tool calls, input tokens split into cache-served and billed-fresh, output tokens, and the cache-hit ratio that Part 2 taught you to watch. That 72% cache-hit line is not a cost report you read next quarter; it is a gauge on the dashboard, and when it drops, Chapter 42's alarms fire, because a falling cache ratio means the fleet silently started paying full price.
This is why observability and cost are the same subject seen twice. The trace answers "what did this run do"; the ledger folded from the same trace answers "what did it cost"; and both are queries against one artifact, which is exactly what gate 9 demanded: a run's full story and exact cost, produced in minutes, not excavated.
Onto the real stack
The lab's tracer is a teaching model of what production emits for free, and the mapping is direct. Agent frameworks and the managed runtimes emit OpenTelemetry spans, the open standard the decoder ring named, increasingly with generative-AI semantic conventions that standardize the attribute names (which field holds input tokens, which holds the model id). Those spans flow through the OTEL pipeline (AWS ships its supported build, ADOT) into a backend: CloudWatch's generative-AI observability grows the agent-shaped dashboards, and because the format is open, the same stream feeds a self-hosted trace store, an existing Datadog, or Hive's own ledger jobs. You instrument once, in a portable format, and choose backends later, which is the anti-lock-in pattern the whole book keeps meeting.
One production concern the toy skips: sampling. A five-hundred-agent night produces millions of spans, and storing every one is neither affordable nor useful. The move is to sample the boring runs (keep 1% of clean completions) while keeping all of the interesting ones: every error, every budget-exhausted run, every run whose token count or duration was an outlier. Tail-based sampling (decide what to keep after a trajectory finishes, when you know whether it was interesting) is the right default, because the runs you most need to see are exactly the ones a head-based sample would most likely discard.
Traces and the event ledger
A subtlety worth pinning, because the two artifacts overlap. The event ledger from Part 1 and the trace from this chapter both record what a run did, and they are not the same thing. The ledger is for replay and audit: complete, byte-faithful, retained, yours, the thing replay debugging and the compliance trail need. The trace is for operators: sampled, dashboarded, retention-limited, tuned for a human scanning for the anomaly. Hive emits both from the same instrumentation hooks, and neither substitutes for the other: you would not replay a bug from a sampled trace (the run you need may have been dropped), and you would not build a live latency dashboard from the full ledger (too much, too slow). Same events, two consumers, two designs.
Don't be confused: a trace vs a log. A log is a flat stream of lines, each independent, and reconstructing what happened means stitching timestamps across them, the archaeology the chapter opened against. A trace is pre-stitched: the parent-child structure is recorded as the run executes, so the tree exists without reconstruction. Logs still have their place (a free-text detail inside a span), but the load-bearing artifact for an agent platform is the trace, because the thing you need to understand, the trajectory, is a tree, and only a trace stores it as one.
Full source
"""Lab 9.1: reading a run from its trace.
Agent observability's unit is the trajectory, not the request: the whole
tree of a run, its units, their turns, and each turn's model and tool
calls, with tokens and durations as span attributes. This lab is a tiny
OpenTelemetry-shaped tracer (a span has an id, a parent, a name, a
start, a duration, and attributes), an instrumented mini-run that emits
that tree, a renderer that prints it, and the token ledger rolled up
from the spans. Reading one run end to end from its trace is the whole
skill.
Standard library only. Simulated clock, seeded sizes. Deterministic.
"""
from __future__ import annotations
import random
from dataclasses import dataclass, field
@dataclass
class Span:
id: int
parent: int | None
name: str
start_ms: int
dur_ms: int
attrs: dict = field(default_factory=dict)
class Tracer:
"""Records spans on a simulated clock; open()/close() nest by parent."""
def __init__(self):
self.spans: list[Span] = []
self._clock = 0
self._next = 0
def start(self, name: str, parent: int | None, **attrs) -> int:
sid = self._next
self._next += 1
self.spans.append(Span(sid, parent, name, self._clock, 0, attrs))
return sid
def advance(self, ms: int) -> None:
self._clock += ms
def end(self, sid: int) -> None:
self.spans[sid].dur_ms = self._clock - self.spans[sid].start_ms
def instrument_run(t: Tracer, units: int = 3) -> int:
rng = random.Random(0)
run = t.start("run", None, task="audit checkout")
for u in range(units):
unit = t.start(f"unit#{u}", run)
turns = rng.randint(2, 3)
for turn in range(turns):
tp = t.start(f"turn {turn}", unit)
# a model call
in_tok = rng.randint(3000, 9000)
mc = t.start("model.call", tp,
input_tokens=in_tok,
output_tokens=rng.randint(200, 800),
# cache read is a fraction of input, never more
cache_read=int(in_tok * rng.uniform(0.55, 0.9)))
t.advance(rng.randint(1200, 4000)) # model latency dominates
t.end(mc)
# maybe a tool call
if turn < turns - 1:
tc = t.start("tool.call", tp, tool="query_metrics")
t.advance(rng.randint(50, 300))
t.end(tc)
t.end(tp)
t.end(unit)
t.end(run)
return run
def render(t: Tracer, root: int) -> None:
kids: dict[int, list[int]] = {}
for s in t.spans:
kids.setdefault(s.parent, []).append(s.id)
def walk(sid: int, depth: int) -> None:
s = t.spans[sid]
tok = ""
if "input_tokens" in s.attrs:
tok = (f" [in {s.attrs['input_tokens']}, "
f"out {s.attrs['output_tokens']}, "
f"cache {s.attrs['cache_read']}]")
elif "tool" in s.attrs:
tok = f" [{s.attrs['tool']}]"
print(f" {' ' * depth}{s.name:<14}{s.dur_ms:>6} ms{tok}")
for k in kids.get(sid, []):
walk(k, depth + 1)
walk(root, 0)
def ledger(t: Tracer) -> dict:
total = {"input": 0, "output": 0, "cache_read": 0, "model_calls": 0,
"tool_calls": 0}
for s in t.spans:
if s.name == "model.call":
total["input"] += s.attrs["input_tokens"]
total["output"] += s.attrs["output_tokens"]
total["cache_read"] += s.attrs["cache_read"]
total["model_calls"] += 1
elif s.name == "tool.call":
total["tool_calls"] += 1
return total
if __name__ == "__main__":
t = Tracer()
root = instrument_run(t)
print("--- the trajectory, read from the trace ---")
render(t, root)
print("\n--- token ledger, rolled up from the same spans ---")
lg = ledger(t)
billed_in = lg["input"] - lg["cache_read"]
print(f" model calls : {lg['model_calls']} "
f"tool calls: {lg['tool_calls']}")
print(f" input tokens : {lg['input']:,} "
f"({lg['cache_read']:,} served from cache, "
f"{billed_in:,} billed fresh)")
print(f" output tokens : {lg['output']:,}")
print(f" run wall clock : {t.spans[root].dur_ms:,} ms")
print(f" cache hit ratio : "
f"{100 * lg['cache_read'] // lg['input']}% of input")
print("\nthe tree IS the run: one glance shows where time went "
"(model calls) and where tokens went (the ledger). No log "
"archaeology.")
👉 Next: evals as regression tests, where the traces you can now read become the data a test suite scores, so a prompt change ships through a gate instead of into production on a hunch.