The Bottleneck Lived Between Tool Calls

The bottleneck lived between the tool calls, not inside them. I almost blamed the model for a slow agent loop.

Does that surprise you after a week of agent hype? It should not, if you have ever read a flamegraph.

Agents look smart because they chain tools with confidence. Your wall clock still pays for every serial round trip. I wanted a note I could rerun on Monday morning.

So I wrote a fake agent that anyone can profile locally. This lab has no production traffic and no secret sauce. It uses sleeps and JSON so you can reproduce the graph.

Think of the loop like a subway map with one track. The trains move fast, yet every station serializes passengers.

Why do we keep timing the locomotive in these reviews? Because the model is the shiny part of the story.

A lab, not a war story

I built a worker that mimics a coding agent with tools. It searches a tree, reads two files, then writes a summary. The sleeps stand in for HTTP, and JSON stands in for payloads.

Please do not treat these numbers as a vendor benchmark. They exist so the graph stays reproducible on a laptop.

# agent_loop.py — lab only, labeled as a simulation
import json, time
from dataclasses import dataclass, field

@dataclass
class Timeline:
    events: list = field(default_factory=list)
    def mark(self, name, start, end):
        self.events.append((name, start, end, end - start))

TL = Timeline()

def fake_http(name, payload, delay):
    t0 = time.perf_counter()
    time.sleep(delay)  # stand-in for network + server
    blob = json.dumps(payload)
    _ = json.loads(blob)
    t1 = time.perf_counter()
    TL.mark(name, t0, t1)
    return blob

def tool_search(query):
    hits = [{"path": f"src/{i}.py", "score": 1.0 - i / 50} for i in range(40)]
    return fake_http("search", {"q": query, "hits": hits}, 0.25)

def tool_read(path):
    body = {"path": path, "text": ("def f():\n    pass\n" * 80)}
    return fake_http("read:" + path, body, 0.18)

def tool_write_summary(notes):
    body = {"summary": notes, "tokens_est": len(notes)}
    return fake_http("write", body, 0.12)

def agent_brain(query):
    # The cheap "smart" part. Labeled as a stub, not a model.
    plan = {"query": query, "reads": 2}
    return json.dumps(plan)

def run_serial(query):
    plan = agent_brain(query)
    search = tool_search(query)
    hits = json.loads(search)["hits"]
    a = tool_read(hits[0]["path"])
    b = tool_read(hits[1]["path"])
    notes = a[:200] + b[:200] + plan
    return tool_write_summary(notes)

if __name__ == "__main__":
    t0 = time.perf_counter()
    run_serial("find slow parser")
    print(f"wall_s={time.perf_counter() - t0:.3f}")
    for name, s, e, d in TL.events:
        print(f"{s:.3f} {e:.3f} {d:.3f} {name}")

Each fake tool sleeps, then returns a fat JSON payload. That payload is the junk food of agent architectures today. It looks pretty in logs and still costs you on every hop.

Profile the stations

I start with cProfile because it already ships with Python. There are no extra agents and no extra dashboards here.

python -m cProfile -o serial.pstats agent_loop.py
python - <<'PY'
import pstats
p = pstats.Stats("serial.pstats")
p.sort_stats("cumtime").print_stats(15)
PY

Want a live flamegraph instead of a cumulative time table? Install py-spy and record the same script without guessing.

pip install py-spy
py-spy record -o serial.svg -- python agent_loop.py

What did I expect to see at the top of that report? Model inference, right, because that is the story we repeat.

The report disagreed, and it was not even slightly close. time.sleep sat in for network, while json.dumps sat in for encoding. The agent_brain function was basically a rounding error.

Have you ever watched a PR bot retry a search three times? That graph is this lab, just wearing a nicer jacket. The model did not melt while the loop waited in line.

I print the timeline because a pstats table still hides overlap. Overlap is the whole question in an agent worker like this.

One experiment, one graph

I changed one thing and batched the independent tool calls. Search still goes first because the later reads need paths. Those two reads do not need a polite little conversation.

They can leave the station together as one packed train. That schedule change is the whole patch, not a new model.

# batch_loop.py — same lab, different schedule
import json, time
from concurrent.futures import ThreadPoolExecutor
from agent_loop import agent_brain, tool_search, tool_read, tool_write_summary, TL

def run_batched(query):
    plan = agent_brain(query)
    search = tool_search(query)
    hits = json.loads(search)["hits"]
    paths = [hits[0]["path"], hits[1]["path"]]
    with ThreadPoolExecutor(max_workers=2) as pool:
        blobs = list(pool.map(tool_read, paths))
    notes = blobs[0][:200] + blobs[1][:200] + plan
    return tool_write_summary(notes)

if __name__ == "__main__":
    t0 = time.perf_counter()
    run_batched("find slow parser")
    print(f"wall_s={time.perf_counter() - t0:.3f}")
    for name, s, e, d in TL.events:
        print(f"{s:.3f} {e:.3f} {d:.3f} {name}")

I kept both scripts and ran them with the same profiler. The batched run dropped one of the two serial read sleeps. That number comes from sleeps I wrote, not a vendor bench.

Your production numbers will differ, so steal the method anyway. I added a tiny assertion so the lab cannot silently regress.

# test_lab_schedule.py — schedule test, not a production benchmark
import time
from agent_loop import run_serial
from batch_loop import run_batched

def wall(fn):
    t0 = time.perf_counter()
    fn("find slow parser")
    return time.perf_counter() - t0

if __name__ == "__main__":
    serial = wall(run_serial)
    batched = wall(run_batched)
    print(f"serial={serial:.3f} batched={batched:.3f}")
    assert batched < serial * 0.85, "batching should drop one fake read wait"

Is that a real performance test for production traffic patterns? No, it is a schedule test with honest fake waits. It fails when someone serializes those two reads again.

The graph I kept

I did not keep a screenshot of a public model leaderboard. I kept a call timeline the next patch could not delete.

The drawing looks ugly, honest, and stubborn after rebase. That is exactly why I still keep it beside the PR.

# graph.py — ASCII Gantt from the lab timeline
def draw(events, width=56):
    if not events:
        print("empty timeline")
        return
    t0 = min(s for _, s, e, d in events)
    t1 = max(e for _, s, e, d in events)
    span = max(t1 - t0, 1e-6)
    print(f"t0={t0:.3f} t1={t1:.3f} span={span:.3f}s")
    for name, s, e, d in events:
        a = int((s - t0) / span * width)
        b = max(a + 1, int((e - t0) / span * width))
        bar = " " * a + "#" * (b - a)
        print(f"{name:16} |{bar}| {d:.3f}s")

# Paste events printed by agent_loop.py or batch_loop.py, then call draw(events).

The picture is simple on purpose, and that is the point. Bars show wait, while gaps show me sitting on my hands. If a patch cannot explain those gaps, I simply reject it.

A speedup comment in a commit message is not an artifact. A timeline that still matches after rebase is an artifact. I tape that output next to the PR before asking for review.

Would I merge a patch that only cites a chatbot complexity claim? Not after this lab, because the graph is cheaper than argument.

Where a free model still helps

I still use a model to propose the batching patch itself. I just refuse to let that proposal skip the profiler.

Disclosure: This article was prepared as part of MonkeyCode's product outreach. I ran the proposal step against MonkeyCode's free model access. The free server option hosted the two scripts during timeline compares.

The product did not replace the flamegraph on my machine. It just lowered the cost of trying another schedule.

Ask the model for a schedule change, not a speedup slogan. Then make it draw the new timeline against the old one. If it cannot do that, you already have your answer.

What this method cannot do

This method lies if your tools are not actually independent. Batching a write with a later read is a consistency bug. Profiling with sleep also lies about real tail latency.

DNS, TLS, and rate limits will rearrange those honest bars. You still need a trace from the real client much later. Thread pools also lie when the GIL fights your Python.

The lab uses IO-bound sleeps, so threads actually help here. CPU-bound JSON on huge trees may not overlap at all. Measure that case and do not believe the subway analogy blindly.

I also will not pretend free inference is a capacity plan. A lab server is not an SLO, so treat it like scratch paper.

Who should skip this whole ritual for their current work? Folks shipping a one-shot script with no tool loop should skip it. Folks with a known database query as the bottleneck should skip it.

Folks who cannot run even a local profiler should skip it. Do not add an agent so you have something cute to profile. That is how you get a slower system with a nicer story.

Re-run the two files whenever an agent optimizes your worker. Keep the timeline artifact next to the patch, not in chat.

If the bars do not move, the story does not ship. Steal the scripts, run the profiler, and keep the ugly timeline.