# I Profiled the Agent. Rebuild Ate the Clock.

> Source: <https://dev.to/apppro_4800/i-profiled-the-agent-rebuild-ate-the-clock-4e0>
> Published: 2026-09-23 16:52:41+00:00

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.
