48-Hour Field Notes: My "Slow" Free Endpoint Was Three Different Clocks in One Request

For two days I kept telling anyone who would listen that my endpoint was slow. Then I opened my own timing code and realized I had been measuring three unrelated things and calling the sum "latency." Is the model slow, is the queue slow, or is my client just bad at arithmetic? Those are different problems with different fixes, and I had been treating them as one.

These are field notes from a 48-hour window, not a benchmark report. I am deliberately not quoting latency numbers here, because a number measured on my connection, my prompt, and my region tells you almost nothing about yours. What I can hand over is the harness, the mistakes, and the decision table I now use before blaming anyone's infrastructure.

The question I actually had

My vague complaint was "responses feel slow," which is not a measurable statement and therefore not a debuggable one. What I actually needed to know was where the wall-clock time went between pressing enter and seeing the last character. Once I wrote that down, the request stopped looking like one event and started looking like a pipeline with several independently slow stages.

I also had a second, sneakier question: is the first request after a quiet period more expensive than the fifth? If yes, part of my "slowness" is just cold-start cost that I keep re-paying because my traffic is bursty. If no, I can stop theorizing about warm-up and go look somewhere else.

Three clocks hide inside one HTTP request

When you time a streaming call with a single stopwatch, you silently merge at least four durations that behave nothing alike:

• Connect time — DNS, TCP, TLS, and whatever a proxy does before your bytes reach an application.
• First-chunk time — admission, queueing, and prompt processing, all of which depend on how busy the shared tier is.
• Generation window — the span from first streamed chunk to last, which is the closest thing you have to "model speed."
• Chunk cadence — how evenly the stream arrives, which is often a network and buffering property rather than a model one.

If you add all four and call it latency, then a slow TLS handshake and a long generation look identical in your logs. No wonder I spent two days fixing the wrong layer.

The harness: four timestamps, no framework

I wanted something I could paste into any repo, read in one sitting, and trust. I pointed this harness at MonkeyCode's free model access running on its free server option, since that is what I had in front of me this week. Disclosure: This article was prepared as part of MonkeyCode's product outreach.

# coldstart_probe.py
# Measures connect / first-chunk / generation separately, and records idle gap.
# Requires: pip install requests
import csv, json, os, sys, time
import requests

BASE     = os.environ["BASE_URL"].rstrip("/")   # e.g. https://<your-endpoint>/v1
KEY      = os.environ["API_KEY"]
MODEL    = os.environ["MODEL"]                  # copy the exact id from your dashboard
GAP      = int(os.environ.get("GAP_SECONDS", "0"))   # sleep BEFORE every probe
REPEATS  = int(os.environ.get("REPEATS", "5"))
OUT      = os.environ.get("OUT", "probe.csv")
PROMPT   = os.environ.get("PROMPT", "Explain in one sentence what a mutex protects.")
MAXTOK   = int(os.environ.get("MAX_TOKENS", "64"))   # fixed, so windows are comparable

FIELDS = ["gap_s", "rep", "connect_s", "first_chunk_s", "last_chunk_s",
          "gen_window_s", "chunks", "status"]

def probe(rep):
    payload = {"model": MODEL, "stream": True, "max_tokens": MAXTOK,
               "messages": [{"role": "user", "content": PROMPT}]}
    t_connect = t_first = t_last = None
    chunks = 0
    t0 = time.perf_counter()                     # monotonic: immune to NTP steps
    with requests.post(f"{BASE}/chat/completions", json=payload,
                       headers={"Authorization": f"Bearer {KEY}"},
                       stream=True, timeout=120) as r:
        t_connect = time.perf_counter() - t0
        r.raise_for_status()
        for raw in r.iter_lines(decode_unicode=True):
            if not raw or not raw.startswith("data:"):
                continue
            data = raw[5:].strip()
            if data == "[DONE]":
                break
            delta = json.loads(data)["choices"][0].get("delta", {})
            if delta.get("content"):
                chunks += 1
                if t_first is None:
                    t_first = time.perf_counter() - t0
                t_last = time.perf_counter() - t0
    gen = (t_last - t_first) if (t_first is not None and t_last is not None) else -1.0
    return {"gap_s": GAP, "rep": rep,
            "connect_s": round(t_connect, 3),
            "first_chunk_s": round(t_first if t_first else -1, 3),
            "last_chunk_s": round(t_last if t_last else -1, 3),
            "gen_window_s": round(gen, 3),
            "chunks": chunks, "status": "ok"}

new_file = not os.path.exists(OUT)
with open(OUT, "a", newline="") as f:
    w = csv.DictWriter(f, fieldnames=FIELDS)
    if new_file:
        w.writeheader()
    for i in range(REPEATS):
        time.sleep(GAP)                          # idle gap lives here, not in the client
        try:
            w.writerow(probe(i))
        except requests.HTTPError as e:
            code = e.response.status_code if e.response is not None else 0
            w.writerow({"gap_s": GAP, "rep": i, "status": f"http_{code}"})
            f.flush()
            if code == 429:                      # do not retry around a rate limit
                sys.exit("429 received; stopping instead of looping")
        f.flush()

Reading it back is the part people skip, so I keep a second file that only does medians per gap bucket:

# summarize.py — median per idle gap, ignoring failed rows
import csv, statistics, collections
rows = list(csv.DictReader(open("probe.csv")))
buckets = collections.defaultdict(list)
for r in rows:
    if r.get("status") == "ok":
        buckets[int(r["gap_s"])].append(r)
for gap, rs in sorted(buckets.items()):
    med = lambda k: statistics.median(float(r[k]) for r in rs)
    print(f"gap={gap:>5}s n={len(rs):>2} connect={med('connect_s'):.3f} "
          f"first={med('first_chunk_s'):.3f} gen={med('gen_window_s'):.3f}")

The test plan, including the part I got wrong first

My first run was a single loop of twenty requests with no idle gap, which produced a tidy number and answered nothing. The plan I ended up trusting looks like this:

1. Sweep the gap, one gap per run. Run with GAP_SECONDS=0, then a few minutes of idling, then a longer gap, keeping every other input identical.
2. Freeze the prompt and max_tokens. A variable output length swamps the thing you are trying to isolate.
3. Interleave, don't sequence. Alternate buckets in time; a shared tier changes under you between an A-run at 09:00 and a B-run at 09:40.
4. Keep at least five samples per bucket before you say anything out loud, because medians of two points are folklore.
5. Log failures as rows. A timeout is data; dropping it silently is how you get a happy average built on the fast requests only.
6. Abort on 429. The harness exits on the first rate-limit response instead of hammering the tier.

What broke

1. I timed the socket, not the model

My first version opened the timer before the request and closed it after the last byte, then labelled the result "generation time." It was really connect plus admission plus generation plus teardown, which is exactly the number that makes you open a support ticket with no evidence.

2. An NTP step ate a sample

The early harness used time.time(), and one sample came back with a suspiciously smooth, almost negative duration. Wall-clock time moves; monotonic time does not, so time.perf_counter() became non-negotiable for every timestamp in the file.

3. My own health check kept the cold bucket empty

I had a keep-alive ping running in another terminal, because of course I did. Every "cold" request was therefore preceded by traffic, and the idle-gap comparison was measuring nothing at all. Ask yourself honestly whether something else in your setup is warming the thing you are trying to observe.

4. I averaged cold and warm rows into one honest-looking lie

The mean of a bucket that includes a wake-up request is dominated by that request, and it hides the steady-state cost that actually affects most of your users. Separating buckets by gap, and reporting medians inside each, fixed this in about ten minutes.

5. Chunk boundaries are not tokens

I briefly convinced myself I had a tokens-per-second figure, which I did not. Streamed chunks are transport events; batching, proxies, and buffering all reshape them, so a chunk count is a cadence signal, never a throughput measurement.

Reading the output: a small decision table

What I would repeat

Separating the clocks is the habit I am keeping, because it turns an argument into a measurement in under an hour. Interleaving the buckets instead of running them back to back also earned its place, since it survives a noisy shared tier. And writing failures into the same CSV as successes cost me almost nothing and saved me from at least one wrong conclusion.

What I would do differently

Next time I would record the response's arrival shape rather than only its timestamps, so buffering issues are visible without re-running everything. I would also pin the probe to a fixed region and note it in the file, because comparing runs from different networks is how people end up arguing about someone else's hardware. Finally, I would decide my threshold for "slow" before the run, not after, since post-hoc thresholds bend toward whatever the numbers already did.

Limitations, and who should skip this entirely

This measures one client, one path, and one prompt, so it cannot tell you what the service does under real concurrency or for other users. It also cannot see inside a queue, so "first-chunk time is high" is a symptom rather than a diagnosis. Free tiers are shared by design, which means variance is a feature of the environment; if your product needs tight latency guarantees, this harness will confirm that rather than fix it.

Skip it if you serve a handful of requests a day and have no latency target, because you will spend an afternoon producing a CSV nobody reads. Skip it too if you already have server-side tracing with spans per stage, since your numbers are better than mine. And if your only question is cost per request, this is the wrong instrument entirely.

If you want to reuse the harness, run it against whatever endpoint you already pay for first, with your own definition of "too slow" written down before the first row lands. I pointed mine at free model access on MonkeyCode's free server option because a shared tier is exactly where the three clocks disagree most, and that turned out to be the useful part of the exercise.