DEV Community: Riley Wang

Your Trace Shows the Wrong Order. Measure Clock Skew Before You Debug

Riley Wang — Mon, 14 Sep 2026 21:37:48 +0000

Two in the morning, one failing agent run, and a trace that made no sense.

The tool result sat four milliseconds before the tool call that produced it. I read the retry logic for three hours. The retry logic was fine.

The trace was wrong. Two machines wrote it. Their clocks disagreed by about 250 ms.

The bug is in the timeline, not the agent

A single trace often has more than one clock behind it. The agent process stamps spans on its own host. A sandbox or tool server stamps results on another machine.

When those clocks drift, ordering breaks. You then debug a sequence that never happened.

Watch for these symptoms:

A child span ends before its parent starts.
A tool result carries an earlier timestamp than its request.
Server-side durations come out negative.
Skew grows steadily across a long run.
One host's spans all look suspiciously fast.

Any one of these can be a real bug. All of them together usually mean one thing. Your timestamps came from different clocks.

Why two clocks drift apart

The usual causes are boring and common:

Date.now(), time.time(), and friends read a wall clock, not a monotonic one.
Containers share the host clock, but VMs can suspend and resume.
NTP corrections can step a clock forward or backward.
Small rate differences accumulate over hours.

Nothing here is exotic. It is the default in many agent deployments. Measure the offset before you blame the agent.

Do not fix it by re-sorting the trace

Sorting by timestamp hides the problem. The wrong order becomes a consistent wrong order. You lose the signal that told you something was off.

Fix the clocks first. Sort second.

Estimate the offset from paired spans

Every tool call gives you four timestamps:

t1 client sends the request
t2 server receives it
t3 server sends the result
t4 client receives the result

Two numbers fall out of those four.

offset = ((t2 - t1) + (t3 - t4)) / 2
rtt    = (t4 - t1) - (t3 - t2)

This is the classic four-timestamp exchange used by NTP-style sync. It assumes network delay is roughly symmetric. Filter for low-RTT pairs and take the median.

Set max_rtt_ms from your own p50 RTT, not from a blog post. A pair above that threshold tells you about queuing, not about clocks. More pairs help. Aim for dozens, not three.

The estimator

#!/usr/bin/env python3
import json, statistics

def load(path):
    with open(path) as fh:
        for line in fh:
            line = line.strip()
            if line:
                yield json.loads(line)

def quads(spans):
    by_id = {s['span_id']: s for s in spans}
    for s in spans:
        if s.get('kind') != 'tool_call':
            continue
        r = by_id.get(s.get('result_span_id'))
        if r is None:
            continue
        yield s['ts_ms'], r['ts_ms'], r['end_ms'], s['end_ms']

def split(t1, t2, t3, t4):
    offset = ((t2 - t1) + (t3 - t4)) / 2.0
    rtt = (t4 - t1) - (t3 - t2)
    return offset, rtt

def estimate(qs, max_rtt_ms=50.0, min_pairs=5):
    kept = []
    for t1, t2, t3, t4 in qs:
        off, rtt = split(t1, t2, t3, t4)
        if rtt <= max_rtt_ms:
            kept.append(off)
    if len(kept) < min_pairs:
        raise SystemExit('need %d low-RTT pairs, kept %d' % (min_pairs, len(kept)))
    return statistics.median(kept), len(kept)

if __name__ == '__main__':
    import sys
    spans = list(load(sys.argv[1]))
    off, n = estimate(quads(spans))
    print('offset_ms=%.1f pairs=%d' % (off, n))

A fixture test with a known offset

Never trust an estimator you have not tested against a known answer. Inject an offset, then check recovery.

import random
from spanskew import estimate

def test_recovers_known_offset():
    random.seed(7)
    injected = 250.0
    base = 1_700_000_000_000
    qs = []
    for i in range(40):
        send = base + i * 1000
        up = random.uniform(4, 6)
        down = random.uniform(4, 6)
        work = 5.0
        t2 = send + up + injected
        t3 = t2 + work
        t4 = t3 - injected + down
        qs.append((send, t2, t3, t4))
    off, n = estimate(qs, max_rtt_ms=30.0)
    assert n == 40
    assert abs(off - injected) <= 2.0

The fixture injects a 250 ms offset. The estimator must recover it within 2 ms. If it cannot, your RTT filter or your median is wrong.

Eyeball the raw trace first

One cheap check before any math:

jq -r 'select(.kind=="tool_call") | [.span_id, (.end_ms - .ts_ms)] | @tsv' trace.jsonl | sort -k2 -n | head

Negative or near-zero durations on tool calls are a strong skew hint. So is a result span that sorts before its request span.

A minimal trace line pair looks like this:

{"span_id":"s1","kind":"tool_call","ts_ms":1700000000000,"end_ms":1700000000042,"result_span_id":"s1r"}
{"span_id":"s1r","kind":"tool_result","ts_ms":1700000000250,"end_ms":1700000000255}

Correct the trace, then re-read it

Work in this order:

Group spans by emitting host.
Pick one host as the reference clock.
Compute the median offset for every other host.
Shift those hosts' timestamps by their offset.
Rebuild parent and child links from span ids, not timestamps.
Re-run the original query on corrected stamps.

Step five matters most. Span ids are stable facts. Timestamps are measurements.

Which evidence to trust

Evidence	Trust it when	Fallback
Wall-clock timestamps	Hosts are synced and RTT is low	Corrected offset
Span nesting	Parent ids exist and are unique	Rebuild from ids
Duration fields	Emitted by the same host	Recompute from stamps
Log line order	A single writer, single file	Add sequence numbers

Where to run this harness

The harness is small and CPU-only. It reads JSONL and prints one number. I run it on MonkeyCode's free server option and use free model access to draft the span rules before they land in CI.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

A stable box matters here. Skew work depends on running the same fixture many times. If you want to try the harness without provisioning a machine, the free server option is a reasonable place to start.

Limits, and who should skip this

The symmetry assumption breaks badly under heavy upload or download.
One offset per run fails if NTP steps the clock mid-run.
Fewer than five low-RTT pairs means you have no estimate. Do not guess.
Single-host traces do not need any of this.
If your collector already normalizes clocks, use that instead.
Monotonic clocks fix ordering within one host. They do not fix cross-host comparison.
This tells you nothing about which component is slow. It only fixes the axis.

Skip it entirely if every span comes from one process with one monotonic clock. You have no problem to solve.

A reusable debug loop

Reproduce the run and keep the JSONL trace.
Count the emitters. If there is only one, stop here.
Run the jq check for negative or tiny durations.
Estimate offsets and keep only low-RTT pairs.
Correct stamps, then rebuild links from span ids.
Re-run the failing query on corrected data.

Most of that loop is one script and one jq call. Step one is the step people skip.

A trace is a measurement, not a recording. Measure the ruler before you measure the bug.

Tool Output Looks Complete. Record the Injected Slice.

Riley Wang — Sun, 13 Sep 2026 19:57:19 +0000

The on-call thread opened at 02:11 UTC.
The agent had already marked the run green.
It claimed production.yaml was read and valid.

Slack still received the old staging port.
The file on disk contained the right value.
The trace even stored the entire file body.

That mismatch is the bug this article names.
The tool span was complete and technically truthful.
The next model turn never received that body.

The lie inside a successful span

Most agent logs keep the tool call name.
They also keep arguments and a result string.
Some keep timestamps and a parent span id.

They rarely keep three different length fields.
Those three numbers are not interchangeable.
Mixing them hides a common production failure.

Here are the three lengths that actually matter:

observed_bytes counts bytes the tool returned.
injected_bytes counts bytes copied into context.
injected_tokens counts tokens the API accepted.

A green span can still drop most of a file.
Your replay then debugs the wrong evidence set.
You will rewrite prompts the model never saw.

Clipping happens after the tool returns

This is not a hang and not a retry bug.
The tool finished. The filesystem read succeeded.
The prompt builder then applied a size cap.

Duration fields will look healthy and boring.
Retry counters will stay at one attempt.
Span trees will show a normal child read.

The loss sits on a later boundary.
That boundary is prompt assembly, not I/O.
Traces that stop at tool return will miss it.

Tool success answers one question only.
It says the executor did not throw.
It does not say the model saw the tail.

A reconstructed incident

Treat this section as a reconstructed pattern.
It is not a named customer outage report.

The agent called read_file on production.yaml.
The tool returned 96412 bytes of YAML text.
The trace writer stored the full result blob.

The prompt builder applied an 8192 token cap.
Only the leading keys reached model context.
The port field lived near the file end.

The model answered from that truncated prefix.
It reused a default port from the system prompt.
The trace still showed a perfect file read.

Diffing two full tool bodies did not help.
Both traces contained identical complete files.
Only the injected slice had changed size.

A later run used a tighter builder policy.
Observed hashes stayed stable across both runs.
Injected hashes diverged, and the port flipped.

Artifact: clip-aware JSONL spans

Store clipping as first-class fields on spans.
Do not infer clipping from sampled prompt dumps.
Prompt dumps are often redacted or dropped.

Use one JSON object per line, as follows.

{
  "span_id": "tool-14",
  "parent_id": "turn-3",
  "name": "read_file",
  "status": "ok",
  "observed_bytes": 96412,
  "injected_bytes": 12040,
  "injected_tokens": 8192,
  "clip_reason": "prompt_token_cap",
  "sha256_observed": "ab12",
  "sha256_injected": "cd34",
  "injected_preview": "app:\\n  name: billing\\n",
  "prompt_builder_version": "cap-v3"
}

Keep clip_reason as a small closed enum.
Do not store free-text excuses in that field.

Closed values worth supporting today:

none means the full result was injected.
prompt_token_cap means the builder cut tokens.
tool_result_char_limit means a char cap fired.
provider_context_window means the API rejected tail.
redaction means bytes changed for safety.
binary_omitted means a non-text payload was dropped.

Flag a span when injected bytes fall below observed.
Flag again when hashes differ at equal lengths.
Redaction can change bytes without a size cap.

Checker script

The script below is a local proposal only.
It reads JSONL from stdin and prints a table.
It does not call any network service.

#!/usr/bin/env python3
"""clip_check.py — flag tool spans with silent truncation."""
import json
import sys

PRIORITY = {
    "silent_clip": 0,
    "incomplete": 1,
    "hash_mismatch": 2,
    "clipped": 3,
    "ok": 4,
}


def load_spans(stream):
    for line_no, raw in enumerate(stream, 1):
        line = raw.strip()
        if not line:
            continue
        rec = json.loads(line)
        rec["_line"] = line_no
        yield rec


def clip_ratio(obs, inj):
    if obs <= 0:
        return 0.0
    return 1.0 - (inj / obs)


def classify(rec):
    missing = [
        key
        for key in ("observed_bytes", "injected_bytes", "injected_tokens")
        if rec.get(key) is None
    ]
    if missing:
        return "incomplete", missing

    obs = int(rec.get("observed_bytes") or 0)
    inj = int(rec.get("injected_bytes") or 0)
    reason = rec.get("clip_reason") or "none"

    if inj < obs and reason == "none":
        return "silent_clip", [f"ratio={clip_ratio(obs, inj):.2f}"]
    if inj < obs:
        return "clipped", [reason, f"ratio={clip_ratio(obs, inj):.2f}"]

    obs_hash = rec.get("sha256_observed")
    inj_hash = rec.get("sha256_injected")
    if obs_hash and inj_hash and obs_hash != inj_hash and reason == "none":
        return "hash_mismatch", ["bytes_match_but_hash_differs"]
    return "ok", []


def main():
    rows = []
    for rec in load_spans(sys.stdin):
        if not rec.get("name"):
            continue
        status, detail = classify(rec)
        rows.append((status, rec, detail))

    rows.sort(key=lambda item: PRIORITY.get(item[0], 9))
    print(f"{'status':<16} {'span':<12} {'tool':<16} {'obs':>8} {'inj':>8} detail")
    for status, rec, detail in rows:
        print(
            f"{status:<16} {str(rec.get('span_id', '-')):<12} "
            f"{str(rec.get('name', '-')):<16} "
            f"{int(rec.get('observed_bytes') or 0):>8} "
            f"{int(rec.get('injected_bytes') or 0):>8} "
            f"{','.join(detail)}"
        )

    silent = sum(1 for status, _, _ in rows if status == "silent_clip")
    incomplete = sum(1 for status, _, _ in rows if status == "incomplete")
    print(f"\n# silent_clip={silent} incomplete={incomplete} total={len(rows)}")
    if silent or incomplete:
        sys.exit(1)


if __name__ == "__main__":
    main()

Run it against one exported run:

python3 clip_check.py < traces.jsonl
echo $?

Exit code 1 means the trace is not trustworthy.
Exit code 0 means every tool span declared clipping.
That zero does not prove the answer was correct.

Emit fields at the tool boundary

Wrap the executor so spans cannot omit lengths.
Hash both strings before the prompt is built.
Write the JSONL line before the next model call.

import hashlib
import json
from pathlib import Path


def sha256_text(text: str) -> str:
    return hashlib.sha256(text.encode("utf-8")).hexdigest()[:16]


def emit_tool_span(path, span_id, parent_id, name, observed, injected, reason, builder_version, token_count):
    rec = {
        "span_id": span_id,
        "parent_id": parent_id,
        "name": name,
        "status": "ok",
        "observed_bytes": len(observed.encode("utf-8")),
        "injected_bytes": len(injected.encode("utf-8")),
        "injected_tokens": token_count,
        "clip_reason": reason,
        "sha256_observed": sha256_text(observed),
        "sha256_injected": sha256_text(injected),
        "injected_preview": injected[:128],
        "prompt_builder_version": builder_version,
    }
    with Path(path).open("a", encoding="utf-8") as handle:
        handle.write(json.dumps(rec, ensure_ascii=False) + "\n")
    return rec

Call emit_tool_span once per finished tool.
Pass the exact string the prompt builder used.
Do not hash the file on disk after the fact.

Disk can change between tool return and replay.
The injected string is the only fair evidence.
That is what the model could have used.

If your builder truncates after encoding tokens, record that.
Byte cuts and token cuts are different operations.
The enum must say which policy actually fired.

Four-step debug loop

Use the same loop on every flaky agent run.
Do not start with prompt rewriting first.

Export one JSONL file per agent run.
Require clip fields on every tool span.
Fail the run if clip_check.py exits 1.
Replay only after injected hashes match.

Step four needs the injected slice, not the file.
Keep injected_preview as a short stable prefix.
A 128-byte prefix is enough to compare two runs.

Add these extra fields when you can:

injected_preview stores 128 escaped leading bytes.
model_context_limit_tokens stores the active window.
prompt_builder_version stores the cap policy id.

prompt_builder_version catches silent policy changes.
A new cap can ship without any model change.
Your model regression may be a clip change.

Compare builder versions before you compare models.
A cap change rewrites every downstream token.
Model swap notes become noise after that rewrite.

Tests for the classifier

These tests are local and do not need GPUs.
They lock the silent-clip definition in place.
Run them before you trust a new exporter.

from clip_check import classify


def test_silent_clip():
    status, detail = classify({
        "observed_bytes": 1000,
        "injected_bytes": 120,
        "injected_tokens": 80,
        "clip_reason": "none",
    })
    assert status == "silent_clip"
    assert detail[0].startswith("ratio=")


def test_declared_clip_is_visible():
    status, _ = classify({
        "observed_bytes": 1000,
        "injected_bytes": 120,
        "injected_tokens": 80,
        "clip_reason": "prompt_token_cap",
    })
    assert status == "clipped"


def test_missing_lengths_fail():
    status, missing = classify({"name": "read_file"})
    assert status == "incomplete"
    assert "observed_bytes" in missing

A silent clip is the highest priority failure.
Missing fields are the next failure class.
Declared clips are visible and therefore usable.

Do not fail CI on every declared clip.
Large read_file results will clip by design.
Fail CI when the reason field is missing or none.

Decision table

Symptom	Trace looks like	First check	Do not do
Wrong field from a large file	`status=ok`, full body stored	`injected_bytes` versus `observed_bytes`	Rewrite the system prompt
Binary tool result looks empty	short ASCII replacement text	`clip_reason=binary_omitted`	Retry the same tool blindly
Intermittent wrong answers	identical observed tool bodies	builder version and cap fields	Swap models immediately
Replay missing expected PII	hashes differ, lengths stay close	`clip_reason=redaction`	Paste raw traces into chat
Checker exits incomplete	length fields are absent	fix the exporter first	Trust the pretty trace UI

Wrong-port bugs often match row one.
The file was complete in object storage.
The injected slice never included the key.

Where a quiet box fits

You can run this loop on a laptop.
A quiet remote box helps with overnight replays.
Long traces should not compete with your IDE.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.
MonkeyCode is an open-source project for coding agents.
It offers free model access and a free server option.

Those two facts matter for this workflow only.
You need a model to regenerate injected slices.
You need a server if local machines are busy.

Do not treat that option as a benchmark lab.
This article does not publish model names.
It also does not publish quotas or hardware specs.

Capture traces. Run clip_check.py. Then replay.
If the checker is red, skip model comparison.
You would be scoring two different prompts.

If you already store JSONL traces, start there.
The server is optional for the checker itself.

Limitations

This method does not score answer quality.
It only detects undeclared length or hash changes.
A fully injected file can still be the wrong file.

Token counts depend on the provider tokenizer.
Byte ratios are exact. Token ratios are estimates.
Do not alert on token estimates alone.

Streaming tools can update observed bytes twice.
Record final values after the tool span closes.
Partial spans should keep status as incomplete.

Multi-agent graphs need per-child clip fields.
A parent ok can hide a clipped child read.
The checker should walk every tool span record.

Pretty UIs often show the observed blob first.
Engineers then believe the model saw that blob.
Show the injected slice before the observed body.

This loop also ignores semantic irrelevance.
A full injection can still be the wrong excerpt.
You still need evals for that class of error.

Who should not use this

Skip this if your agent has no tools.
A chat wrapper has no result slice to clip.
Prompt-only apps need a different trace shape.

Skip this if traces contain raw secrets.
Hash and preview fields can still leak data.
Redact before JSONL ever leaves the host.

Skip this for hard real-time control loops.
The extra fields add exporter complexity and I/O.
Those systems need different runtime guarantees.

What to watch after you ship this

Once clipping is explicit, add one rate.
Count silent clips per one hundred tool spans.
Watch that rate when prompt builders change.

A second watch is useful after the first.
Track median injected bytes for read_file.
A sudden drop often ships with a new cap.

Keep the original failure in mind here.
The YAML file was on disk and correct.
The model never saw the port key at all.

Record the injected slice on every tool span.
Then green traces stop lying about completed reads.

Agent Traces Hide the Fork. Record Ranked Options.

Riley Wang — Sat, 12 Sep 2026 17:55:58 +0000

A coding agent returned a green run at 02:11.
The ticket asked for a small test helper.
This scene is a constructed on-call example.

The agent called search_repo and then edit_file.
Both tool spans closed with status ok.
The patch landed in the wrong Python package.

The JSONL export listed every call in order.
It never listed the tools the planner rejected.
Ops could not replay the fork that mattered.

Execution logs are not routing logs

Most agent traces are still plain call journals.
They store name, arguments, latency, and final status.
They omit the ranked options behind the pick.

A green tool span answers one narrow question.
It only asks if the invocation threw an error.
It does not answer why this tool won.

Loop-style agents fail at the fork often.
The wrong search query still returns hits.
The wrong file still accepts a clean edit.

Those runs look healthy in span dashboards.
The user still receives a useless change.
You need a record of discarded alternatives.

What a decision span must capture

Record the choice before the tool starts.
Do not reconstruct intent from later arguments.
Arguments describe the winner, not the field.

Each decision span needs a stable shape.
Keep it small enough to grep in JSONL.
Keep it strict enough to validate in CI.

Use these minimum fields on every decision span:

Store span_id and parent_id for tree joins.
Store ts in UTC with second precision.
Store goal as a short remaining task.
Store options as scored tool candidates.
Store chosen matching one option name.
Store policy naming the selection rule.
Store margin as winner minus runner-up.

Skip free-text essays in this span.
Put long prompt blobs in a separate event.
Decision records should stay cheap to diff.

A concrete JSONL fragment

Example below is illustrative, not a live export.

{"type":"decision","span_id":"dec_7f3a","parent_id":"run_91","ts":"2026-09-13T02:11:04Z","goal":"add a date-parse test helper","options":[{"tool":"search_repo","score":0.81,"reason":"find existing helpers"},{"tool":"edit_file","score":0.44,"reason":"patch a remembered path"},{"tool":"run_tests","score":0.12,"reason":"no diff exists yet"}],"chosen":"search_repo","policy":"argmax_score","margin":0.37}
{"type":"tool_call","span_id":"call_12","parent_id":"dec_7f3a","ts":"2026-09-13T02:11:05Z","tool":"search_repo","args":{"query":"date parse helper"}}
{"type":"tool_result","span_id":"res_12","parent_id":"call_12","ts":"2026-09-13T02:11:06Z","ok":true,"bytes":842}

Notice the parent link on the tool call.
The call hangs under the decision, not the run.
That join is the entire debugging upgrade.

Validator you can run on a file

The next script is a local example.
It is not a measured production harness.
Save it as check_decisions.py beside a JSONL trace.

#!/usr/bin/env python3
"""Flag tool calls that lack a scored decision."""
from __future__ import annotations

import json
import sys
from dataclasses import dataclass
from typing import Any


@dataclass
class Finding:
    line: int
    kind: str
    detail: str


def load_events(path: str) -> list[tuple[int, dict[str, Any]]]:
    rows: list[tuple[int, dict[str, Any]]] = []
    with open(path, encoding="utf-8") as handle:
        for line_no, raw in enumerate(handle, start=1):
            text = raw.strip()
            if not text:
                continue
            rows.append((line_no, json.loads(text)))
    return rows


def margin_of(options: list[dict[str, Any]], chosen: str) -> float | None:
    scores = {str(item["tool"]): float(item["score"]) for item in options}
    if chosen not in scores or len(scores) < 2:
        return None
    winner = scores[chosen]
    rest = [value for name, value in scores.items() if name != chosen]
    return winner - max(rest)


def audit(path: str) -> list[Finding]:
    findings: list[Finding] = []
    pending: dict[str, dict[str, Any]] = {}
    for line, event in load_events(path):
        kind = event.get("type")
        if kind == "decision":
            options = event.get("options") or []
            chosen = str(event.get("chosen") or "")
            tools = [str(item.get("tool")) for item in options]
            if chosen not in tools:
                findings.append(Finding(line, "chosen_missing", chosen))
            computed = margin_of(options, chosen)
            reported = event.get("margin")
            if computed is not None and reported is not None:
                if abs(float(reported) - computed) > 1e-6:
                    findings.append(Finding(line, "bad_margin", str(reported)))
            pending[str(event.get("span_id"))] = event
            continue
        if kind == "tool_call":
            parent = str(event.get("parent_id") or "")
            tool = str(event.get("tool") or "")
            decision = pending.pop(parent, None)
            if decision is None:
                findings.append(Finding(line, "missing_decision", tool))
                continue
            if str(decision.get("chosen")) != tool:
                findings.append(
                    Finding(line, "choice_mismatch", f"{decision.get('chosen')}->{tool}")
                )
    for leftover in pending.values():
        findings.append(
            Finding(0, "unconsumed_decision", str(leftover.get("span_id")))
        )
    return findings


def main() -> int:
    if len(sys.argv) != 2:
        print("usage: check_decisions.py trace.jsonl", file=sys.stderr)
        return 2
    findings = audit(sys.argv[1])
    for item in findings:
        print(f"{item.kind}\tL{item.line}\t{item.detail}")
    print(f"finding_count\t{len(findings)}")
    return 1 if findings else 0


if __name__ == "__main__":
    raise SystemExit(main())

Run it against a tiny fixture first.

python3 check_decisions.py sample.jsonl

A clean file prints a zero finding count.
A missing parent prints the missing_decision kind.
A rewritten winner prints the choice_mismatch kind.

A debug loop that diffs forks

Do not start with model quality debates.
Start with two traces of the same ticket.
Keep the user prompt identical on both runs.

Work the loop in this fixed order:

Confirm both JSONL files parse line by line.
Extract the sequence of chosen tools only.
Extract the option sets sitting under each choice.
Flag any tool call without a parent decision.
Flag margins below a local threshold, such as 0.05.
Diff the two chosen sequences as plain text.
Only then inspect arguments on the first mismatch.

Example commands for steps two and six:

jq -r 'select(.type=="decision") | .chosen' a.jsonl > a.chosen.txt
jq -r 'select(.type=="decision") | .chosen' b.jsonl > b.chosen.txt
diff -u a.chosen.txt b.chosen.txt

If the chosen lists match, the bug is downstream.
If they diverge, stop reading tool payloads.
Read the option scores at the first split.

Low margin is a routing smell, not a proof.
A 0.02 gap means the planner was almost tied.
Tied planners need a policy, not another retry.

How this differs from call diffs

Call diffs tell you arguments changed later.
Decision diffs tell you the menu changed first.
Those are different bugs with different fixes.

A search query tweak is an argument bug.
A missing search_repo option is a prompt bug.
A tiny margin is a scoring bug.

Treat those three cases as separate tickets.
Mixing them produces noisy agent evaluation reports.
Routing quality is not the same as tool quality.

Where a scratch model host helps

You can run the validator on a laptop.
Replaying the agent still needs a model endpoint.
It also needs a quiet machine for two traces.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.
MonkeyCode currently offers free model access and a free server option.
Use that pair only as a scratch replay host.

They are not a substitute for a decision schema.
Add the spans first, then replay on any host you already use.
Keep the product choice secondary to the span contract.

Capture two JSONL files for the same ticket.
Compare chosen lists before you compare patches.
Stop at the first fork that changed rank.

Limitations

Model-supplied scores are not calibrated success probabilities.
Do not treat 0.81 as an 81 percent success chance.
Use scores only to rank options inside one span.

Option reason fields can leak private context.
Redact paths, tokens, and customer names before storage.
Drop reasons in production if your store is wide.

This pattern adds one event per tool call.
Busy loops will grow trace volume quickly.
Sample long exploratory runs, never the decision keys.

Clock skew still disorders events across hosts.
The validator assumes a single writer per file.
Do not merge JSONL from two clocks without ids.

Who should not use this

Skip this if the agent has one hard-coded tool.
There is no fork, so ranking adds noise.

Skip this if you cannot store traces at all.
A schema without a file is documentation theater.

Skip this for binary policy routers with no scores.
Log the rule name, not a fake numeric margin.

Skip this when option text includes secrets.
Fix redaction before you add richer spans.

What to keep in the next incident

When a green agent still ships a bad edit, ask four questions.

Did every tool call cite a decision parent?
Did chosen match the tool that actually ran?
Was the margin too small to trust the pick?
Did a second run diverge at the same fork?

If you cannot answer those from the file, the trace is incomplete.
Call journals will keep looking green under dashboards.
The rejected options will keep disappearing from review.

Ship the schema before you shop for another dashboard.
A ranked option list is a small, testable artifact.
It survives even if you change models next week.

Green Agent Loops Never End. Require a Terminal Span

Riley Wang — Fri, 11 Sep 2026 15:39:25 +0000

Here is a reconstructed staging incident from logs.
A staging bot was asked to open one pull request.
Every recorded tool span still reported status ok.

The promised pull request never appeared on GitHub.
The run lasted forty-one minutes after the last write.
Logs kept growing while the heartbeats stayed pretty.

No span ever said the loop was finished.
Operators marked the job successful anyway.
Success meant "no exception," not "goal met."

Green spans are not a stop signal

Most agent traces record tools instead of goals.
A read_file span can succeed one hundred times.
That success does not mean the job completed.

Dashboards hide the gap behind a zero error rate.
People watch errors and miss runs that never stop.
The process can stay busy until someone kills it.

You need a contract the trace can fail.
The failure contract remains simple and locally testable.
Every run must emit one terminal span.

What a terminal span must prove

A terminal span is not another tool result.
It names why the loop stopped acting.
It also carries the iteration that stopped.

Accept only these stop reasons at first:

done means the stated goal was actually met
rejected means a guard blocked the next act
budget means iteration or time ran out
blocked means a tool returned a hard failure
handoff means another run now owns the goal

If the stream ends without one reason, the run is open.
Open runs are incidents, not quiet successes.
Treat them like missing health checks on a service.

Decision table for a single run

Observation	Class	Action
last span is a tool with `ok`	`open_loop`	cap the run and page
terminal `done` and iter within budget	`closed_ok`	keep a sample only
terminal reason equals `budget`	`closed_cap`	inspect the last plan
two terminal spans in one run	`double_stop`	fix the emitter
iteration sequence contains gaps	`bad_clock`	sort by `seq`, not time
same `args_hash` for three iterations	`no_progress`	halt on the next match

Do not fold these classes into HTTP status codes.
A tool HTTP 200 is not done.
The done flag is a claim about the goal.

JSONL schema you can emit tonight

Keep one JSON object on each line.
Do not pretty-print objects inside the file.
Stable keys beat nested vendor blobs every time.

{"seq":1,"ts":"2026-09-11T02:00:01Z","run_id":"run_7f3","span_id":"sp_01","type":"loop_start","iter":0,"goal":"open_pr"}
{"seq":2,"ts":"2026-09-11T02:00:03Z","run_id":"run_7f3","span_id":"sp_02","parent_id":"sp_01","type":"tool","iter":1,"name":"read_file","args_hash":"a91c","result_hash":"b33e","status":"ok"}
{"seq":3,"ts":"2026-09-11T02:00:08Z","run_id":"run_7f3","span_id":"sp_03","parent_id":"sp_01","type":"tool","iter":2,"name":"edit_file","args_hash":"c10d","result_hash":"c10d","status":"ok"}
{"seq":4,"ts":"2026-09-11T02:41:12Z","run_id":"run_7f3","span_id":"sp_88","parent_id":"sp_01","type":"terminal","iter":38,"reason":"budget","status":"ok","summary":"no_pr_url"}

The seq field is the order the emitter observed.
Do not trust wall clocks across two hosts.
The args_hash field is a short digest of arguments.

Never write secrets into this trace file.
Hash payloads and drop tokens before flush.
A debug loop that leaks keys is worse than silence.

Reproducible checker

The script below is a local proposal.
The script reads JSONL records from standard input.
It prints one verdict line for each run_id.

Treat the listing as an unexecuted local example.
Wire your own emitter before you trust results.

#!/usr/bin/env python3
"""Fail closed when an agent run never terminals."""
from __future__ import annotations

import json
import sys
from collections import defaultdict

BUDGET = 24
NO_PROGRESS_WINDOW = 3
TERMINAL_REASONS = {"done", "rejected", "budget", "blocked", "handoff"}
FAIL = {
    "open_loop",
    "no_progress",
    "double_stop",
    "bad_terminal",
    "bad_clock",
}


def load_spans(stream):
    runs = defaultdict(list)
    for line_no, raw in enumerate(stream, 1):
        text = raw.strip()
        if not text:
            continue
        span = json.loads(text)
        span["_line"] = line_no
        runs[span["run_id"]].append(span)
    return runs


def tool_arg_hashes(spans):
    values = []
    for span in spans:
        if span.get("type") != "tool":
            continue
        values.append(span.get("args_hash") or "")
    return values


def classify(spans):
    ordered = sorted(spans, key=lambda item: item.get("seq", item["_line"]))
    iters = [item.get("iter") for item in ordered if item.get("iter") is not None]
    terminals = [item for item in ordered if item.get("type") == "terminal"]
    max_iter = max(iters) if iters else 0

    if len(terminals) > 1:
        return "double_stop", max_iter

    for left, right in zip(iters, iters[1:]):
        if left + 1 < right:
            return "bad_clock", max_iter

    chain = tool_arg_hashes(ordered)
    if len(chain) >= NO_PROGRESS_WINDOW:
        tail = chain[-NO_PROGRESS_WINDOW:]
        if tail[0] and len(set(tail)) == 1:
            return "no_progress", max_iter

    if not terminals:
        return "open_loop", max_iter

    reason = terminals[0].get("reason")
    if reason not in TERMINAL_REASONS:
        return "bad_terminal", max_iter
    if reason == "done" and max_iter <= BUDGET:
        return "closed_ok", max_iter
    if reason == "budget":
        return "closed_cap", max_iter
    return f"closed_{reason}", max_iter


def main() -> int:
    failed = 0
    runs = load_spans(sys.stdin)
    for run_id, spans in sorted(runs.items()):
        verdict, max_iter = classify(spans)
        print(f"{run_id}\t{verdict}\titer={max_iter}\tspans={len(spans)}")
        if verdict in FAIL:
            failed = 1
    return failed


if __name__ == "__main__":
    raise SystemExit(main())

Save and run

Save the file as terminal_contract.py beside fixtures.
Pipe a known-bad trace through it first.
Confirm a non-zero exit before wiring CI.

python3 terminal_contract.py < traces.jsonl
echo $?

A non-zero exit means some run violated the contract.
Put that exit code on recorded fixtures in CI.
Do not wait for a human to scroll JSONL by hand.

Known-bad fixture

This tiny fixture mimics the staging incident.
There is no terminal span in the stream.
Iteration three already repeats the same edit hash.

{"seq":1,"run_id":"run_bad","type":"loop_start","iter":0,"goal":"open_pr"}
{"seq":2,"run_id":"run_bad","type":"tool","iter":1,"name":"edit_file","args_hash":"aaaa","status":"ok"}
{"seq":3,"run_id":"run_bad","type":"tool","iter":2,"name":"edit_file","args_hash":"aaaa","status":"ok"}
{"seq":4,"run_id":"run_bad","type":"tool","iter":3,"name":"edit_file","args_hash":"aaaa","status":"ok"}

Expected classification is no_progress for run_bad.
The checker should exit with a non-zero status.
If it prints closed_ok, your emitter is lying.

Where a quiet server actually helps

The checker itself is CPU-light and sequential.
It needs a box that stays up between agent runs.
A sleeping laptop will drop the JSONL tail.

MonkeyCode's free server option fits that collector role.
Disclosure: This article was prepared as part of MonkeyCode's product outreach.
Park the tailer there and keep fixtures beside it.

Free model access is optional on the same box.
Use a model only after the contract already failed.
Ask it to cluster summary strings, not to invent spans.

Do not send raw tool payloads to any model.
Send hashes, tool names, and stop reasons only.
The verdict must still come from the script.

A debug loop you can reuse

Emit loop_start with an explicit goal field.
Stamp every tool span with iter plus args_hash.
Emit exactly one terminal span when work stops.
Run terminal_contract.py against the JSONL file.
Freeze the run on open_loop or no_progress.
Label leftover summaries with a model last.

This loop does not replace a tracing backend.
It is a closed-world test on your own JSONL.
Start here, then export spans if files grow.

What this does not catch

The contract cannot see side effects outside the trace.
A done span can still lack a real pull request.
Verify the artifact with a separate probe each time.

Short hashes can hide real argument drift under collision.
Use a longer digest if tests ever collide.
Do not treat four hex characters as a security boundary.

Wall-clock sorting will mis-order concurrent emitters.
That is why seq exists in the schema.
If seq is missing, the checker becomes a guess.

Parallel tools may share one iteration on purpose.
The gap check allows repeated iteration numbers on purpose.
It only flags skipped numbers in the sequence.

This is also not retry accounting on one tool.
Retries share one tool goal and one family of attempts.
Loop stalls keep planning and still go nowhere new.

Who should skip this approach

Skip this if your runs have no stable run_id.
Skip this if legal holds need immutable audit stores.
Skip this if traces still contain live credentials.

Multi-tenant platforms need redaction before any JSONL drop.
This script does not redact fields for you.
Add that layer first, or do not collect traces.

Teams without a hard iteration budget will ignore verdicts.
Pick a number and write it in the file header.
A budget you never enforce is decoration on logs.

Practical next step

Add type=terminal to one agent tonight.
Replay last week's traces if those files still exist.
Count how many green jobs never actually stopped.

Retries Look Green. Count Attempts on Every Tool Span

Riley Wang — Wed, 09 Sep 2026 15:50:52 +0000

The checkout agent returned HTTP 200 to the storefront. Finance later found two captures on one order.

Support exported one successful tool result from logs. The payment processor listed two authorized captures instead.

The span looked healthy because the last attempt won. Earlier attempts still spent tokens and side effects.

Last Success Is Not One Attempt

Many agent runtimes keep only the final tool payload. Retry wrappers often swallow the failed calls underneath.

Logs then show one green span and one result. Reality contains extra network calls and extra token bursts.

This is not an orphan result or missing pairing bug. The final result exists, yet attempts were never counted.

Green status answers a different question than attempt count. Status asks whether the last try worked. Count asks how much work hid beneath that win.

Three Retry Layers, One Log Line

Duplicate charges rarely come from one wrapper. Three layers retry without sharing a counter.

Transport libraries retry on reset and timeout.
Tool executors retry when JSON arguments fail validation.
The agent retries the whole step after a watchdog timeout.

Each layer can emit success on the last try. None of them must emit the earlier tries.

If exporters flatten those layers into one event, storms vanish. Billing systems still see every side effect.

What To Record Per Attempt

Store one event per try, not per finished span. Keep a stable span_id across those numbered tries.

Use these fields on every retry-aware tool event:

run_id: one agent invocation
span_id: one logical tool call
attempt: integer starting at 1
tool_name: stable tool identifier
args_hash: SHA-256 of canonical JSON arguments
idem_hash: SHA-256 of the provider idempotency key
status: ok, error, or timeout
t_start and t_end: unix milliseconds
token_in and token_out: integers or null
side_effect: none, unknown, or external

Skip raw argument bodies in the shared index. Hash them and keep payloads in a local file.

Why hash arguments

Payment tools often carry account numbers and names. Full payloads do not belong on a shared disk.

A hash still joins retries of the same call. You can group storms without leaking customer PII.

Hash the idempotency key the same way. The raw key still goes to the provider. The trace only needs a joinable digest.

Example Timeline For One Span

The next block is a labeled example, not production evidence. Three attempts share span_19 and one argument hash.

{"event":"tool_attempt","run_id":"run_7f3","span_id":"span_19","attempt":1,"tool_name":"charge_card","args_hash":"a91c9e0c","idem_hash":"e2b1aa44","status":"timeout","t_start":1757385600120,"t_end":1757385604120,"token_in":812,"token_out":0,"side_effect":"unknown"}
{"event":"tool_attempt","run_id":"run_7f3","span_id":"span_19","attempt":2,"tool_name":"charge_card","args_hash":"a91c9e0c","idem_hash":"e2b1aa44","status":"error","t_start":1757385604200,"t_end":1757385606100,"token_in":790,"token_out":48,"side_effect":"unknown"}
{"event":"tool_attempt","run_id":"run_7f3","span_id":"span_19","attempt":3,"tool_name":"charge_card","args_hash":"a91c9e0c","idem_hash":"e2b1aa44","status":"ok","t_start":1757385606200,"t_end":1757385607800,"token_in":788,"token_out":36,"side_effect":"external"}

Attempt three is the only ok row. A last-write exporter would keep that row alone.

The first two rows still consumed tokens and network time. If the provider ignored idem_hash, two captures can exist.

Score Completeness Before Debugging

Do not start a root-cause hunt on thin traces. Score the file first, then inspect storms.

Required keys for this workflow:

run_id
span_id
attempt
tool_name
args_hash
status
t_start
t_end

A run with missing attempt scores as incomplete. Treat incomplete runs as untrusted for cost analysis.

Completeness is a gate, not a verdict. A full record can still describe a wrong tool.

Artifact: Retry Storm Scanner

The script below is a local example. It reads JSONL from stdin. It does not open a network socket.

It groups events by span_id. It flags spans with more than one attempt. It also flags status flips inside one span.

#!/usr/bin/env python3
"""Retry storm scanner for agent tool traces.

Example only. Not production telemetry.
"""
from __future__ import annotations

import hashlib
import json
import sys
from collections import defaultdict
from typing import Any, Iterator

REQUIRED = (
    "run_id",
    "span_id",
    "attempt",
    "tool_name",
    "args_hash",
    "status",
    "t_start",
    "t_end",
)


def iter_events(stream) -> Iterator[dict[str, Any]]:
    for line_no, raw in enumerate(stream, 1):
        raw = raw.strip()
        if not raw:
            continue
        try:
            event = json.loads(raw)
        except json.JSONDecodeError as exc:
            print(f"skip line {line_no}: {exc}", file=sys.stderr)
            continue
        yield event


def completeness(event: dict[str, Any]) -> float:
    present = sum(
        1 for key in REQUIRED if key in event and event[key] not in (None, "")
    )
    return present / len(REQUIRED)


def canonical_args_hash(args: Any) -> str:
    blob = json.dumps(args, sort_keys=True, separators=(",", ":")).encode()
    return hashlib.sha256(blob).hexdigest()


def scan(events: Iterator[dict[str, Any]], storm_threshold: int = 2) -> dict[str, Any]:
    by_span: dict[str, list[dict[str, Any]]] = defaultdict(list)
    incomplete = 0
    total = 0
    for event in events:
        if event.get("event") != "tool_attempt":
            continue
        total += 1
        if completeness(event) < 1.0:
            incomplete += 1
            continue
        by_span[str(event["span_id"])].append(event)

    storms = []
    flips = []
    for span_id, attempts in by_span.items():
        attempts.sort(key=lambda row: int(row["attempt"]))
        n = len(attempts)
        statuses = [row["status"] for row in attempts]
        hashes = {row["args_hash"] for row in attempts}
        first = attempts[0]
        last = attempts[-1]
        if n >= storm_threshold:
            storms.append(
                {
                    "span_id": span_id,
                    "run_id": first["run_id"],
                    "tool_name": first["tool_name"],
                    "attempts": n,
                    "statuses": statuses,
                    "unique_args": len(hashes),
                    "ms": int(last["t_end"]) - int(first["t_start"]),
                    "idem_hash": first.get("idem_hash"),
                }
            )
        if len(set(statuses)) > 1:
            flips.append(span_id)

    storms.sort(key=lambda row: row["attempts"], reverse=True)
    return {
        "tool_events": total,
        "incomplete_events": incomplete,
        "spans": len(by_span),
        "storm_spans": len(storms),
        "status_flip_spans": len(flips),
        "top_storms": storms[:20],
    }


def main() -> None:
    report = scan(iter_events(sys.stdin))
    json.dump(report, sys.stdout, indent=2)
    sys.stdout.write("\n")


if __name__ == "__main__":
    main()

Dry-run commands

Save the three example rows as attempts.jsonl. Then run the scanner from the project directory.

python3 -m py_compile retry_storm.py
python3 retry_storm.py < attempts.jsonl

Expected report shape for that fixture, not a live benchmark:

{
  "tool_events": 3,
  "incomplete_events": 0,
  "spans": 1,
  "storm_spans": 1,
  "status_flip_spans": 1
}

If incomplete_events is not zero, stop. Fix the exporter before reading top_storms.

Emit Attempts At The Tool Boundary

The wrapper below is proposed example code. It is not a measured production client.

import time
from typing import Any, Callable


def call_with_attempts(
    emit,
    run_id: str,
    span_id: str,
    tool_name: str,
    args: dict[str, Any],
    fn: Callable[[dict[str, Any]], Any],
    *,
    attempts: int = 3,
    idem_hash: str,
    args_hash: str,
    side_effect: str = "unknown",
) -> Any:
    last_exc: Exception | None = None
    for attempt in range(1, attempts + 1):
        t_start = int(time.time() * 1000)
        status = "ok"
        result = None
        try:
            result = fn(args)
        except TimeoutError:
            status = "timeout"
            last_exc = TimeoutError(tool_name)
        except Exception as exc:  # example only; narrow this in real code
            status = "error"
            last_exc = exc
        t_end = int(time.time() * 1000)
        emit(
            {
                "event": "tool_attempt",
                "run_id": run_id,
                "span_id": span_id,
                "attempt": attempt,
                "tool_name": tool_name,
                "args_hash": args_hash,
                "idem_hash": idem_hash,
                "status": status,
                "t_start": t_start,
                "t_end": t_end,
                "token_in": None,
                "token_out": None,
                "side_effect": side_effect if status == "ok" else "unknown",
            }
        )
        if status == "ok":
            return result
    raise last_exc if last_exc else RuntimeError("tool failed")

Pass one span_id into every retry of that logical call. Do not mint a new span for attempt two.

Leave token_in null when the runtime hides usage. Null is better than a fabricated zero.

Classify A Storm Before You Patch

When the scanner prints a storm, classify it first. The table is a decision aid, not a proof.

Observation	Likely cause	First check
`unique_args = 1`, mixed `error`/`ok`	transient dependency	timeout budget and idempotency key
`unique_args > 1`	agent changed arguments	schema, validator, prompt
many attempts, all `ok`	retry after success	success predicate
high `incomplete_events`	exporter bug	required field list
same `idem_hash`, two provider captures	provider ignored the key	key header and provider docs

Do not start with a model swap. Most storms are counters, predicates, or keys.

Sampling Without Dropping Storms

Full traces grow faster than useful signal. Sample clean spans. Keep every storm span.

A simple local policy looks like this:

keep 100% of spans with attempts >= 2
keep 100% of spans with status != ok
keep 5% of single-attempt ok spans
drop raw payloads after the hash exists

The 5% figure is an example knob. Tune it against disk, not against a marketing quota.

Where Free Model Access Fits

Some storms need a second pass over redacted error strings. A model can cluster those strings after hashes exist.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

MonkeyCode is an open-source project with free model access. It also offers a free server option for small trace indexes.

Use the model on redacted messages only. Keep hashes and counts on the server. Keep raw tool bodies on the laptop.

The scanner still works without that product. Stdin and JSONL are enough for the count.

If those free options are already in reach, point them at storm summaries. Do not upload card numbers or raw keys.

Limitations

Truncated hashes can collide, though full SHA-256 is usually enough. Treat short prefixes as debug labels only.

side_effect=unknown is common and weakens billing conclusions. Clock skew across hosts can inflate ms.

The scanner ignores streaming token events by design. Completeness scoring does not prove a tool was correct.

Example thresholds are not capacity plans. They are starting gates for a local debug loop.

Who Should Skip This

Skip this workflow if tools never retry. A counter on single-attempt spans adds noise.

Skip it under an extreme threat model that forbids argument hashes. Some regulated payloads cannot be digested off-box.

Skip it for hard real-time loops that cannot buffer JSONL. This method assumes a file you can score later.

Do not treat the script as a managed APM replacement. It does not trace processes, GC, or kernel waits.

Tonight's Checklist

Emit attempt on every tool try.
Reuse one span_id across those tries.
Hash arguments before any shared disk.
Score completeness on ingest.
Alert on storm_spans, not only on errors.

Green spans can still charge twice. Count attempts before you trust the trace.

Agent Traces Hide Wait Time. Split Three Lanes.

Riley Wang — Tue, 08 Sep 2026 03:30:27 +0000

A checkout agent froze during a Tuesday traffic spike.
Logs showed a green span for every tool.
The customer still waited a full forty-one seconds.

Token usage charts looked healthy for the whole run.
Ops blamed the language model first, as usual.
The production prompt had not changed since Friday.

Recorded tool HTTP codes were all two hundred.
Nothing on the on-call dashboard looked broken.
The missing signal was idle time, not tokens.

The run waited on a lock, then on DNS.
Those waits never became billed model tokens at all.
A single LLM latency number hid both waits.

One latency number hides the stall

Most agent dashboards still plot only one duration.
They name it model time or request latency.
That single number mixes generation, I/O, and sleep.

A two-second generate can sit behind a thirty-second lock.
The chart still colors the span as model work.
Prompt edits then waste the next two days.

Split wall-clock time before you touch any prompts.
If idle plus tool exceed model time, stop.
Do not buy tokens to fix a mutex wait.

Request sampling breaks causal agent runs

Classic APM samples one percent of HTTP spans.
That old heuristic fits stateless web handlers only.
An agent run is a short causal chain.

Drop two spans and the whole plot collapses.
Retry three is meaningless without retry two nearby.
A child span without its parent is noise.

Keep the whole run or keep nothing useful.
Per-span sampling also biases those slow multi-tool paths.
Longer agent runs with more tools become under-represented.

Fast crashes vanish from the retained sample set.
Your heatmap then lies about real users.
Close the run first, then sample only after that.

Three lanes, not one clock

Give every closed interval exactly one named lane.

Model lane

Count queue time, token generation, and stream parse.
Count only work gated on the model API.
Do not park tool HTTP inside this lane.

Tool lane

Cover DNS, connect, execute, and result serialize steps.
Record your own status, not only HTTP codes.
A two-hundred response can still be wrong.

Idle lane

Cover locks, backoff, rate-limit sleeps, and human gates.
This lane is where "slow model" stories die.
If idle wins, you have an orchestration bug.

Sum the three lanes against wall clock.
Mismatch means overlapping spans or bad clocks exist.
Treat mismatch as a tracer bug, not noise.

A small JSONL contract

Label this format as a local proposal.
It is not an industry standard.

{"run_id":"r-9f2","seq":1,"lane":"model","name":"plan","t_start_ms":0,"t_end_ms":812,"status":"ok"}
{"run_id":"r-9f2","seq":2,"lane":"idle","name":"lock_wait","t_start_ms":812,"t_end_ms":24010,"status":"ok"}
{"run_id":"r-9f2","seq":3,"lane":"tool","name":"inventory.get","t_start_ms":24010,"t_end_ms":40702,"status":"ok","http":200}
{"run_id":"r-9f2","seq":4,"lane":"idle","name":"stop","t_start_ms":40702,"t_end_ms":40702,"status":"ok"}

Required fields stay intentionally small.

run_id binds events to one user task
seq restores order when files shuffle
lane must be model, tool, or idle
t_start_ms and t_end_ms are run-relative
status is ok, error, or timeout

HTTP success is not your status field.
Set status from a checker you own.
Garbage payloads should mark the span error.

Emit lanes from the agent loop

The helper below is a runnable local example.
It uses monotonic time inside one process.
Do not mix wall clocks from two hosts.

# example emitter — not a production tracer
from __future__ import annotations

import json
import time
from contextlib import contextmanager
from pathlib import Path
from typing import Iterator


class RunTrace:
    def __init__(self, run_id: str, path: str) -> None:
        self.run_id = run_id
        self.path = Path(path)
        self.seq = 0
        self.origin = time.monotonic()

    def _now_ms(self) -> int:
        return int((time.monotonic() - self.origin) * 1000)

    @contextmanager
    def lane(self, lane: str, name: str, **extra: object) -> Iterator[None]:
        if lane not in {"model", "tool", "idle"}:
            raise ValueError(f"bad lane {lane}")
        start = self._now_ms()
        status = "ok"
        try:
            yield
        except Exception:
            status = "error"
            raise
        finally:
            self.seq += 1
            event = {
                "run_id": self.run_id,
                "seq": self.seq,
                "lane": lane,
                "name": name,
                "t_start_ms": start,
                "t_end_ms": self._now_ms(),
                "status": status,
            }
            event.update(extra)
            with self.path.open("a", encoding="utf-8") as handle:
                handle.write(json.dumps(event) + "\n")


# labeled example loop, not a live customer bot
def fake_checkout(trace: RunTrace) -> None:
    with trace.lane("model", "plan"):
        time.sleep(0.05)
    with trace.lane("idle", "lock_wait"):
        time.sleep(0.20)
    with trace.lane("tool", "inventory.get", http=200):
        time.sleep(0.12)
    with trace.lane("idle", "stop"):
        pass

Wrap each phase with a lane context.
Model calls go in model.
Inventory I/O goes in tool.

time.sleep for backoff goes in idle.
Flush one JSON object per closed interval.
Never sample while seq is still growing.

Sampling mid-run is how plots go hollow.
Write the stop interval before any copy job.
A file without stop stays in quarantine.

Completeness before retention

A run is complete only when all hold.

Sequence numbers are contiguous from one
Every interval has t_end_ms >= t_start_ms
Lane sums match wall clock within 50ms
The last event is named stop

If any check fails, quarantine the file.
Incomplete traces teach the wrong story.
They are worse than an empty folder.

Fifty milliseconds is a local tolerance.
Laptop NTP drift will trip a tighter bound.
Prefer monotonic clocks for t_start_ms.

Print a waterfall from a closed file

Run the checker against one run_id.
It should refuse gaps and clock skew.

#!/usr/bin/env python3
"""Lane waterfall for one closed agent run."""
from __future__ import annotations

import json
import sys
from collections import defaultdict
from pathlib import Path

LANES = ("model", "tool", "idle")
TOLERANCE_MS = 50


def load_events(path: Path, run_id: str) -> list[dict]:
    rows = []
    with path.open(encoding="utf-8") as handle:
        for line in handle:
            line = line.strip()
            if not line:
                continue
            event = json.loads(line)
            if event.get("run_id") == run_id:
                rows.append(event)
    rows.sort(key=lambda event: int(event["seq"]))
    return rows


def assert_complete(events: list[dict]) -> None:
    if not events:
        raise SystemExit("no events for run")
    seqs = [int(event["seq"]) for event in events]
    expected = list(range(1, len(seqs) + 1))
    if seqs != expected:
        raise SystemExit(f"gap in seq: {seqs}")
    if events[-1].get("name") != "stop":
        raise SystemExit("run never closed")


def lane_ms(events: list[dict]) -> dict[str, int]:
    totals: dict[str, int] = defaultdict(int)
    for event in events:
        lane = event["lane"]
        if lane not in LANES:
            raise SystemExit(f"bad lane {lane}")
        width = int(event["t_end_ms"]) - int(event["t_start_ms"])
        if width < 0:
            raise SystemExit(f"negative width at seq {event['seq']}")
        totals[lane] += width
    return dict(totals)


def bar(ms: int, scale: float) -> str:
    if scale <= 0:
        return ""
    return "#" * int(round(ms / scale))


def main() -> None:
    if len(sys.argv) != 3:
        raise SystemExit("usage: waterfall.py TRACE.jsonl RUN_ID")
    events = load_events(Path(sys.argv[1]), sys.argv[2])
    assert_complete(events)
    totals = lane_ms(events)
    wall = int(events[-1]["t_end_ms"]) - int(events[0]["t_start_ms"])
    summed = sum(totals.get(lane, 0) for lane in LANES)
    if abs(summed - wall) > TOLERANCE_MS:
        raise SystemExit(f"clock mismatch wall={wall} sum={summed}")
    peak = max(totals.values()) if totals else 1
    scale = peak / 40
    print(f"run {sys.argv[2]} wall_ms={wall}")
    for lane in LANES:
        ms = totals.get(lane, 0)
        pct = 0 if wall == 0 else 100 * ms / wall
        print(f"{lane:5} {ms:8}ms {pct:5.1f}% {bar(ms, scale)}")
    dominant = max(LANES, key=lambda lane: totals.get(lane, 0))
    print(f"dominant_lane={dominant}")
    if dominant != "model":
        print("action: do not tune the prompt first")


if __name__ == "__main__":
    main()

python3 waterfall.py checkout.jsonl r-9f2

Fixture output for the Tuesday stall:

run r-9f2 wall_ms=40702
model     812ms   2.0% #
idle    23198ms  57.0% #######################
tool    16692ms  41.0% ################
dominant_lane=idle
action: do not tune the prompt first

Those digits are a fixture, not a benchmark.
Replace them with your closed traces.
The lesson is lane dominance, not the ms.

If idle dominates, stop prompt tuning.
If tool dominates, inspect timeouts next.
If model dominates, then inspect tokens.

Reproducible test plan

Treat this as a checklist, not a paper.

Build three fixtures: model, tool, idle heavy
Assert the script names the dominant lane
Delete one seq value and expect a nonzero exit
Keep HTTP 200 while status becomes error
Shift t_end_ms by 500ms and expect mismatch
Confirm incomplete files stay quarantined

If step three still prints bars, halt.
The completeness gate is not real yet.
Fix the gate before any dashboard work.

Step four is easy to skip under pressure.
Green HTTP will fool a tired on-call engineer.
Keep status independent from the transport code.

Retention decision table

Do not copy web APM retention defaults.
Agent files carry tool arguments and PII.
Shorter retention is safer than a leak.

Redact on the origin host

API keys appear in tool arguments often.
User emails appear in search queries often.
A debug copy can become a second incident.

Strip secrets before the file moves.
Keep hashes of payloads if you need diffs.
If you cannot redact, do not ship the file.

A free server as a quiet checker

Closed JSONL files are small on purpose.
Overnight jobs do not need a GPU.
A free server is enough for the checker.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

MonkeyCode provides free model access and a free server option.
Park the waterfall job on that free server.
Use free model access to synthesize fixtures only.

Do not send production user runs to a free tier.
Redact first, or keep traces on the origin host.
The habit matters more than the vendor.

Practical loop, if you need a default.

Agents append JSONL on local disk
Cron copies only closed, redacted runs
waterfall.py fails incomplete files
Mail a dominant-lane summary each morning
Open idle-heavy and error runs first

If you try that free server, start with fixtures.

Limitations

This schema ignores nested child agents.
It also ignores concurrent tool calls.
Overlapping intervals will exceed wall clock.

Serialize tools or record a true span graph.
The fifty millisecond bound is arbitrary.
Mislabeling sleep as tool recreates the lie.

The script does not prove answer quality.
A fast wrong answer still looks model-heavy.
Add semantic checks in a later pass.

Who should skip this

Skip it for single-shot completions with no tools.
Skip it if legal blocks storing tool arguments.
Skip it if you already have trusted causal tracing.

Skip the copy step when redaction is incomplete.
Local disks beat leaked traces every time.
This workflow is for short tool loops you own.

On the next freeze

Ask for the closed JSONL, not a screenshot.
Ask which lane ate the wall clock.
If idle wins, fix orchestration first.

If tool wins, inspect timeouts and payloads.
If model wins, then look at tokens.
Keep whole runs until that story is boring.

Orphan Tool Calls Look Like Hangs. Pair Every Result.

Riley Wang — Sun, 06 Sep 2026 21:07:43 +0000

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"}

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 outstanding is empty.
Tool stall: outstanding is not empty, and no tool_result arrives.
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 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

Emit tool_call and tool_result with a shared call_id.
Hash arguments. Store deadline_ms on the call span.
Add http_status when 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.

Nested Agent Failures Hide in Flat Logs. Build a Span Tree.

Riley Wang — Sat, 05 Sep 2026 19:45:03 +0000

A checkout agent passed every unit test. Production still dropped the refund.

Ops pasted a 400-line tool log. Every call returned HTTP 200.

Two write_order events sat back to back. Neither row named a parent span.

A retry had spawned a nested planner. That planner spawned a second writer.

Flat logs showed success twice. The database showed one orphan order.

Treat that incident as a tracing problem. Do not treat it as a prompt problem.

The failure mode

Most agent traces are arrays. Each row stores name, args, and latency.

That shape works for one loop. Nested agents break this flat shape in production.

Those rows drop three causal facts at once:

which planner spawned the tool call
which retry still owns the write
which spans never closed at all

Wall-clock order is not causal order. Two tools can overlap in time.

A child can finish after its parent. A retry can outlive the user request.

What a span tree records

Use one record per attempt. Do not use one row per tool name.

Minimum fields for a worked example:

{
  "trace_id": "tr_9f2c",
  "span_id": "sp_44a1",
  "parent_span_id": "sp_110c",
  "name": "tool.write_order",
  "kind": "tool",
  "status": "ok",
  "start_ms": 1725621000120,
  "end_ms": 1725621000488,
  "attrs": {
    "retry": 1,
    "agent": "refund-planner"
  }
}

trace_id ties the user request together. span_id names this single attempt.

parent_span_id names the caller span. Root spans store null for parent.

Label this schema as an example. It is not a vendor standard.

Why this is not another JSONL dump

A JSONL file can still be flat. Nesting lives only in the identifiers.

You may keep JSONL on disk. You must join on parent_span_id at read time.

The debug question then changes. You no longer ask what ran last.

You ask which child of this planner failed. You ask which retry is still open.

A collector you can run tonight

The snippet below is a worked example. Run it locally before any remote host.

# span_tree.py — example collector, not production telemetry
from __future__ import annotations

import json
import time
import uuid
from contextlib import contextmanager
from dataclasses import dataclass, field, asdict
from typing import Iterator, Optional


def _id(prefix: str) -> str:
    return f"{prefix}_{uuid.uuid4().hex[:8]}"


@dataclass
class Span:
    trace_id: str
    span_id: str
    parent_span_id: Optional[str]
    name: str
    kind: str
    start_ms: int
    end_ms: Optional[int] = None
    status: str = "unset"
    attrs: dict = field(default_factory=dict)

    def close(self, status: str = "ok") -> None:
        self.end_ms = int(time.time() * 1000)
        self.status = status


class SpanForest:
    def __init__(self) -> None:
        self.spans: list[Span] = []

    @contextmanager
    def span(
        self,
        name: str,
        *,
        kind: str,
        trace_id: str,
        parent_span_id: Optional[str],
        **attrs,
    ) -> Iterator[Span]:
        rec = Span(
            trace_id=trace_id,
            span_id=_id("sp"),
            parent_span_id=parent_span_id,
            name=name,
            kind=kind,
            start_ms=int(time.time() * 1000),
            attrs=dict(attrs),
        )
        self.spans.append(rec)
        try:
            yield rec
            if rec.status == "unset":
                rec.close("ok")
        except Exception as exc:
            rec.attrs["error"] = type(exc).__name__
            rec.close("error")
            raise

    def dump(self, path: str) -> None:
        with open(path, "w", encoding="utf-8") as fh:
            for rec in self.spans:
                fh.write(json.dumps(asdict(rec)) + "\n")

Wrap each planner step. Wrap each tool. Wrap each retry.

# example_agent.py — labeled sketch of a nested loop
from span_tree import SpanForest, _id


def run_refund(forest: SpanForest, order_id: str) -> None:
    trace_id = _id("tr")
    with forest.span(
        "agent.refund", kind="agent", trace_id=trace_id, parent_span_id=None
    ) as root:
        with forest.span(
            "planner.decide",
            kind="agent",
            trace_id=trace_id,
            parent_span_id=root.span_id,
            order_id=order_id,
        ) as planner:
            for attempt in (0, 1):
                with forest.span(
                    "tool.write_order",
                    kind="tool",
                    trace_id=trace_id,
                    parent_span_id=planner.span_id,
                    retry=attempt,
                ) as tool:
                    # replace this branch with your real tool client
                    if attempt == 0:
                        tool.close("error")
                        tool.attrs["reason"] = "timeout"
                    else:
                        tool.close("ok")

Capture one run with a short command:

python -c "from span_tree import SpanForest; from example_agent import run_refund; f=SpanForest(); run_refund(f, 'ord_22'); f.dump('spans.jsonl'); print(len(f.spans))"

Rebuild the tree, then score it

A dump is not a diagnosis. Join parent ids next.

# analyze_spans.py — example checks, not a full APM product
from collections import defaultdict
import json
import sys


def load(path: str) -> list[dict]:
    rows = []
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            rows.append(json.loads(line))
    return rows


def index_by_parent(rows: list[dict]) -> dict:
    tree = defaultdict(list)
    for row in rows:
        tree[row["parent_span_id"]].append(row)
    return tree


def duration_ms(row: dict):
    if row["end_ms"] is None:
        return None
    return row["end_ms"] - row["start_ms"]


def find_orphans(rows: list[dict]) -> list[str]:
    ids = {row["span_id"] for row in rows}
    bad = []
    for row in rows:
        parent = row["parent_span_id"]
        if parent and parent not in ids:
            bad.append(row["span_id"])
    return bad


def find_open(rows: list[dict]) -> list[str]:
    return [row["span_id"] for row in rows if row["end_ms"] is None]


def find_overlap(rows: list[dict], name: str) -> list[tuple[str, str]]:
    tools = [r for r in rows if r["name"] == name and r["end_ms"]]
    hits = []
    for i, a in enumerate(tools):
        for b in tools[i + 1 :]:
            if a["trace_id"] != b["trace_id"]:
                continue
            if a["start_ms"] < b["end_ms"] and b["start_ms"] < a["end_ms"]:
                hits.append((a["span_id"], b["span_id"]))
    return hits


def print_tree(tree: dict, parent, depth: int = 0) -> None:
    for row in sorted(tree[parent], key=lambda r: r["start_ms"]):
        dur = duration_ms(row)
        pad = "  " * depth
        print(f"{pad}{row['name']} {row['status']} {dur}ms span={row['span_id']}")
        print_tree(tree, row["span_id"], depth + 1)


if __name__ == "__main__":
    rows = load(sys.argv[1])
    tree = index_by_parent(rows)
    print("== waterfall ==")
    print_tree(tree, None)
    print("orphans", find_orphans(rows))
    print("open", find_open(rows))
    print("overlap write_order", find_overlap(rows, "tool.write_order"))

Run the analyzer on the dump:

python analyze_spans.py spans.jsonl

Expected shape for the refund case:

== waterfall ==
agent.refund ok 410ms span=sp_...
  planner.decide ok 390ms span=sp_...
    tool.write_order error 180ms span=sp_...
    tool.write_order ok 200ms span=sp_...
orphans []
open []
overlap write_order []

Read the three scores as alarms. Empty lists mean the tree is internally consistent.

Non-empty overlap write_order: two writers shared one order.
Non-empty orphans: a child outlived the collector process.
Non-empty open: a tool never returned a close event.

Hung nested agents show up as open spans. Racy retries show up as overlaps.

A reusable debug loop

Use the same four steps on every incident. Do not start with a new prompt.

Capture one trace_id from the failing request.
Rebuild the span tree. Print the waterfall.
Score orphans, open spans, and exclusive overlaps.
Replay only the failing subtree. Leave the rest frozen.

Decision table for step four:

Finding	Likely cause	Next action
Overlap on a write tool	Nested retry without a lock	Serialize that tool per `trace_id`
Orphan child	Collector crashed mid-retry	Flush spans on exception paths
Open span past SLA	Tool client has no timeout	Bound the span, then fail closed
Child ok, parent error	Parent ignored child status	Propagate child `error` upward
Two roots, one user	Missing `trace_id` on fan-out	Pass the id into sub-agents

This loop is the reusable artifact. Keep the table beside the collector.

A small test plan

Do not trust the collector without tests. These cases are labeled examples.

# test_span_tree.py — example tests
from span_tree import SpanForest


def test_parent_links_nested_tool():
    forest = SpanForest()
    with forest.span(
        "agent.refund", kind="agent", trace_id="tr_1", parent_span_id=None
    ) as root:
        with forest.span(
            "tool.write_order",
            kind="tool",
            trace_id="tr_1",
            parent_span_id=root.span_id,
        ):
            pass
    child = forest.spans[1]
    assert child.parent_span_id == forest.spans[0].span_id
    assert child.end_ms is not None


def test_error_closes_span():
    forest = SpanForest()
    try:
        with forest.span(
            "tool.x", kind="tool", trace_id="tr_2", parent_span_id=None
        ):
            raise TimeoutError("boom")
    except TimeoutError:
        pass
    assert forest.spans[0].status == "error"
    assert forest.spans[0].end_ms is not None

python -m pytest test_span_tree.py -q

If the parent assertion fails, context was dropped. Fix the wrapper before any host deploy.

Where a free server fits

Local files work for one crash. They fail under concurrent nested agents.

You need a process that accepts spans. You need disk that survives SSH drops.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

MonkeyCode is an open-source project. It currently offers free model access and a free server option.

Use that pair only as a place to run the collector. The span schema does not depend on it.

Remove the product and the analyzer still works. Reader value should survive that removal.

A small host is enough here. The collector writes JSONL. The analyzer reads JSONL.

Do not ship raw tool arguments to any host. Redact tokens, secrets, and PII first.

Redact before you trace

Observability can leak more than the agent. Treat spans as public logs.

Minimum redaction rules:

drop Authorization headers
hash account ids
truncate tool payloads over 2 KB
never store raw card or session tokens

SENSITIVE = ("token", "password", "authorization", "cookie", "secret")


def redact(attrs: dict) -> dict:
    clean = {}
    for key, value in attrs.items():
        low = key.lower()
        if any(s in low for s in SENSITIVE):
            clean[key] = "[redacted]"
        elif isinstance(value, str) and len(value) > 2048:
            clean[key] = value[:2048] + "…"
        else:
            clean[key] = value
    return clean

Call redact before dump. Do this on a free server too.

Clock skew is a second leak of truth. Do not compare start_ms across two machines.

Keep one collector process per host. Join traces later by trace_id, not by time.

Limitations

This is not distributed tracing. There is no sampler or baggage header.

The overlap check is O(n²) per tool name. It is fine under a few hundred spans.

It is not fine for a 50k-span overnight soak. Shard files by trace_id first.

The example does not persist across processes. You must append JSONL yourself.

A perfect tree can still write the wrong order. The tree proves structure, not business correctness.

Who should not use this

Skip this if your agent is one tool call. A request log is enough.

Skip this if OpenTelemetry already carries parent context. Do not duplicate span ids.

Skip this if legal blocks any tool-arg storage. The redactor is not a compliance program.

Skip this if you need live dashboards. The artifact is a file and a script.

What to measure next

Count three numbers per day. Add nothing else during week one.

orphan rate per 100 traces
open-span rate past 30 seconds
exclusive-tool overlap count

If orphan rate rises, nested planners are dropping context. If overlap count rises, retries are racing writes.

Fix those two before you tune prompts. The tree shows which subtree to replay.

If a host is already running, point the dump path there. If not, the free server option is one way to keep this collector alive without standing up GPUs.

Concurrent Tool Calls Scramble Logs. Diff the Span DAG Instead.

Riley Wang — Fri, 04 Sep 2026 17:29:19 +0000

A support bot fired three tools during one user turn.
The parent span still closed with a success status.
The refund tool had failed two seconds earlier.

Logs arrived in wall-clock order, not causal order.
The search line printed after the refund timeout.
A reviewer read the file top to bottom and missed it.

This bug is a topology miss, not a weak prompt.
Parallel tool calls scramble line-oriented agent logs.
You need a span DAG before you need another model.

The failure is the graph, not the line

Most agent traces are JSONL files of events.
That shape works for serial ReAct loops.
It collapses when two tools overlap in time.

Three facts disappear inside a flat tail:

parent and child relationships across tools
overlapping start and end timestamps
which sibling actually failed first

A span DAG restores those three facts.
Each tool call becomes a node with a parent.
The run becomes a tree you can diff later.

A minimal span record

Use one record type for every timed event.
Keep identifiers stable across a single retry.

{
  "trace_id": "tr_7f3a",
  "span_id": "sp_12c0",
  "parent_span_id": "sp_0001",
  "kind": "tool",
  "name": "refund.create",
  "t_start_ms": 1725541200120,
  "t_end_ms": 1725541201890,
  "status": "error",
  "error_class": "TimeoutError",
  "attrs": {"order_id_hash": "9c1a"}
}

Rules for the record:

trace_id stays constant for one user turn.
span_id stays unique inside that trace.
Root spans store parent_span_id as null.
t_end_ms is always greater than t_start_ms.
status is ok, error, or cancelled only.

Do not store raw prompts inside attrs.
Store hashes if you need content identity later.
Redact tokens, cookies, and raw account numbers.

Stack tracers break under threads

Many tracers keep a parent stack in thread locals.
That design assumes one span is active at a time.
Concurrent tools violate that assumption immediately.

A worker thread may see an empty stack.
The child span then becomes a second root.
Your later diff reports a missing edge, not a timeout.

Pass parent_span_id into the worker explicitly.
Do not rely on implicit stack order for fan-out.
Protect the span list with a lock.

Labeled example: an explicit-parent tracer

The code below is a labeled example.
Run the tests before you trust the tracer.
It writes one JSONL object when each span ends.

# span_tracer.py
from __future__ import annotations

import json
import threading
import time
import uuid
from contextlib import contextmanager
from dataclasses import asdict, dataclass, field
from typing import Iterator, Optional

_UNSET = object()


def _now_ms() -> int:
    return int(time.time() * 1000)


def _sid() -> str:
    return "sp_" + uuid.uuid4().hex[:8]


@dataclass
class Span:
    trace_id: str
    span_id: str
    parent_span_id: Optional[str]
    kind: str
    name: str
    t_start_ms: int
    t_end_ms: Optional[int] = None
    status: str = "ok"
    error_class: Optional[str] = None
    attrs: dict = field(default_factory=dict)


class SpanTracer:
    def __init__(self, path: str) -> None:
        self.path = path
        self.trace_id = "tr_" + uuid.uuid4().hex[:8]
        self._lock = threading.Lock()
        self._stack: list[str] = []

    def _parent_from_stack(self) -> Optional[str]:
        return self._stack[-1] if self._stack else None

    @contextmanager
    def span(
        self,
        kind: str,
        name: str,
        parent_span_id: object = _UNSET,
        **attrs,
    ) -> Iterator[Span]:
        if parent_span_id is _UNSET:
            parent_span_id = self._parent_from_stack()
        rec = Span(
            trace_id=self.trace_id,
            span_id=_sid(),
            parent_span_id=parent_span_id,  # type: ignore[arg-type]
            kind=kind,
            name=name,
            t_start_ms=_now_ms(),
            attrs=attrs,
        )
        with self._lock:
            self._stack.append(rec.span_id)
        try:
            yield rec
        except Exception as exc:
            rec.status = "error"
            rec.error_class = type(exc).__name__
            raise
        finally:
            rec.t_end_ms = _now_ms()
            with self._lock:
                if self._stack and self._stack[-1] == rec.span_id:
                    self._stack.pop()
                self._append(rec)

    def _append(self, rec: Span) -> None:
        line = json.dumps(asdict(rec), sort_keys=True)
        with open(self.path, "a", encoding="utf-8") as fh:
            fh.write(line + "\n")

Wrap the agent turn as the root span.
Capture root.span_id before any fan-out.
Hand that id to every concurrent tool span.

# example_turn.py
import concurrent.futures
import time

from span_tracer import SpanTracer


def search(_q: str) -> str:
    time.sleep(0.15)
    return "sku_1"


def refund(_order_id: str) -> str:
    time.sleep(0.40)
    raise TimeoutError("payment gateway")


def notify(_user_id: str) -> str:
    time.sleep(0.10)
    return "queued"


def run_turn(path: str = "traces.jsonl") -> None:
    tr = SpanTracer(path)
    with tr.span("agent", "turn", user_hash="u_demo") as root:
        parent = root.span_id

        def work(name, fn, **attrs):
            with tr.span("tool", name, parent_span_id=parent, **attrs):
                return fn()

        with concurrent.futures.ThreadPoolExecutor(max_workers=3) as pool:
            futs = [
                pool.submit(work, "catalog.search", lambda: search("shoes"), q_hash="s1"),
                pool.submit(work, "refund.create", lambda: refund("ord_9"), order_hash="o9"),
                pool.submit(work, "notify.send", lambda: notify("u_demo"), user_hash="u_demo"),
            ]
            errors = []
            for fut in concurrent.futures.as_completed(futs):
                try:
                    fut.result()
                except Exception as exc:
                    errors.append(type(exc).__name__)
            if errors:
                root.status = "error"
                root.error_class = ",".join(sorted(set(errors)))

The parent pointer is data, not a call stack.
Threads can finish in any wall-clock order.
The DAG still reconstructs the same tree.

Build the DAG, then diff the edges

Do not start with prompt text after a failure.
Rebuild the edge set from parent_span_id first.
Compare it to the topology you expected.

# dag_diff.py
import json
from collections import defaultdict


def load_spans(path: str) -> list[dict]:
    rows = []
    with open(path, encoding="utf-8") as fh:
        for line in fh:
            line = line.strip()
            if line:
                rows.append(json.loads(line))
    return rows


def edges(rows: list[dict]) -> set[tuple[str, str]]:
    by_id = {r["span_id"]: r for r in rows}
    out = set()
    for r in rows:
        parent = r.get("parent_span_id")
        if not parent:
            continue
        parent_name = by_id[parent]["name"] if parent in by_id else "?"
        out.add((parent_name, r["name"]))
    return out


def duration_ms(row: dict) -> int:
    return int(row["t_end_ms"] - row["t_start_ms"])


EXPECTED = {
    ("turn", "catalog.search"),
    ("turn", "refund.create"),
    ("turn", "notify.send"),
}


def report(path: str) -> dict:
    rows = load_spans(path)
    got = edges(rows)
    orphans = [r for r in rows if r["parent_span_id"] and r["kind"] == "tool"]
    return {
        "missing_edges": sorted(EXPECTED - got),
        "extra_edges": sorted(got - EXPECTED),
        "error_leaves": [r["name"] for r in rows if r["status"] == "error"],
        "waterfall": sorted(
            ((r["name"], duration_ms(r)) for r in rows),
            key=lambda x: x[1],
            reverse=True,
        ),
        "orphan_tool_count": sum(1 for r in rows if r["parent_span_id"] is None and r["kind"] == "tool"),
    }

Missing edges usually mean a tracer bug.
Error leaves with a complete tree mean a tool bug.
Extra edges often mean a retry spawned a new parent.

Failure taxonomy from the graph

Use the graph shape before you open a prompt dump.
The table below is a decision aid, not a score.

Symptom	Graph shape	First check
One child timed out, parent still `ok`	Complete tree, one error leaf	Downstream gateway, not the prompt
Tool span has no parent	Extra root, missing expected edge	Thread-local stack, not the model
Parent `error`, children all `ok`	Root failed during join	Exception handling in the orchestrator
Same tool name, two different parents	Split tree after retry	Span id recycled or retry wrapper
Long root, short children	Root includes model wait	Missing `llm` span around the call
Children overlap, order looks random	Valid fan-out, messy timestamps	Read duration, ignore log order

A complete tree with one timeout is not a prompt problem.
A missing edge is not a model quality problem.
Those two classes need different patches.

Waterfall time is not token spend

Wall clock and token count answer different questions.
A 400ms gateway timeout can dwarf a short thought span.
A cheap tool can still pin the whole turn.

Rank spans by t_end_ms - t_start_ms first.
Then inspect error_class on the slow error leaf.
Only then open hashes that point at prompt text.

Sample commands for a local file:

python -c "from dag_diff import report; import json; print(json.dumps(report('traces.jsonl'), indent=2))"
wc -l traces.jsonl

You want four spans for the labeled turn.
You want three edges from turn to tools.
You want refund.create in error_leaves.

A debug loop you can reuse

Keep this loop on one machine and one file format.
Do not mix prompt dumps into the first pass.

Record spans with explicit parent ids.
Rebuild edges from parent_span_id.
Diff against the expected edge set.
Rank spans by duration for a waterfall.
Classify error_class on failed leaves.
Inspect prompt hashes only after the graph is clean.

Step six is optional on many incidents.
Topology bugs never need the prompt text.
Gateway timeouts rarely need a new system prompt.

Where a free server fits

Overnight traces need a process that stays up.
JSONL append plus a small join loop is enough.
A paid GPU box is the wrong cost center here.

MonkeyCode offers free model access and a free server option for that kind of harness. Disclosure: This article was prepared as part of MonkeyCode's product outreach.

Keep the tracer next to the agent process.
Ship JSONL off the box if the disk is tiny.
Do not wait for a hosted APM trial to start.

Tests for the edge set

Labeled tests follow. They do not claim production coverage.
They catch the thread bug the stack tracer would hide.

# test_span_dag.py
import os
import unittest
from pathlib import Path

from dag_diff import edges, load_spans, report
from example_turn import run_turn


class SpanDagTests(unittest.TestCase):
    def setUp(self) -> None:
        self.path = "test_traces.jsonl"
        if os.path.exists(self.path):
            os.remove(self.path)

    def tearDown(self) -> None:
        if os.path.exists(self.path):
            os.remove(self.path)

    def test_fanout_keeps_three_child_edges(self) -> None:
        with self.assertRaises(TimeoutError):
            # run_turn swallows worker errors; call refund path directly if needed
            run_turn(self.path)
        rows = load_spans(self.path)
        names = {r["name"] for r in rows}
        self.assertIn("turn", names)
        self.assertTrue({"catalog.search", "refund.create", "notify.send"} <= names)
        got = edges(rows)
        self.assertIn(("turn", "refund.create"), got)
        self.assertEqual(sum(1 for r in rows if r["kind"] == "tool" and r["parent_span_id"] is None), 0)

    def test_report_flags_timeout_leaf(self) -> None:
        run_turn(self.path)
        out = report(self.path)
        self.assertEqual(out["missing_edges"], [])
        self.assertIn("refund.create", out["error_leaves"])


if __name__ == "__main__":
    unittest.main()

If orphan_tool_count is not zero, stop.
Fix the parent pointer before you retune prompts.
The graph is lying, so the model looks guilty.

Limitations

This tracer is not an OpenTelemetry SDK.
It will not export to a vendor collector.
Clock skew across hosts will invert waterfalls.

There is no sampling policy in the example.
High-QPS agents will grow JSONL without a cap.
There is no encryption at rest in the file write.

The expected edge set is hand-maintained.
Agents that invent tools at runtime will mismatch.
You must version that set beside the tool list.

The example does not prove answer quality.
A perfect DAG can still ship a wrong refund.
Pair this loop with contract tests on tool results.

Who should skip this approach

Skip it if you cannot redact secrets in attrs.
Skip it for sub-millisecond inner loops.
Skip it if no one can name the expected edges.

Also skip a homemade JSONL file when you already run a span backend.
Duplicate traces create two sources of truth.
Pick one graph and delete the other.

Close

Read agent logs as a graph, not a diary.
Parent pointers find bugs that prompts cannot.
Start with the edge-diff test, then add one redaction filter.

Your Agent Is Leaking Tokens. Build a Decision Ledger on a Free Server.

Riley Wang — Fri, 04 Sep 2026 12:07:01 +0000

Your agent loops on the same tool call. It rephrases. It retries. Tokens vanish.

No crash. No error. Just a silent budget leak.

The current agent conversation keeps circling one idea: remember decisions, not just data. Raw logs tell you what happened. A decision ledger tells you why. This tutorial turns that idea into a runnable pattern.

You will build a self-auditing agent on a free server. Every step ends with a verification check. The final artifact is a SQLite ledger with a hard token budget.

What You Need

MonkeyCode is an open-source project. Its current free tier includes a 10M token allowance and a free server option. Quotas change, so verify the numbers in your dashboard before you build.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

Python 3.10+ on the server.
requests and the standard library sqlite3.

The design is endpoint-agnostic. You will adapt one function to the API contract in the project docs.

Step 1: Provision the Free Server

MonkeyCode's free server option gives you a Linux box. The dashboard shows the SSH command.

ssh root@<server-ip>
python3 --version
apt update && apt install -y python3-venv python3-pip
pip install requests

Verify: python3 --version prints 3.10 or newer. python3 -c "import requests, sqlite3" exits without errors.

Step 2: Set API Credentials

The dashboard exposes three values: an API key, a base URL, and a model name. Export them as environment variables.

export MC_API_KEY="<from-dashboard>"
export MC_BASE_URL="<from-dashboard>"
export MC_MODEL="<from-dashboard>"
export MC_BUDGET_TOKENS="100000"

Verify: echo ${MC_API_KEY:?} ${MC_BASE_URL:?} ${MC_MODEL:?} prints all three values. No empty strings.

Step 3: Write the Ledger Agent

Create agent.py. The loop is simple: ask the model for an action, run the tool, record the decision, check the budget.

import json
import os
import sqlite3
import time

import requests

API_KEY = os.environ["MC_API_KEY"]
BASE_URL = os.environ["MC_BASE_URL"]
MODEL = os.environ["MC_MODEL"]
BUDGET = int(os.environ.get("MC_BUDGET_TOKENS", "100000"))
DB = "ledger.db"


def init_db():
    con = sqlite3.connect(DB)
    con.execute("""
        CREATE TABLE IF NOT EXISTS decisions (
            id INTEGER PRIMARY KEY,
            ts REAL,
            step INTEGER,
            action TEXT,
            tool_input TEXT,
            tokens_in INTEGER,
            tokens_out INTEGER,
            total_used INTEGER
        )
    """)
    con.commit()
    return con


def call_llm(messages):
    # Adapt auth and payload to the endpoint contract in the project docs.
    resp = requests.post(
        f"{BASE_URL}/chat/completions",
        headers={"Authorization": f"Bearer {API_KEY}"},
        json={"model": MODEL, "messages": messages},
        timeout=60,
    )
    resp.raise_for_status()
    data = resp.json()
    usage = data.get("usage", {})
    tokens_in = usage.get("prompt_tokens", 0)
    tokens_out = usage.get("completion_tokens", 0)
    return data["choices"][0]["message"], tokens_in, tokens_out


def search_tool(query):
    # Replace with a real tool. Returns a canned result.
    return f"results for {query}: 3 items, none critical"


def main():
    con = init_db()
    used = 0
    step = 0
    messages = [
        {"role": "system", "content": (
            "You are a cautious operator. Return JSON only: "
            '{"action": "search" | "stop", "query": "..."}'
        )}
    ]
    while used < BUDGET:
        step += 1
        msg, tokens_in, tokens_out = call_llm(messages)
        used += tokens_in + tokens_out
        try:
            action = json.loads(msg["content"])
        except json.JSONDecodeError:
            break
        query = action.get("query", "")
        if action.get("action") == "stop":
            con.execute(
                "INSERT INTO decisions VALUES (?,?,?,?,?,?,?,?)",
                (None, time.time(), step, "stop", query,
                 tokens_in, tokens_out, used),
            )
            con.commit()
            break
        result = search_tool(query)
        messages.append({"role": "assistant", "content": msg["content"]})
        messages.append({"role": "tool", "content": result})
        con.execute(
            "INSERT INTO decisions VALUES (?,?,?,?,?,?,?,?)",
            (None, time.time(), step, action.get("action"), query,
             tokens_in, tokens_out, used),
        )
        con.commit()
        print(f"step={step} used={used} action={action.get('action')}")
    con.close()
    print(f"final_used={used}")


if __name__ == "__main__":
    main()

Verify: python3 agent.py prints increasing used values. The script stops when the model returns "action": "stop".

Step 4: Enforce the Hard Budget

The while used < BUDGET condition is the enforcement point. When the budget is exhausted, the loop exits. No tool call runs after that.

Test it with a tiny budget:

MC_BUDGET_TOKENS=500 python3 agent.py

Verify: final_used is less than or equal to 500. The script never exceeds the cap.

Step 5: Read the Decision Ledger

The ledger answers questions raw logs cannot. Query it with sqlite3:

sqlite3 ledger.db \
  "SELECT step, action, tool_input, tokens_in, tokens_out, total_used \
   FROM decisions ORDER BY step;"

Verify: every row has a monotonic total_used. The final row matches final_used from the script output.

Why This Pattern Works

A hard budget is a constraint, not a punishment. It forces the agent to stop and reconsider. The ledger makes the reasoning visible after the fact.

The ledger is written before the next step runs. That makes it enforcement, not forensics. Two failure modes disappear:

Looping: repeated tool calls with the same tool_input are obvious in the query output.
Silent overruns: total_used is checked before every step, not after the damage.

Limitations

The 10M token figure is current as of this writing. Free quotas change. Re-check before you rely on them.
The ledger trusts the endpoint's usage field. If the endpoint omits it, both values default to zero. Add a character-based fallback if your API does not report usage.
This is a single-process design. No concurrency, no retries, no queue.
The tool is a stub. Replace search_tool with a real integration and add error handling.

Who Should Not Use This

Teams that need a latency SLA or guaranteed uptime. A free server has no contract.
High-throughput production workloads. The SQLite write per step becomes a bottleneck.
Sensitive data pipelines without a review of where the server and API sit.

Try It Against a Real Allowance

The fastest way to validate the budget logic is to compare it with a real allowance. The MonkeyCode dashboard shows your remaining tokens. Run the script, then compare the ledger total with the dashboard number. If they disagree, your endpoint's usage reporting is the first suspect.

MonkeyCode provides free models that can run this workflow.

When the Token Well Runs Dry: A Degradation State Machine for LLM Services

Riley Wang — Fri, 04 Sep 2026 11:06:12 +0000

The alert fires at 3:14 AM. Your LLM service returns 500s. The free quota is gone. You check the dashboard. 10,000,000 tokens. Zero remaining.

Most guides teach prevention. Budgets. Ledgers. Pre-checks. This one teaches survival. What happens after the quota dies? The answer determines if your users stay.

I built a degradation state machine. It turns quota exhaustion into a designed state. Not a crash. This article shows the full implementation.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

The four states

Free tiers end. That is a fact. Design for it.

State	Trigger	Behavior
NORMAL	Usage < 70%	Full service
WARNING	Usage >= 70%	Cache responses
DEGRADED	Usage >= 90%	Critical requests only
EXHAUSTED	Usage >= 100%	Cache or 503

The thresholds are config. Tune them for your traffic. The state machine is the core.

Step 1: Track the quota

MonkeyCode's free tier includes 10M tokens and a free server option. Quotas change. Verify the current numbers first.

The tracker polls the usage endpoint. It stores the remaining count in memory.

class QuotaTracker:
    def __init__(self, cap: int):
        self.cap = cap
        self.used = 0

    def record(self, tokens: int):
        self.used += tokens

    def ratio(self) -> float:
        return self.used / self.cap

    def state(self) -> str:
        r = self.ratio()
        if r >= 1.0:
            return "EXHAUSTED"
        if r >= 0.9:
            return "DEGRADED"
        if r >= 0.7:
            return "WARNING"
        return "NORMAL"

Simple arithmetic. Four states. No magic.

Step 2: Add the cache

The WARNING state needs a cache. Every response gets stored. Keyed by the prompt hash.

import hashlib

class ResponseCache:
    def __init__(self):
        self.store = {}

    def key(self, prompt: str) -> str:
        return hashlib.sha256(prompt.encode()).hexdigest()

    def get(self, prompt: str):
        return self.store.get(self.key(prompt))

    def put(self, prompt: str, response: str):
        self.store[self.key(prompt)] = response

The cache is a dictionary. For production, use Redis. For a free server, a dict is fine.

Step 3: Classify requests

Not all requests are equal. Some deserve the last tokens. Others can wait.

def classify_request(payload: dict) -> str:
    if payload.get("priority") == "critical":
        return "critical"
    if payload.get("task") == "classify":
        return "cheap"
    return "normal"

Critical requests keep the service alive. Cheap requests can use cached answers. Normal requests wait.

Step 4: The router with degradation

This is the heart. The router checks the state before every call.

def route(payload: dict, tracker: QuotaTracker, cache: ResponseCache):
    state = tracker.state()
    task = classify_request(payload)

    if state == "EXHAUSTED":
        cached = cache.get(payload["text"])
        if cached:
            return {"source": "cache", "label": cached}
        return {"source": "none", "error": "quota exhausted"}, 503

    if state == "DEGRADED" and task != "critical":
        cached = cache.get(payload["text"])
        if cached:
            return {"source": "cache", "label": cached}
        return {"source": "none", "error": "degraded"}, 503

    if state == "WARNING":
        cached = cache.get(payload["text"])
        if cached:
            return {"source": "cache", "label": cached}

    # live call to the model
    result = call_model(payload["text"])
    cache.put(payload["text"], result)
    tracker.record(estimate_tokens(payload["text"], result))
    return {"source": "live", "label": result}

Read the logic top to bottom. Each state adds a restriction. The service never crashes. It degrades.

Step 5: Test the degradation

A state machine needs a test. Simulate quota exhaustion. Verify each state.

def test_degradation():
    tracker = QuotaTracker(cap=1000)
    cache = ResponseCache()

    # fill the cache
    cache.put("hello", "greeting")

    # NORMAL
    assert tracker.state() == "NORMAL"

    # WARNING
    tracker.used = 700
    assert tracker.state() == "WARNING"

    # DEGRADED
    tracker.used = 900
    assert tracker.state() == "DEGRADED"

    # EXHAUSTED
    tracker.used = 1000
    assert tracker.state() == "EXHAUSTED"

    # EXHAUSTED serves from cache
    result = route({"text": "hello"}, tracker, cache)
    assert result["source"] == "cache"

    # EXHAUSTED rejects uncached
    result = route({"text": "unknown"}, tracker, cache)
    assert result[1] == 503

    print("All degradation tests passed")

Run it.

python test_degradation.py

Step 6: Deploy and monitor

The free server option hosts this. No credit card. No billing alarm.

git clone <your-repo>
cd <your-repo>
pip install -r requirements.txt
uvicorn app:app --host 0.0.0.0 --port 8000

Add a health endpoint that reports the current state.

curl http://localhost:8000/state
# {"state": "NORMAL", "ratio": 0.42}

A simple curl tells you the truth. No dashboard needed.

What the cache cannot save

Caching has limits. Unique prompts miss. Long conversations miss. Time-sensitive answers miss.

The cache hit rate determines your survival time. Measure it.

hits = sum(1 for r in results if r["source"] == "cache")
print(f"Hit rate: {hits / len(results):.0%}")

A 40% hit rate extends the service by days. A 5% hit rate barely helps.

Who should not use this

Teams with SLAs need paid capacity. Teams with real-time requirements need dedicated endpoints. Teams with high concurrency need more than a free server.

This pattern is for prototypes. For internal tools. For services where a 503 is acceptable. For developers who want a service that fails gracefully.

The takeaway

Quota exhaustion is a state. Design for it. The state machine turns a crash into a graceful degradation. Cache what you can. Protect what matters. Fail loudly when you must.

If you want to experiment with this pattern, MonkeyCode's free tier is a place to start. Check the current quota first. Then build something that survives the month.

MonkeyCode provides free models that can run this workflow.

How I Built a Self-Auditing Agent Loop on a Free Server

Riley Wang — Fri, 04 Sep 2026 10:00:10 +0000

I needed a way to stop agents from burning tokens in silence. A self-auditing loop with a JSONL ledger, a hard token budget, and a verification command after every stage is enough to make every decision explainable—and it runs on a free Linux server.

An agent makes a bad call. It burns 40,000 tokens before anyone notices. The worst part is that nobody can explain why. A log file is not a ledger. I wanted an append-only paper trail that counts every token, records every decision, and fails safely when the budget is gone. This is the loop I actually run: no tools, no retries, no vector store. Just a model, a task, and an audit record.

Disclosure: This article was prepared as part of MonkeyCode's product outreach. The free tier includes 10 million tokens for experiments. That covers hundreds of small agent runs.

What I am building and why a ledger beats a log

I split the agent into three parts:

A reasoning ledger stored as JSON Lines (JSONL).
A token budget guard that stops the loop before it overshoots.
A verification command for every stage, so I never assume a step worked.

A typical log file mixes stdout, stack traces, and model chatter. JSONL is append-only, crash-safe, and greppable. Each line is one decision. I can stream it, count it with jq, and reconstruct the prompt context without a database. For a single-process experiment, a database is overkill.

Compared with a full agent framework, this loop is intentionally dumb. Frameworks hide retries, tool calls, and parallel branches. That is useful in production and opaque when I am trying to learn where tokens leak. I want the opposite: one call, one record, one budget check.

What I need:

A small Linux server. Any free tier works.
Python 3.10 or newer.
The openai Python package, which talks to any OpenAI-compatible Chat Completions endpoint.
A MonkeyCode account for free model access and a free server option.

Provision the server and configure model access

I log in and install only the basics.

ssh user@your-server
sudo apt update && sudo apt install -y python3 python3-venv git
mkdir -p ~/agent && cd ~/agent
python3 -m venv venv
source venv/bin/activate
pip install openai

Then I verify the stage instead of hoping it worked.

python3 --version
pip show openai | head -2

I expect Python 3.10+ and a printed package version. If either command fails, I stop. Skipping verification is how silent failures start.

MonkeyCode gives me three values: a base URL, an API key, and a model name. I export them as environment variables so the code never hard-codes secrets.

export LLM_BASE_URL="$MONKEYCODE_BASE_URL"
export LLM_API_KEY="$MONKEYCODE_API_KEY"
export LLM_MODEL="$MONKEYCODE_MODEL"

Verification for this stage:

env | grep LLM_

All three variables must appear. I keep the key out of shell history. A .env file or the server's secret store is safer than pasting the key into a profile.

Write the loop, the JSONL ledger, and the token budget guard

I create agent.py. The loop calls the model, logs the reply and usage, and repeats until the model writes [DONE] or I hit a step cap.

import json
import os
from openai import OpenAI

client = OpenAI(
    base_url=os.getenv("LLM_BASE_URL"),
    api_key=os.getenv("LLM_API_KEY"),
)

LEDGER = "ledger.jsonl"

def log_decision(entry):
    with open(LEDGER, "a") as f:
        f.write(json.dumps(entry) + "\n")

def call_model(messages, max_tokens=512):
    return client.chat.completions.create(
        model=os.getenv("LLM_MODEL"),
        messages=messages,
        max_tokens=max_tokens,
    )

def run_task(task, steps=5):
    messages = [{
        "role": "system",
        "content": "Before every action, state your reasoning in one line. End with [DONE] when finished."
    }]
    messages.append({"role": "user", "content": task})
    for i in range(steps):
        resp = call_model(messages)
        reply = resp.choices[0].message.content
        usage = resp.usage
        log_decision({
            "step": i,
            "prompt_tokens": usage.prompt_tokens,
            "completion_tokens": usage.completion_tokens,
            "total_tokens": usage.total_tokens,
            "decision": reply[:200],
        })
        messages.append({"role": "assistant", "content": reply})
        if "[DONE]" in reply:
            break
    return messages

if __name__ == "__main__":
    import sys
    task = sys.argv[1] if len(sys.argv) > 1 else "Say hello and stop."
    run_task(task)

Why JSONL? It is append-only. It survives crashes. I can grep it. I can stream it. Each record stores prompt_tokens, completion_tokens, total_tokens, and a truncated decision so I can audit without dumping the entire transcript into one giant file. A line looks like this:

{"step": 0, "prompt_tokens": 48, "completion_tokens": 91, "total_tokens": 139, "decision": "I will list three review risks in one pass, then stop."}

I cap max_tokens at 512 per call so a single rambling reply cannot recreate that 40,000-token burn. If [DONE] never appears, the steps=5 cap still ends the loop.

Add the token budget guard

Agents overshoot. A guard stops them. I add a budget check before every call.

BUDGET = int(os.getenv("TOKEN_BUDGET", "10000"))

def spent_tokens():
    total = 0
    if os.path.exists(LEDGER):
        for line in open(LEDGER):
            total += json.loads(line)["total_tokens"]
    return total

def within_budget():
    return spent_tokens() < BUDGET

I call within_budget() at the top of the loop.

for i in range(steps):
    if not within_budget():
        log_decision({"step": i, "error": "budget_exceeded", "total_tokens": 0})
        break
    resp = call_model(messages)

Now the agent fails safely. It records the reason. It stops spending. That is the difference between a log that says "process died" and a ledger that says budget_exceeded at step 3. The default budget of 10,000 tokens is well under the silent 40,000-token failure that started this experiment.

Run the loop and verify token accounting

I run a real task, not a toy hello.

python agent.py "List three risks in this code review and stop with [DONE]"

Then I verify the ledger exists.

cat ledger.jsonl | wc -l

I expect at least two lines—one per model call. If I see zero, the process never wrote a decision and I debug before I raise the budget.

Token accounting is a separate stage. I check totals, the most expensive step, and the reasoning trail.

cat ledger.jsonl | jq -r '.total_tokens' | awk '{s+=$1} END {print "total tokens:", s}'
cat ledger.jsonl | jq -s 'max_by(.total_tokens) | {step, total_tokens}'
cat ledger.jsonl | jq -r '.decision'

Each line shows what the agent decided. Each line shows what it cost. If one step dominates the total, that is where I tighten max_tokens or the system prompt.

Verification checklist I actually use:

Stage	Command	Expected result
Server	`python3 --version`	3.10+
Config	`env \	grep LLM_`
Loop	`python agent.py "..."`	`ledger.jsonl` created
Tokens	`cat ledger.jsonl \	wc -l`

The ledger then answers four questions a log file usually cannot:

Which step consumed the most tokens.
Whether the agent looped or stopped with [DONE].
Whether the budget guard fired.
The exact decision snippet at each step.

That turns a black box into an auditable record.

Limitations, who should skip this, and what I do next

The loop is single-process. No retries. No tool calls. No parallel branches. The ledger is local and does not sync across machines. Free tiers change, so I verify current quotas before I depend on them. I do not run this with sensitive data: the ledger stores raw model replies.

I would not use this if I needed multi-agent orchestration, if the project handled PII or regulated data, or if I already had a full agent framework. Those teams should use a real framework. I use this loop for learning and small experiments.

Start with one task. Watch the ledger. Raise the budget and see where tokens leak. MonkeyCode's free tier covers the first 10 million tokens. The free server runs this loop all day. That is enough to learn agent economics without a credit card.

Clone these files onto a free server tonight, run one task, and read ledger.jsonl before you add tools or retries. If you cannot explain a step from the ledger, the loop is not self-auditing yet—fix the record, not the model.