I Timed Inference. Packing Won.

The p99 never lived inside the model call. It hid in packing, retries, and leftover tool JSON.

I learned that the hard way this week. A flamegraph made the runtime look busy and guilty.

So I kept a waterfall instead of another CPU profile. That graph finally named the stall for me.

I profiled the wrong clock

I thought the agent was compute bound on every turn. Python was chewing JSON, so I assumed CPU.

Have you ever optimized a hot function off the wall clock? I did that twice before I drew a waterfall.

cProfile and py-spy both fell in love with json.dumps. Neither graph knew about the network wait sitting there.

The process was idle for most of the recorded turn. The packer still added real seconds before the request left.

I even sampled during a slow demo for a teammate. The cores looked bored. The user still waited.

Wall clock and CPU time are different instruments. Mixing them is how a packer stays invisible.

What a turn actually costs

One agent turn is not one model call. It is a short pipeline with a few hidden queues.

I split the turn into named spans I could time. Those spans were packing, connect, first token, stream, parse, and validate.

Then I logged payload bytes beside each timed span. Bytes explain stalls that CPU samples cannot see.

Here is the sketch I actually ran locally. Treat the printed numbers as a method, not a benchmark.

# turn_waterfall.py
# Proposal: local instrumentation for one agent turn.
# Printed timings are illustrative. They are not product claims.

import json
import time
from dataclasses import dataclass, asdict

@dataclass
class Span:
    name: str
    ms: float
    bytes_in: int = 0
    bytes_out: int = 0

class Waterfall:
    def __init__(self):
        self.spans = []
        self._t0 = time.perf_counter()

    def mark(self, name, bytes_in=0, bytes_out=0):
        now = time.perf_counter()
        self.spans.append(Span(
            name=name,
            ms=(now - self._t0) * 1000.0,
            bytes_in=bytes_in,
            bytes_out=bytes_out,
        ))
        self._t0 = now

    def dump(self, path="waterfall.json"):
        payload = [asdict(s) for s in self.spans]
        with open(path, "w", encoding="utf-8") as handle:
            json.dump(payload, handle, indent=2)
        return payload

def pack_messages(history, tool_results):
    packed = {
        "messages": history + tool_results,
        "tools": ["search", "read_file", "run_tests"],
    }
    raw = json.dumps(packed)
    return packed, len(raw.encode("utf-8"))

def clip_tool_result(result, limit=2000):
    text = result if isinstance(result, str) else json.dumps(result)
    if len(text) <= limit:
        return text
    return text[:limit] + "\n...[clipped]"

def replay_turn(history, tool_results, clip=False):
    wf = Waterfall()
    src_history = history[-6:] if clip else history
    src_tools = (
        [clip_tool_result(item) for item in tool_results]
        if clip else tool_results
    )
    packed, nbytes = pack_messages(src_history, src_tools)
    wf.mark("pack_history", bytes_out=nbytes)
    wf.mark("pack_tools", bytes_out=sum(len(json.dumps(t)) for t in src_tools))
    # Proposal: put your real client under these marks.
    wf.mark("connect")
    wf.mark("ttft")
    wf.mark("stream", bytes_in=0, bytes_out=0)
    wf.mark("parse")
    wf.mark("validate")
    return packed, wf

That file is the whole argument in code. Name every span and keep the bytes beside it.

The experiment I actually ran

I replayed one failing user task twenty times. Same prompt, same tools, and the same machine.

I did not chase a speedup number for a chart. I chased a stable shape on the waterfall instead.

First run packed the full chat plus raw tool dumps. Search hits arrived as pretty JSON with heavy wrappers.

Second run packed a clipped history and shrunk tool results. I kept identifiers and I dropped the extra prose.

Third run reused one warm connection on purpose. It also refused to retry after a valid parse.

I logged each replay with a boring command line. The spans landed beside the fixture, with no dashboard.

python turn_waterfall.py --fixture failing_task.json --clip history
python turn_waterfall.py --fixture failing_task.json --clip tools
python turn_waterfall.py --fixture failing_task.json --clip both
python -m json.tool waterfall.json

Then I plotted those spans as a stacked bar. I wanted a waterfall, not another pretty flamegraph.

def print_waterfall(spans):
    total = sum(item.ms for item in spans)
    print(f"{'span':<18} {'ms':>8} {'share':>8} {'bytes':>10}")
    for item in spans:
        share = 100.0 * item.ms / total if total else 0.0
        print(
            f"{item.name:<18} {item.ms:8.1f} {share:7.1f}% {item.bytes_out:10d}"
        )
    print(f"{'total':<18} {total:8.1f}")


def test_packing_is_not_the_turn(spans):
    total = sum(item.ms for item in spans)
    packing = sum(item.ms for item in spans if item.name.startswith("pack_"))
    # Proposal: fail the fixture when packing dominates wall clock.
    assert total > 0
    assert packing / total < 0.35, "clip history before you swap models"

The table below is an illustrative shape only. It is not a promise about any hosted model.

span                     ms    share      bytes
pack_history          412.0    18.4%     186211
pack_tools            503.0    22.4%     240088
connect                41.0     1.8%          0
ttft                  880.0    39.2%          0
stream                310.0    13.8%      15440
parse                  62.0     2.8%      15440
validate               36.0     1.6%          0
total                2244.0

Look at that bar before you swap the model. Inference is not the whole turn on this fixture.

Packing already ate a third of the wall clock. Why do we still start with model shopping then?

Because the model is the character we can name. The packer is plumbing, and plumbing skips the keynote.

Plumbing still owns p99 when history gets fat. Have you measured history bytes after the fifth tool call?

I had not. The fifth dump looked harmless in the terminal. The wire disagreed, at length, without raising its voice.

The graph I kept

I kept the waterfall as waterfall.json in the repo. I did not keep another CPU profile this time.

The CPU graph made me rewrite json.dumps with orjson. Wall clock barely moved after that clever swap.

orjson was faster on the microbenchmark, obviously. The payload was still huge on the wire though.

The remote side still had to read every extra byte. Faster dumps do not shrink a novel.

That is the analogy I cannot shake today. You do not win a traffic jam by painting the car.

You win it by sending fewer cars into the lane. Clip the history and summarize the tool output.

Then stop retrying calls that already parsed cleanly. Retries look like diligence until they clone the stall.

def should_retry(parse_ok, status_code):
    if parse_ok:
        return False
    if status_code in (408, 429, 500, 502, 503, 504):
        return True
    return False

After clipping, the pack spans shrank on my fixture. TTFT often improved too, because the prompt got smaller.

I still will not quote a multiplier here. My fixture is not your production traffic mix.

The lesson is the shape of the bar. If packing rivals TTFT, stop shopping models tonight.

Ask the rude question before you open a catalog. Are we thinking slowly, or shipping leftover JSON?

Where a free remote lane helped

I needed a remote endpoint while I iterated the packer. Paid GPU time makes you timid about extra replays.

Disclosure: This article was prepared as part of MonkeyCode's product outreach. I am stating that relationship before the product talk.

I used MonkeyCode's free model access as a scratch lane. The free server option let me replay the same fixture.

I could iterate without guarding every token like a bill. That is the only product detail I will stand on.

I am not inventing model names, quotas, or hardware here. Those claims would rot, and this note should not.

The server did not make packing magically free. It made the experiment cheap enough to repeat daily.

If you already have a local stub, use that. A stub can lie about TTFT, though, and it will.

A real remote call keeps connect, queue, and stream visible. That honesty matters more than a prettier local fake.

Want a quiet place to rerun this waterfall? Try that free lane, then keep your own spans.

What I refuse to claim

This is not a model bake-off in disguise. I did not rank providers against each other.

I did not measure a public leaderboard this week. I measured one fixture on one crowded desk.

Free shared capacity will jitter without asking you first. Overnight noise will move TTFT around a lot.

So I compare shapes inside one replay window only. I do not crown a winner from a single bar.

If your agent is tiny and stateless, packing looks cheap. Skip this note and go ship the feature then.

If you only stream tokens to a human, parse may not matter. That path can ignore half of this waterfall.

If you swore a hard latency SLO, listen closely. Do not pin that number on shared free capacity.

Use the free lane to debug packing first. Then pin a dedicated path for the number you swore.

Shared free inference is a microscope. It is a bad load balancer for a promise you printed.

Who should not listen

Do not use this workflow as a procurement score. It will mislead you the first week you try.

Do not clip tool results if you must audit full payloads. Clipping is a trade, not a free lunch.

Do not trust my illustrative table as capacity planning. Copy the spans, not the milliseconds I printed.

And do not replace tracing with hallway vibes later. If you cannot name the span, you cannot cut it.

If your bottleneck is a lock inside your own process, this graph will look dull. Go back to the flamegraph then, without shame.

What I do on the next stall

I start with bytes on the wire, not a new model. I ask one rude question before I open a catalog.

Is this turn slow because thinking is slow? Or did we ship a novel of JSON again?

Then I pack less and I retry less. I keep the waterfall next to the failing fixture.

The flamegraph can come later, after the wait is gone. It is a great liar when the process is waiting.

I will keep publishing the graphs I actually keep. Bring your own fixture if you want a fight.