Mini-Project: A Traced Reservo Run

Description

Seven lessons built, separately, every piece: why print() isn't enough (02), the structured JSON format (03), a deterministic trace_id that opens and closes a run (04), instrumenting every step of the loop without touching the agent's code (05), severity levels and what to capture at each one (06), and reading a real log file back (07). This mini-project brings them all together, over a batch of tasks larger and more realistic than any previous example: four Reservo runs — two clean, one with a business error, and one that fails outright — all run with traced_run, all written to the same RUN_LOG.jsonl, and a final report reconstructed entirely from that file, with no reference at all to the Python variables that produced the original runs.

That last restriction is deliberate, and it's the whole mini-project's central point: the report doesn't read history, doesn't read any RunReport in memory — it reads, exclusively, RUN_LOG.jsonl's lines. It's the definitive proof that this module's structured logging captures everything needed, without depending on the original process still being alive.

Connection to the module

This is the synthesis of the eight lessons. There's no new piece of run_logger.py — the mini-project reuses traced_run, load_events, and read_trace exactly as they stood at the end of lessons 06 and 07, and adds a single new function, summarize_by_trace, which groups a file's events by trace_id to produce a batch summary — the piece that was missing to answer, once and for all, the question that opened this entire module: "what happened with this batch of runs?"

Worked example: four runs, one file, one report

The batch: two clean, one with a business error, one that fails

import json
import logging

import reservo_agent as ra
import run_logger as rl

_file_handler = logging.FileHandler("RUN_LOG.jsonl", mode="w", encoding="utf-8")
_file_handler.setFormatter(logging.Formatter("%(message)s"))
rl.logger.handlers = [_file_handler]
rl.logger.setLevel(logging.INFO)

script_a = [
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_01", "name": "list_rooms", "input": {}}]},
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_02", "name": "get_quote",
         "input": {"room": "Focus", "tier": "premium", "hours": 3}}]},
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_03", "name": "get_quote",
         "input": {"room": "Focus", "tier": "pro", "hours": 3}}]},
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_04", "name": "book_room",
         "input": {"room": "Focus", "tier": "pro", "hours": 3, "member": "Ana"}}]},
    {"stop_reason": "end_turn", "content": [
        {"type": "text", "text": "Reservé Focus pro por 3 horas para Ana. Total $60.00. Confirmación #1."}]},
]
script_b = [
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_01", "name": "list_rooms", "input": {}}]},
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_02", "name": "get_quote",
         "input": {"room": "Boardroom", "tier": "pro", "hours": 1}}]},
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_03", "name": "book_room",
         "input": {"room": "Boardroom", "tier": "pro", "hours": 1, "member": "Sofia"}}]},
    {"stop_reason": "end_turn", "content": [
        {"type": "text", "text": "Reservé Boardroom pro por 1 hora para Sofía. Total $64.00. Confirmación #2."}]},
]
script_cancel_missing = [
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_01", "name": "cancel_booking", "input": {"id": 999}}]},
    {"stop_reason": "end_turn", "content": [
        {"type": "text", "text": "No encontré esa reserva."}]},
]
stuck_script = [
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": f"toolu_0{n}", "name": "list_rooms", "input": {}}]}
    for n in range(1, 4)
]

tasks = [
    ("Reserva Focus pro 3h para Ana", script_a, 10),
    ("Reserva Boardroom pro 1h para Sofia", script_b, 10),
    ("Cancela la reserva 999", script_cancel_missing, 10),
    ("Reserva algo ambiguo", stuck_script, 2),
]

for i, (question, script, max_iter) in enumerate(tasks, start=1):
    try:
        with rl.traced_run(question, i):
            final, history = ra.run_reservo_agent(question, script, max_iterations=max_iter)
        print(f"run {i} OK :", final["content"][0]["text"])
    except RuntimeError as exc:
        print(f"run {i} FALLÓ:", exc)

_file_handler.close()

What to expect:

run 1 OK : Reservé Focus pro por 3 horas para Ana. Total $60.00. Confirmación #1.
run 2 OK : Reservé Boardroom pro por 1 hora para Sofía. Total $64.00. Confirmación #2.
run 3 OK : No encontré esa reserva.
run 4 FALLÓ: max_iterations alcanzado (2)

Notice the try/except around each task: traced_run never hides run 4's RuntimeError — it re-raises it, exactly as lesson 04 designed — so the code that calls traced_run remains responsible for deciding what to do with a run that fails. Here, it simply gets reported and the loop moves on to the batch's next task — a real batch doesn't stop because one individual run failed.

The report, reconstructed 100% from RUN_LOG.jsonl

Without using any variable from the previous block — not tasks, not history, not final — read the file from scratch and group by trace_id:

def load_events(path):
    events = []
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            events.append(json.loads(line))
    return events


def summarize_by_trace(events):
    """Agrupa los eventos por trace_id (preservando el orden de aparición)
    y arma un resumen de una línea por run: completo o no, cuántos pasos,
    cuántos tool_errors."""
    order = []
    by_trace = {}
    for e in events:
        tid = e["trace_id"]
        if tid not in by_trace:
            by_trace[tid] = []
            order.append(tid)
        by_trace[tid].append(e)

    summaries = []
    for tid in order:
        own = by_trace[tid]
        question = own[0]["question"]
        steps = sum(1 for e in own if e["event"] == "tool_use")
        tool_errors = sum(1 for e in own if e["event"] == "tool_result" and e["is_error"])
        last = own[-1]
        completed = last["event"] == "run_finished"
        summaries.append({
            "trace_id": tid, "question": question, "steps": steps,
            "tool_errors": tool_errors, "completed": completed,
        })
    return summaries


events = load_events("RUN_LOG.jsonl")
summaries = summarize_by_trace(events)

print("=== resumen por trace_id, reconstruido 100% desde RUN_LOG.jsonl ===")
for s in summaries:
    estado = "completado" if s["completed"] else "FALLIDO"
    print(f"{s['trace_id']}  {estado:10} steps={s['steps']} tool_errors={s['tool_errors']}  {s['question']!r}")

print()
print("=== agregado del lote ===")
print("runs totales        :", len(summaries))
print("runs completados     :", sum(1 for s in summaries if s["completed"]))
print("runs fallidos        :", sum(1 for s in summaries if not s["completed"]))
print("tool_errors totales  :", sum(s["tool_errors"] for s in summaries))

What to expect:

=== resumen por trace_id, reconstruido 100% desde RUN_LOG.jsonl ===
run-8487582448eb  completado steps=4 tool_errors=1  'Reserva Focus pro 3h para Ana'
run-c720132bf969  completado steps=3 tool_errors=0  'Reserva Boardroom pro 1h para Sofia'
run-8d26276b0d45  completado steps=1 tool_errors=1  'Cancela la reserva 999'
run-61abb643a67b  FALLIDO    steps=2 tool_errors=0  'Reserva algo ambiguo'

=== agregado del lote ===
runs totales        : 4
runs completados     : 3
runs fallidos        : 1
tool_errors totales  : 2

Read this output with Module 1 lesson 01's five unanswered questions firmly in mind: how many steps did each run take? — 4, 3, 1, 2, all right there, exact. Which tools did it call? — reconstructible, step by step, with lesson 07's read_trace on any of these four trace_ids. Did anything fail along the way? — yes, twice: Ana's invalid tier (tool_errors=1), and the cancel_booking over a nonexistent id (tool_errors=1). Did the run complete? — three out of four, yes; the fourth, no, and the report knows it with certainty because its last event is run_failed, not run_finished. And the run that failed — run-61abb643a67b — doesn't show up with steps=0 the way it would have with run_and_observe in Module 1: it shows up with steps=2, because the two list_rooms that did run before the RuntimeError got recorded, and summarize_by_trace counts them the same as any other step.

None of these answers depended on the Python process that ran the four runs still being alive. RUN_LOG.jsonl, a plain text file on your disk, was all the evidence needed.

The limit still deliberately left open, for the remaining modules

It's worth closing precisely on what this module does not solve — not out of oversight, but because those are, exactly, this guide's five remaining modules:

• run-8487582448eb cost something, and took some time — but this module didn't calculate it. Each tool_result's content field has enough text to estimate it (with len(text)//4 and claude-sonnet-5's fixed pricing, as Module 1 previewed), but doing it for real, broken down per tool call and aggregated over batches, is Module 3 (cost) and Module 4 (latency).
• Is tool_errors=2 in this batch acceptable? This module has no criterion at all to decide that — it only measures and records. Turning that question into a deterministic PASS/FAIL, against a fixed threshold, is Module 5.
• If cancel_booking keeps failing over the next hundred runs, should the agent stop trying it? This module records every individual failure, but has no memory between runs — every traced_run is independent. A circuit breaker that does remember repeated failures, across runs, is Module 6.
• Is this behavior the same as the agent's previous version, or did something change? Comparing two versions of the system with the same criterion is Module 7.

Each of those modules starts, literally, from observability/run_logger.py exactly as it stood at the end of this lesson — the same traced_run, unchanged, reused as the foundation.

Common mistakes

1. Calculating the batch's summary from the Python variables in the block that ran the runs, instead of reading RUN_LOG.jsonl. It would work just as well while the same process stays alive — but it loses exactly the property this mini-project exists to demonstrate: that the information survives the process that generated it. A real system restarts its processes constantly; its log file, it doesn't.

2. Counting steps by summing tool_use and tool_result separately. summarize_by_trace counts only the tool_use events (e["event"] == "tool_use") — counting the tool_results too would double the step count, because every tool call generates exactly one event of each type.

3. Forgetting that completed depends on the last event, not the absence of run_failed. This lesson's implementation uses last["event"] == "run_finished" — looking at the trace_id's last event, not searching for any run_failed at any position. For this guide's format both criteria give the same result (a run has, at most, one closing event), but the last-event criterion is more robust if the event schema were to grow.

4. Averaging tool_errors per run instead of summing before dividing, if you wanted to calculate the whole batch's per-tool failure rate — the same mistake Module 1's lesson 08 already warned about: summing tool_errors and summing steps across every run first, and dividing after, gives a different (and more correct) rate than averaging each run's individual rates.

5. Thinking this mini-project "is already" Module 3 or Module 5. It doesn't measure cost or latency (Module 3/4), and it doesn't apply any PASS/FAIL criterion (Module 5) — it only observes and records, with complete precision. That is, deliberately, this module's entire responsibility.

Exercises

Exercise 1: Add a fifth clean run and recalculate the aggregate (Easy)

With mode="a", add a fifth run — a simple quote, with no error at all — to the same RUN_LOG.jsonl. Reload the whole file and recalculate the batch's aggregate summary (total runs, completed, failed, total tool_errors).

fh = logging.FileHandler("RUN_LOG.jsonl", mode="a", encoding="utf-8")
fh.setFormatter(logging.Formatter("%(message)s"))
rl.logger.handlers = [fh]
rl.logger.setLevel(logging.INFO)

script_e = [
    {"stop_reason": "tool_use", "content": [
        {"type": "tool_use", "id": "toolu_01", "name": "get_quote",
         "input": {"room": "Studio", "tier": "pro", "hours": 2}}]},
    {"stop_reason": "end_turn", "content": [{"type": "text", "text": "Studio pro 2h cuesta $64.00."}]},
]
with rl.traced_run("¿Cuánto cuesta Studio pro 2h?", 5):
    ra.run_reservo_agent("¿Cuánto cuesta Studio pro 2h?", script_e)
fh.close()

events = load_events("RUN_LOG.jsonl")
summaries = summarize_by_trace(events)
print("runs totales      :", len(summaries))
print("runs completados   :", sum(1 for s in summaries if s["completed"]))
print("runs fallidos       :", sum(1 for s in summaries if not s["completed"]))
print("tool_errors totales :", sum(s["tool_errors"] for s in summaries))

runs totales      : 5
runs completados   : 4
runs fallidos       : 1
tool_errors totales : 2

Exercise 2: Find the batch's run with the most steps (Medium)

Using Exercise 1's summaries (five runs), write code that finds the trace_id with the highest number of steps, without assuming in advance which one it is.

busiest = max(summaries, key=lambda s: s["steps"])
print(f"run con más pasos: {busiest['trace_id']} ({busiest['steps']} pasos) -- {busiest['question']!r}")

run con más pasos: run-8487582448eb (4 pasos) -- 'Reserva Focus pro 3h para Ana'

Exercise 3: Verify the file's integrity — no tool_use without its tool_result (Hard)

Write a find_orphan_tool_use(events) function that, for each trace_id, confirms every tool_use event has a tool_result event with the same step. Apply it to this mini-project's real RUN_LOG.jsonl — it should find none, because traced_dispatch always logs both events consecutively. Then apply it to this hypothetical fragment, written by hand to test your function: it represents a process that died (say, a kill -9) right after logging step 2's tool_use, without getting to log its tool_result.

def find_orphan_tool_use(events):
    """Para cada trace_id, confirma que cada tool_use tenga su tool_result
    con el mismo step. Si no lo tiene, el run murió a la mitad de un paso
    -- el proceso terminó ENTRE el log del tool_use y el log del
    tool_result (por ejemplo, un kill -9)."""
    by_trace = {}
    for e in events:
        by_trace.setdefault(e["trace_id"], []).append(e)
    orphans = []
    for trace_id, own in by_trace.items():
        uses = {e["step"] for e in own if e["event"] == "tool_use"}
        results = {e["step"] for e in own if e["event"] == "tool_result"}
        missing = uses - results
        if missing:
            orphans.append((trace_id, sorted(missing)))
    return orphans

real_events = load_events("RUN_LOG.jsonl")
print("log real (completo):", find_orphan_tool_use(real_events))

# Fragmento hipotético, escrito a mano: un proceso que murió justo después
# de loguear el tool_use del paso 2, antes de que dispatch_robust
# devolviera el resultado -- nunca llegó a loguear el tool_result de ese
# paso.
synthetic_crash = [
    {"trace_id": "run-hipotetico", "event": "run_started", "step": 0},
    {"trace_id": "run-hipotetico", "event": "tool_use", "step": 1},
    {"trace_id": "run-hipotetico", "event": "tool_result", "step": 1},
    {"trace_id": "run-hipotetico", "event": "tool_use", "step": 2},
    # -- el proceso murió aquí; nunca se escribió el tool_result del paso 2 --
]
print("fragmento hipotético (proceso muerto a la mitad):", find_orphan_tool_use(synthetic_crash))

log real (completo): []
fragmento hipotético (proceso muerto a la mitad): [('run-hipotetico', [2])]

Summary and next step

• We closed the module with a batch of four Reservo runs — two clean, one with a half-corrected business error, one that fails outright — all run with traced_run and written to the same RUN_LOG.jsonl.
• We built summarize_by_trace, the final piece: it groups events by trace_id and produces a batch summary — completed/failed, steps, tool_errors — reconstructed exclusively from the log file, with no dependency on any variable from the process that generated the runs.
• We confirmed, with real, cited evidence, that the five questions Module 1 left unanswered — steps, tools, failures, and now also "did it complete?" — all have an exact answer, even for the run that ended in RuntimeError.
• We precisely named what this module deliberately doesn't solve — cost, latency, a PASS/FAIL criterion, memory between runs, version comparison — and which module in this guide solves each one.

With this, Module 2 closes. You have a complete observability/run_logger.py — the JSON formatter, the deterministic trace_id, traced_run with its three severity levels, and the read-back functions — and the run-tested evidence that it solves, at the root, the limit Module 1 left open.

Next module: Module 3 — Measuring Cost and Tokens per Run. With every step of the loop now recorded and available in RUN_LOG.jsonl, that module picks back up the honest token-estimation convention (len(text)//4) and claude-sonnet-5's fixed pricing to actually calculate how much each run this module already knows how to observe cost.

Additional resources

1. Python — logging — The complete module this mini-project finishes exercising, from its most basic level (lesson 02) to persistence to a file (this lesson).
2. Python — json — json.dumps/json.loads, the pair of functions behind every line of RUN_LOG.jsonl and every read-back in this module.
3. Python — max/min functions with key — The pattern used in Exercise 2 to find the list element with the highest value without fully sorting it.
4. Anthropic — Building effective agents — On why an agentic system's complete observability is the foundation any other operating discipline gets built on — this module's complete argument, closed.
5. Python 3.14 — What's New — The version every line of code in this module ran on, including the final batch's real evidence.