DEV Community

Riley Wang
Riley Wang

Posted on

Orphan Tool Calls Look Like Hangs. Pair Every Result.

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_call with no tool_result for its call_id
  • Unmatched result: a tool_result with no prior tool_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"}
Enter fullscreen mode Exit fullscreen mode

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))
Enter fullscreen mode Exit fullscreen mode

Run it

python3 pair_tool_spans.py < traces.jsonl
echo $?
Enter fullscreen mode Exit fullscreen mode

Expected healthy output:

runs=12 calls=48 results=48
orphans=0 unmatched=0
duplicate_call_ids=0
budget_misses=0 storms=0
Enter fullscreen mode Exit fullscreen mode

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
Enter fullscreen mode Exit fullscreen mode

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"}
Enter fullscreen mode Exit fullscreen mode
python3 pair_tool_spans.py < sample_orphan.jsonl; echo exit:$?
Enter fullscreen mode Exit fullscreen mode

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.

  1. LLM stall: no tokens for N seconds, and outstanding is empty.
  2. Tool stall: outstanding is not empty, and no tool_result arrives.
  3. 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
Enter fullscreen mode Exit fullscreen mode

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]
Enter fullscreen mode Exit fullscreen mode

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 Authorization headers before write.
  • Hash tool arguments. Do not store them raw.
  • Keep error_class as 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_id on 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

  1. Emit tool_call and tool_result with a shared call_id.
  2. Hash arguments. Store deadline_ms on the call span.
  3. Add http_status when the tool is HTTP.
  4. Pipe JSONL through pair_tool_spans.py.
  5. Fail the job on any orphan or unmatched result.
  6. 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)