The status dashboard still showed a green check. The end user was still waiting on a reply. The agent log ended on a single search call. No matching tool result ever arrived after that.
This is not a prompt problem. This is a missing span.
The pairing invariant
Every tool_call span must produce one tool_result span. That rule is small. Breaking it hides hangs, retries, and silent timeouts.
Flat logs hide the gap. A later token stream still looks busy. Operators then rewrite the system prompt. The orphan call stays in the trace.
Check the invariant first. Edit the prompt second.
Four failure classes
-
Orphan call: a
tool_callwith notool_resultfor itscall_id -
Unmatched result: a
tool_resultwith no priortool_call -
Retry storm: the same
(tool, args_hash)repeats inside one run - Budget miss: wall-clock time exceeds that span's deadline
These four checks catch most "the model froze" tickets. They do not score answer quality.
A reconstructed incident
Treat the next fragment as a labeled example. It is not a production dump.
{"ts":"2026-09-07T09:14:01.102Z","run_id":"r_18","span_id":"s1","kind":"llm","event":"assistant_delta"}
{"ts":"2026-09-07T09:14:01.440Z","run_id":"r_18","span_id":"s2","kind":"tool_call","call_id":"c_9","tool":"web_search","args_hash":"a1f3","deadline_ms":8000}
{"ts":"2026-09-07T09:14:04.201Z","run_id":"r_18","span_id":"s3","kind":"llm","event":"assistant_delta"}
Three lines. One search. Zero results. The model kept emitting tokens anyway.
A human reading the file sees activity. A pairing script sees a hang.
Minimal trace schema
Do not log full prompts in the first pass. Log pairing fields only.
| Field | Required | Purpose |
|---|---|---|
run_id |
yes | groups one agent attempt |
span_id |
yes | unique row id |
kind |
yes |
llm / tool_call / tool_result
|
call_id |
for tools | joins call to result |
tool |
for tools | function name |
args_hash |
for calls | hash of canonical JSON args |
deadline_ms |
optional | wall-clock budget for that span |
http_status |
for HTTP tools | 4xx/5xx vs a model stall |
ts |
yes | UTC timestamp with milliseconds |
error_class |
for results | short class, not a stack dump |
Hash arguments. Do not store raw secrets. Truncate error strings.
Artifact: pair spans, then fail the job
Save this as pair_tool_spans.py. It reads JSONL from stdin. It prints a compact report. It exits 1 when the invariant fails.
#!/usr/bin/env python3
"""Pair tool_call spans to tool_result spans. Fail on orphans."""
from __future__ import annotations
import hashlib
import json
import sys
from collections import Counter, defaultdict
from datetime import datetime
from typing import Any
def load_rows(fp) -> list[dict[str, Any]]:
rows = []
for line_no, line in enumerate(fp, 1):
line = line.strip()
if not line:
continue
try:
row = json.loads(line)
except json.JSONDecodeError as exc:
raise SystemExit(f"line {line_no}: invalid json: {exc}") from exc
row["_line"] = line_no
rows.append(row)
return rows
def fingerprint(tool: str, args_hash: str) -> str:
raw = f"{tool}:{args_hash}".encode()
return hashlib.sha256(raw).hexdigest()[:12]
def parse_ts(value: str) -> datetime:
return datetime.fromisoformat(value.replace("Z", "+00:00"))
def audit(rows: list[dict[str, Any]]) -> dict[str, Any]:
calls: dict[str, dict[str, Any]] = {}
results: dict[str, dict[str, Any]] = {}
dup_call_ids = 0
by_run: dict[str, list] = defaultdict(list)
for row in rows:
run_id = row.get("run_id") or "unknown"
by_run[run_id].append(row)
kind = row.get("kind")
call_id = row.get("call_id")
if kind == "tool_call" and call_id:
if call_id in calls:
dup_call_ids += 1
calls[call_id] = row
elif kind == "tool_result" and call_id:
results[call_id] = row
orphans = []
unmatched = []
budget_miss = []
storms: Counter[str] = Counter()
for call_id, call in calls.items():
result = results.get(call_id)
if result is None:
orphans.append(call)
continue
started = call.get("ts")
ended = result.get("ts")
deadline = call.get("deadline_ms")
if started and ended and deadline is not None:
took_ms = (parse_ts(ended) - parse_ts(started)).total_seconds() * 1000
if took_ms > float(deadline):
budget_miss.append({**call, "took_ms": round(took_ms, 1)})
tool = call.get("tool") or "?"
args_hash = call.get("args_hash") or "?"
storms[fingerprint(tool, args_hash)] += 1
for call_id, result in results.items():
if call_id not in calls:
unmatched.append(result)
retry_storms = [
{"fingerprint": fp, "n": n} for fp, n in storms.items() if n >= 3
]
return {
"runs": len(by_run),
"tool_calls": len(calls),
"tool_results": len(results),
"orphans": orphans,
"unmatched_results": unmatched,
"duplicate_call_ids": dup_call_ids,
"budget_misses": budget_miss,
"retry_storms": retry_storms,
}
def summarize(report: dict[str, Any]) -> int:
print(
f"runs={report['runs']} calls={report['tool_calls']} "
f"results={report['tool_results']}"
)
print(
f"orphans={len(report['orphans'])} "
f"unmatched={len(report['unmatched_results'])}"
)
print(f"duplicate_call_ids={report['duplicate_call_ids']}")
print(
f"budget_misses={len(report['budget_misses'])} "
f"storms={len(report['retry_storms'])}"
)
for row in report["orphans"][:20]:
print(
f"ORPHAN run={row.get('run_id')} call_id={row.get('call_id')} "
f"tool={row.get('tool')} line={row.get('_line')}"
)
for row in report["unmatched_results"][:20]:
print(
f"UNMATCHED run={row.get('run_id')} "
f"call_id={row.get('call_id')} line={row.get('_line')}"
)
for row in report["budget_misses"][:20]:
print(
f"BUDGET run={row.get('run_id')} call_id={row.get('call_id')} "
f"took_ms={row.get('took_ms')} deadline_ms={row.get('deadline_ms')}"
)
for storm in report["retry_storms"]:
print(f"STORM fingerprint={storm['fingerprint']} n={storm['n']}")
failed = (
report["orphans"]
or report["unmatched_results"]
or report["duplicate_call_ids"]
or report["budget_misses"]
or report["retry_storms"]
)
return 1 if failed else 0
if __name__ == "__main__":
report = audit(load_rows(sys.stdin))
sys.exit(summarize(report))
Run it
python3 pair_tool_spans.py < traces.jsonl
echo $?
Expected healthy output:
runs=12 calls=48 results=48
orphans=0 unmatched=0
duplicate_call_ids=0
budget_misses=0 storms=0
A hung search looks like this:
runs=1 calls=1 results=0
orphans=1 unmatched=0
duplicate_call_ids=0
budget_misses=0 storms=0
ORPHAN run=r_18 call_id=c_9 tool=web_search line=2
Exit code 1 means stop. Do not tune temperature yet.
Fixture you can paste
Save this as sample_orphan.jsonl and pipe it in.
{"ts":"2026-09-07T09:14:01.440Z","run_id":"r_18","span_id":"s2","kind":"tool_call","call_id":"c_9","tool":"web_search","args_hash":"a1f3","deadline_ms":8000}
{"ts":"2026-09-07T09:14:04.201Z","run_id":"r_18","span_id":"s3","kind":"llm","event":"assistant_delta"}
python3 pair_tool_spans.py < sample_orphan.jsonl; echo exit:$?
You should see one ORPHAN line. You should see a non-zero exit.
Decision table
Use the report as a triage map. Do not guess.
| Signal | Likely cause | Next action |
|---|---|---|
| Orphan call, no later spans | Tool process blocked or crashed | Inspect the tool runtime, not the prompt |
| Orphan call, later LLM deltas | Model continued without the result | Gate generation on tool_result
|
| Unmatched result | Duplicate worker or reordered ship | Check call_id allocation and log order |
Duplicate call_id
|
IDs reused across retries | Namespace IDs with run_id
|
Retry storm n>=3
|
Agent loop on the same args | Add a per-run fingerprint cache |
Budget miss, http_status empty |
Deadline too tight, or tool never returned | Split the tool or raise that span only |
Budget miss, http_status>=500
|
Upstream fault, not a model stall | Retry with jitter; do not rewrite prompts |
This table is the reusable debug loop. Pair. Classify. Then change one thing.
Classify the timeout source
"Timeout" is not one bug. Split it on the trace.
-
LLM stall: no tokens for N seconds, and
outstandingis empty. -
Tool stall:
outstandingis not empty, and notool_resultarrives. - Late result: a result arrives after the caller already moved on.
Late results often show up as unmatched rows. They can also pair after a budget miss. Those two cases need different fixes.
A tool stall needs a runtime watchdog. An LLM stall needs a stream heartbeat. A late result needs a call_id tombstone, not another sample.
Guard generation on the pair
The common bug is simple. The runtime emits tokens while a tool is outstanding.
Pseudocode follows. It is not production code.
outstanding = set()
def on_tool_call(call_id: str) -> None:
outstanding.add(call_id)
def on_tool_result(call_id: str) -> None:
outstanding.discard(call_id)
def can_emit_tokens() -> bool:
return len(outstanding) == 0
If can_emit_tokens() is false, write a blocked_on span. Do not stream. The trace then explains the wait.
Hash args the same way every time
Retry storms need a stable fingerprint. Canonicalize JSON before hashing.
import hashlib
import json
def hash_args(args: dict) -> str:
blob = json.dumps(args, sort_keys=True, separators=(",", ":"))
return hashlib.sha256(blob.encode()).hexdigest()[:16]
Unstable key order creates fake uniqueness. The storm detector then stays quiet. Arrays that encode sets need an explicit sort too.
Keep secrets out of the JSONL
Pairing does not need payloads. It needs identities and hashes.
- Drop
Authorizationheaders before write. - Hash tool arguments. Do not store them raw.
- Keep
error_classas an enum. Do not keep full bodies. - Redact emails and tokens with a single pass before upload.
A free scratch host is still a host. Treat the file as public once it leaves the laptop.
Where a scratch server fits
You can run the audit on a laptop. A long agent suite needs a box that stays up.
Disclosure: This article was prepared as part of MonkeyCode's product outreach.
MonkeyCode is an open-source coding agent with free model access and a free server option. Those two facts matter here for one reason. You can keep JSONL traces and the pairing script on a scratch host. You can re-run failed suites against a free model endpoint. You do not need a GPU box first.
If you already have OpenTelemetry in production, keep it. This script does not replace a collector. It is a gate in front of prompt debugging.
Limitations
This method is narrow. Know the edges.
- It needs
call_idon both sides. Missing IDs make every call look orphaned. - It trusts timestamps. Merging two clocks without NTP creates fake budget misses.
- It does not recover truncated JSON inside tool payloads.
- It does not score answer quality. A paired result can still be wrong.
- It is not a distributed trace backend. Cross-host fan-out needs context propagation.
- Hash collisions are unlikely at 16 hex chars. They are not impossible.
- HTTP status is optional. Without it, 503s look like model stalls.
Label every example here as unexecuted on your data. Run the script on your file before you trust the counts.
Who should not use this
Skip this loop in a few cases.
- Multi-tenant production logs with PII and no redaction path
- Teams that already fail CI on unpaired OTel spans
- Streaming UIs that cannot buffer until tools finish
- Workflows whose tools are not request/response, such as open sockets
- Agents with no tools at all; the invariant is empty then
If your runtime already blocks generation on outstanding calls, you may only need the storm check.
A 15-minute checklist
- Emit
tool_callandtool_resultwith a sharedcall_id. - Hash arguments. Store
deadline_mson the call span. - Add
http_statuswhen the tool is HTTP. - Pipe JSONL through
pair_tool_spans.py. - Fail the job on any orphan or unmatched result.
- Only then inspect prompts, temperature, or model choice.
The order is the point. Incomplete traces waste model budget. Pairing is cheaper than another sample.
If you need a scratch host for that JSONL loop, MonkeyCode's free server option is one place to park the script and the traces.
Top comments (0)