I Profiled the Agent. Rebuild Ate the Clock.

A developer built an open-source Python harness that profiles agent-loop latency by instrumenting four separate spans — serialization, tool execution, prompt rebuild, and model inference — and logging them to a CSV. Running the harness against a stubbed model revealed that quadratic prompt rebuilding, not model inference, dominated wall-clock time in later rounds, contradicting the common assumption that the language model is the bottleneck.

The language model was not my real bottleneck. Prompt rebuild ate the clock on every later round. I spent days blaming inference like a fool. Have you ever tuned the model and missed the copy? I wanted one graph I could actually keep. A zoo of dashboards would have hidden the crossing. I plotted rebuild time against a stubbed model nap. This is a lab note, not a customer war story. I did not harvest production traces for this. I wrote a harness you can run tonight. The plot is an agent loop with tools. Each tool returns a chunky JSON payload on purpose. Then the loop concatenates history into the next prompt. After that step it calls the model again. In the stub, the model is just sleep. On the wire, the model is a network hop. The span names stay identical either way though. Why named spans and not a single timer? Averages already lied to me enough last month. I wanted stackable intervals with very boring names. I clocked serialize, tool, rebuild, and model separately. They all land in one boring CSV file. The CSV is the graph I kept. Here is the core of that harness. bash /usr/bin/env python3 """Agent-loop span profiler. Stub model. Rebuild grows.""" from future import annotations import csv import json import os import time from dataclasses import dataclass @dataclass class RoundRow: n: int serialize ms: float tool ms: float rebuild ms: float model ms: float prompt chars: int def fake tool round n: int - tuple dict, float : t0 = time.perf counter time.sleep 0.005 5ms stand-in for a local tool payload = { "round": round n, "files": {"path": f"src/mod {i}.py", "preview": "x" 2000} for i in range 50 , "log": "ok" 400, } return payload, time.perf counter - t0 1000.0 def serialize tool result payload: dict - tuple str, float : t0 = time.perf counter text = json.dumps payload, separators= ",", ":" return text, time.perf counter - t0 1000.0 def rebuild prompt history: list str , tool text: str - tuple str, float : t0 = time.perf counter history.append "TOOL:" + tool text prompt = "" Quadratic on purpose: a join people actually write. for i in range len history : prompt = "\n".join history : i + 1 return prompt, time.perf counter - t0 1000.0 def stub model prompt: str - tuple str, float : t0 = time.perf counter time.sleep 0.040 ruler, not a model benchmark = len prompt return "call tool", time.perf counter - t0 1000.0 def run loop rounds: int, model fn - list RoundRow : history = "SYS:you are a coding agent", "USER:find the leak" rows: list RoundRow = for n in range 1, rounds + 1 : payload, tool ms = fake tool n tool text, ser ms = serialize tool result payload prompt, rebuild ms = rebuild prompt history, tool text , model ms = model fn prompt rows.append RoundRow n, ser ms, tool ms, rebuild ms, model ms, len prompt return rows def write csv path: str, rows: list RoundRow - None: with open path, "w", newline="" as f: w = csv.writer f w.writerow "round", "serialize ms", "tool ms", "rebuild ms", "model ms", "prompt chars" for r in rows: w.writerow r.n, f"{r.serialize ms:.3f}", f"{r.tool ms:.3f}", f"{r.rebuild ms:.3f}", f"{r.model ms:.3f}", r.prompt chars, def ascii graph rows: list RoundRow - str: lines = "round rebuild model.", "----- -------- ------" for r in rows: rb = max 1, int round r.rebuild ms md = max 1, int round r.model ms / 2 lines.append f"{r.n:5d} {' ' rb} {'.' md}" return "\n".join lines I run the stub path with a plain command. Nothing fancy. No extra flags. python agent spans.py Wire main to run loop 12, stub model and write agent spans.csv . The stub sleeps for forty milliseconds each round. That sleep is a ruler, not a benchmark. Please do not quote it as model speed. What should you watch on a quiet machine? Rebuild starts tiny, almost like a rounding error. Then the tool payload lands and history snowballs. By later rounds the copy work gets rude. The snowball is the whole point here. If rebuild crosses that forty millisecond ruler, keep the graph. That crossing is the only picture I kept. Everything else was noise I threw away. I also wrap the same loop with cProfile. Spans tell a timeline, and functions tell a culprit. json.dumps often walks into the spotlight first here. php import cProfile import io import pstats def profile loop - None: pr = cProfile.Profile pr.enable run loop 12, stub model pr.disable buf = io.StringIO stats = pstats.Stats pr, stream=buf stats.sort stats "cumulative" .print stats 15 print buf.getvalue Did you expect the model function to win? I did. It lost on the stub path. That embarrassment is why I kept the picture. Export pstats if you want a flame-style view. A wide plateau sits under rebuild prompt on stub runs. The stub model bar stays thin and honest. I still prefer the stacked CSV over a flame. It pastes into notes without a graphics stack. The insult survives the copy-paste just fine. Sample stub output will look locally noisy. Treat the shape as the lesson, not the digits. round rebuild model. ----- -------- ------ 1 .................... 4 .................... 8 .................... 12 .................... Your bars will move. That is expected. Pin the payload size if you need a fair fight. Inflate the tool payload until the bars actually fight. Now comes the remote path with the same four spans. The model function POSTs the prompt over HTTP. I do not wrap a vendor SDK in this note. I pointed this harness at MonkeyCode because free model access and a free server option let the loop leave my laptop without a GPU box. Disclosure: This article was prepared as part of MonkeyCode's product outreach. I am not publishing their latency, model names, or quotas. I am not calling this a product benchmark either. Point the client at any URL you actually control. php import urllib.request def remote model prompt: str - tuple str, float : url = os.environ.get "AGENT MODEL URL", "" .strip if not url: raise SystemExit "set AGENT MODEL URL to an endpoint you control" body = json.dumps {"prompt": prompt} .encode "utf-8" req = urllib.request.Request url, data=body, method="POST" req.add header "Content-Type", "application/json" t0 = time.perf counter with urllib.request.urlopen req, timeout=30 as resp: raw = resp.read return raw.decode "utf-8", errors="replace" :200 , time.perf counter - t0 1000.0 Set AGENT MODEL URL and run the same CSV path. Compare stub bars against wire bars on your graph. Keep the picture and throw away vendor adjectives. export AGENT MODEL URL="http://127.0.0.1:8080/prompt" python -c "from agent spans import run loop, remote model, write csv, ascii graph rows = run loop 8, remote model write csv 'agent spans wire.csv', rows print ascii graph rows " Watch the first remote round with extra suspicion. TLS and DNS can steal that opening lap. Queue delay on a shared box can steal more. After warmup, rebuild may still be the growth term. Why? You resend the whole history every round. Streaming would change this story quite a bit. This harness does not stream a single token. If your real agent streams, instrument the decoder. Do not borrow my stub graph for that case. The quadratic join is a microscope, not advice. Real history should be appended, not rebuilt from prefixes. I left the slow join in so the graph has teeth. Swap it for a single "\n".join history after you see the crossing. Then run the CSV again on the same machine. Did the rebuild bar collapse like a cheap tent? If it did, you just caught the copy. If it did not, stare at json.dumps next. Huge tool payloads serialize like wet cement. This method will not find GPU kernel stalls. It will not find tokenizer weirdness on its own. cProfile also perturbs the thing you measure. Laptop clocks are noisy and fans make them worse. Run it thrice before you believe a crossing. Pin CPU frequency if you are being precious. A free shared server adds queue time you cannot see. Without server-side traces you must not blame the model. You can only blame the round trip you measured. Skip this if you already have tracing in the agent. Skip this if you need legal vendor comparisons. Skip this if your bottleneck is inside CUDA. I would also skip it for tiny prompts. A twenty token chat will not show rebuild. Inflate the tool payload until the bars fight. That inflation is a lab trick, not production. Real tools should return less, not more. The harness is a microscope, not a product. Clone the idea, not my sleep constant. Change the payload. Change the join. Keep one graph. When rebuild crosses your ruler, you have a bug. Fix the copy. Then go bother inference again.