48-Hour Field Notes: The Model Was Fast — My Connection Setup Was the Queue

Background: a worker I could not profile

I had a batch job that pushed a few hundred short prompts at a model endpoint and wrote every answer to disk as it arrived. It ran on a free server box, it used a free model tier, and it felt slow in the vaguest possible way. My first instinct was to blame the model, because "the model is slow" is a story I can tell without opening a profiler. That instinct survived almost two full days, and what finally killed it was a twenty-line timing script.

Ask yourself a blunt question: when your job is slow, which phase are you actually naming? If the answer is "the call", you have not named anything yet.

The measurement I should have run on hour zero

Every HTTPS request is at least five phases pretending to be one. Collapse them and the only part you control disappears.

1. dns — resolving the hostname, which may hit a resolver cache or miss it entirely.
2. tcp — the socket connect, which is where a shared box's CPU quota shows up first.
3. tls — the handshake, which costs a round trip or two before any HTTP exists.
4. ttfb — from request bytes sent to the first response byte, the closest thing you have to "model time".
5. body — reading the response, which is buffering behaviour more than compute.

Here is the harness I ended up keeping. It is stdlib only, so it runs on a free box without a dependency install.

#!/usr/bin/env python3
# phase_timer.py - split one HTTPS call into dns / tcp / tls / ttfb / body
import json, socket, ssl, sys, time
from urllib.parse import urlsplit


def now_ms():
    return time.perf_counter() * 1000.0


def timed_call(url, headers=None, timeout=10.0):
    u = urlsplit(url)
    host, port = u.hostname, u.port or 443
    path = u.path or "/"
    row = {"url": url}

    t = now_ms()
    infos = socket.getaddrinfo(host, port, type=socket.SOCK_STREAM)
    row["dns_ms"] = now_ms() - t

    family, socktype, proto, _, addr = infos[0]
    t = now_ms()
    sock = socket.socket(family, socktype, proto)
    sock.settimeout(timeout)
    sock.connect(addr)
    row["tcp_ms"] = now_ms() - t

    t = now_ms()
    ctx = ssl.create_default_context()
    tls = ctx.wrap_socket(sock, server_hostname=host)
    row["tls_ms"] = now_ms() - t

    req = f"GET {path} HTTP/1.1\r\nHost: {host}\r\nConnection: close\r\n\r\n"
    t = now_ms()
    tls.sendall(req.encode())
    first = tls.recv(1)
    row["ttfb_ms"] = now_ms() - t

    t = now_ms()
    chunks, total = [first], len(first)
    while True:
        b = tls.recv(65536)
        if not b:
            break
        chunks.append(b)
        total += len(b)
    row["body_ms"] = now_ms() - t
    row["bytes"] = total
    tls.close()
    return row


if __name__ == "__main__":
    url, runs, out = sys.argv[1], int(sys.argv[2]), sys.argv[3]
    with open(out, "a", encoding="utf-8") as fh:
        for _ in range(runs):
            fh.write(json.dumps(timed_call(url)) + "\n")
            fh.flush()

Run it cold first, one fresh connection per call, and keep the file:

python3 phase_timer.py "https://your-endpoint.example/v1/models" 200 phases_cold.jsonl

Then run it again with one connection reused per worker and diff the two files. The gap between phases_cold.jsonl and phases_warm.jsonl is the entire article, and it is reproducible on your own box in under an hour.

What broke, in order of embarrassment

1. I opened a new connection for every single prompt

Each call paid the full handshake tax before a single token of work happened. On a shared free box with a small CPU quota, that tax is not a constant — it moves with whatever else is running on the host. So my "model latency" was partly a measurement of my neighbours, which is exactly the kind of number that makes you tune the wrong knob for two days.

2. My retry wrapper rebuilt the socket and called itself resilient

The slowest calls in the run were not the first attempts, they were the retries, because each retry re-ran dns, tcp and tls before it re-sent anything. A retry that reconnects is correct when the failure was in the connection, and wasteful when the failure was a stall on a socket that was already healthy. Does your retry know the difference? Mine did not, and it was hiding in a decorator I had stopped reading.

3. My timings had totals but no phase labels

I could prove the run was long, and I could not prove which part was long, so every hypothesis sounded equally plausible. A wall-clock total is a feeling with a decimal point. The fix was not more logging, it was logging the right five numbers per attempt.

Phase-attributed retries, which is the part worth copying

Once each attempt carries a phase, the retry policy writes itself. Pre-request failures mean nothing was sent, so retrying costs you almost nothing. Post-first-byte failures mean the provider already did the work, so a blind re-send can duplicate it.

RETRYABLE = {"dns", "tcp", "tls", "ttfb"}
CONNECTION_PHASES = {"dns", "tcp", "tls"}


def should_retry(phase, attempt):
    if phase not in RETRYABLE:
        return False
    if phase in CONNECTION_PHASES:
        return attempt < 2          # reconnect, then give up quietly
    return attempt < 4              # provider-side stall: back off, then stop

Two consequences fell out of that table immediately. Connection failures stopped being reported as model failures, and my fallback path stopped firing on problems the fallback could not fix. If you only change one thing after reading this, make it that: tag the phase, then let policy depend on it.

A decision table I keep next to the harness

What the JSONL shows	Most likely cause	What I change
tcp_ms + tls_ms comparable to ttfb_ms	new socket per call	one connection per worker, keep-alive on
dns_ms spikes with no pattern	resolver misses on a restarting box	resolve once per process, reuse the address
ttfb_ms p90 much larger than p50, body flat	provider-side queueing	cap concurrency, do not add workers
body_ms grows with payload, ttfb flat	response buffering	read incrementally, time the first chunk
every phase flat but run long	your own code between calls	profile the loop, not the network

Where MonkeyCode actually fit

I used MonkeyCode's free model access to run the calibration passes, since a few hundred throwaway calls per iteration is exactly what you do not want to pay for while you are still guessing. The free server option hosted the harness next to the worker, so the numbers came from the same box that ran the job instead of from my laptop. Disclosure: This article was prepared as part of MonkeyCode's product outreach. The free tier is also shared and noisy, which is precisely why the harness matters: do not trust my shapes, measure yours.

Limitations, and who should skip this

• One box, one region, one endpoint. This workflow does not tell you anything about multi-region routing or provider-side rate limits.
• Small samples are noise. Under roughly fifty calls, p90 is a rumour, so run for a full day before drawing a conclusion.
• A harness that reuses a socket will not show you TLS session resumption, connection pooling internals, or HTTP/2 behaviour.
• If you have a hard latency SLO and a paid provider with a status page, this is the wrong tool; go read their numbers instead of generating your own.
• If your calls are long-lived streams where the first byte is the only byte that matters, skip the body phase and stop here.

What I would repeat at hour 48

1. Hours 0–2: run the cold harness, save the JSONL, and compute the share of each phase before forming any opinion.
2. Hours 2–6: flip to one connection per worker, re-run the identical command, and diff the two files.
3. Hours 6–24: run the real job with phase-tagged attempts, and log the phase on every failure, not just the message.
4. Hours 24–48: change one variable per run, then re-read the p90 instead of the average, because the tail is what misses deadlines.

If you run the harness yourself, keep the JSONL and diff it after each change. That file, not my conclusions, is the artifact worth comparing with someone else's box.