Break Down Scrape Latency: A Timing Harness You Can Run

What We’re Measuring

A scraping pipeline that averages 900ms per page tells you almost nothing. Is the resolver slow? Is the origin server sitting on the response? Are you paying for a TLS handshake on every single request because your client creates a new connection each time? A single total-latency number can’t answer any of those questions, and neither can most dashboards, because they aggregate before they measure.

The fix is unglamorous: instrument each request into its component stages, log one flat JSON line per fetch, and compute percentiles per stage. Then the slow stage names itself. This post builds that harness end to end in Python — plain HTTP first, then browser-rendered pages — and finishes with the percentile math and the interpretation patterns that actually lead to fixes.

Anatomy of a Scrape Request: The Six Stages You Should Be Timing Separately

Every HTTPS fetch, no matter the library, decomposes into the same sequence. Here is one request to https://example.com with plausible millisecond values:

0        18       34        95        96                 240       312   ms
|--------|--------|---------|---------|------------------|---------|
 DNS      TCP      TLS       send      server wait       download
 lookup   connect  handshake + write   (TTFB window)     body
 18ms     16ms     61ms      1ms       144ms             72ms

Read it left to right. DNS resolution turns the hostname into an IP. TCP connect is one round trip to establish the socket. TLS handshake is one to two more round trips plus crypto work, depending on whether the session is resumed. Sending the request is usually negligible. Then the big silent gap: time to first byte, which is the server thinking, queueing you behind other clients, or deliberately throttling. Finally, content download, which is pure bandwidth and payload size.

Each stage explains a different symptom, which is why collapsing them into one number wastes the measurement:

Stage	What slow values typically mean	Signature pattern
DNS	Resolver under load, missing local cache, NXDOMAIN retries	High variance across different hosts; first request to a host slow, repeats fast
TCP	Far-away origin, network path issues, SYN drops	Consistent per host, scales with geographic distance
TLS	No session reuse, new connection per request, large cert chains	Near-constant per host; disappears entirely with connection pooling
TTFB	Server-side processing, rate limiting, bot mitigation holding connections	Dominates p99; spikes under concurrency
Download	Large pages, throttled bandwidth, slow trickle responses	Correlates with page size, not with host behavior
Render (browser only)	JS execution, lazy loading, third-party scripts	Only exists when use_js_render-style rendering is in play

The one that bites most scrapers is TTFB, and it’s the one you can least fix client-side. That asymmetry matters when you decide where to spend engineering effort, and we’ll come back to it in the diagnosis section.

Building the Timing Harness with httpx and event Hooks

httpx gives you event hooks — callbacks fired on request send and response receipt — which get you two of the five network stages for free. The rest need lower-level plumbing, covered in the next section. Start with the timer itself:

import time
from contextvars import ContextVar

current_timer: ContextVar["StageTimer | None"] = ContextVar(
    "current_timer", default=None
)

class StageTimer:
    STAGES = [
        ("dns_ms", "dns_start", "dns_end"),
        ("tcp_ms", "tcp_start", "tcp_end"),
        ("tls_ms", "tls_start", "tls_end"),
        ("ttfb_ms", "request_sent", "headers_received"),
        ("download_ms", "headers_received", "body_complete"),
    ]

    def __init__(self, url: str):
        self.url = url
        self.marks: dict[str, int] = {}
        self.ok = True
        self.error = None

    def mark(self, name: str) -> None:
        self.marks[name] = time.perf_counter_ns()

    def as_dict(self) -> dict:
        row = {
            "url": self.url,
            "ts": time.time(),
            "ok": self.ok,
            "error": self.error,
        }
        for field, start, end in self.STAGES:
            a, b = self.marks.get(start), self.marks.get(end)
            row[field] = (
                None if a is None or b is None else round((b - a) / 1e6, 3)
            )
        return row

Missing marks become None rather than zero — an important distinction, because “TLS took 0ms” and “this request reused a connection and never did a handshake” are completely different facts. The hooks:

async def on_request(request):
    timer = current_timer.get()
    if timer:
        timer.mark("request_sent")

async def on_response(response):
    timer = current_timer.get()
    if timer:
        timer.mark("headers_received")

The response hook fires when status line and headers have arrived, which makes request_sent -> headers_received a solid TTFB measurement. Body download completes when the awaited get() returns. Wrapping it up:

import httpx

async def timed_get(client: httpx.AsyncClient, url: str) -> dict:
    timer = StageTimer(url)
    token = current_timer.set(timer)
    try:
        r = await client.get(url)
        timer.mark("body_complete")
        timer.ok = r.status_code == 200
        return timer.as_dict()
    except Exception as exc:
        timer.ok = False
        timer.error = type(exc).__name__
        return timer.as_dict()
    finally:
        current_timer.reset(token)

If you have existing fetch code and don’t want to thread a timer through it, make instrumentation opt-in with a decorator. The function being wrapped doesn’t change; the harness attaches itself through the context variable:

from functools import wraps

def instrumented(fetch):
    @wraps(fetch)
    async def wrapper(url, *args, **kwargs):
        timer = StageTimer(url)
        token = current_timer.set(timer)
        try:
            result = await fetch(url, *args, **kwargs)
            timer.mark("body_complete")
            return result
        except Exception as exc:
            timer.ok = False
            timer.error = type(exc).__name__
            raise
        finally:
            emit(timer.as_dict())   # writer defined later
            current_timer.reset(token)
    return wrapper

@instrumented
async def fetch_page(url: str, client: httpx.AsyncClient):
    return await client.get(url)

One design note: I use a ContextVar instead of passing the timer as an argument because the low-level hooks in the next section don’t have access to your call stack. The context variable flows down through the async machinery, which is exactly what we need.

Capturing DNS, TCP, and TLS Timings That httpx Doesn’t Expose

Here’s the library boundary problem. httpx’s public API ends at “request sent” and “response received.” DNS, TCP, and TLS all happen inside httpcore, the transport layer underneath, and none of it surfaces in the hooks. You have two options: read timings out of the socket after the fact (fragile, platform-dependent), or intercept the calls themselves.

I prefer interception. DNS first — httpcore resolves hostnames through socket.getaddrinfo run in a worker thread, and anyio copies the execution context into worker threads, so our context variable is visible there. A module-level patch:

import socket

_orig_getaddrinfo = socket.getaddrinfo

def _timed_getaddrinfo(host, port, *args, **kwargs):
    timer = current_timer.get()
    if timer is None:
        return _orig_getaddrinfo(host, port, *args, **kwargs)
    timer.mark("dns_start")
    try:
        return _orig_getaddrinfo(host, port, *args, **kwargs)
    finally:
        timer.mark("dns_end")

socket.getaddrinfo = _timed_getaddrinfo

Blunt, yes. Fine for a harness process you control; do not ship this inside a library. For TCP and TLS, swap the network backend that httpcore uses, and wrap the stream so the TLS handshake gets timed too:

import httpcore
import httpx

class TimingStream(httpcore.AsyncStream):
    def __init__(self, stream, timer):
        super().__init__(stream)
        self._timer = timer

    async def start_tls(self, ssl_context, server_hostname=None, timeout=None):
        self._timer.mark("tls_start")
        stream = await super().start_tls(
            ssl_context, server_hostname=server_hostname, timeout=timeout
        )
        self._timer.mark("tls_end")
        return TimingStream(stream, self._timer)

class TimingBackend(httpcore.AsyncNetworkBackend):
    async def connect_tcp(self, host, port, timeout=None,
                          local_address=None, socket_options=None):
        timer = current_timer.get()
        timer.mark("tcp_start")
        stream = await super().connect_tcp(
            host, port, timeout=timeout,
            local_address=local_address, socket_options=socket_options,
        )
        timer.mark("tcp_end")
        return TimingStream(stream, timer)

def timed_client(**client_kwargs) -> httpx.AsyncClient:
    transport = httpx.AsyncHTTPTransport(backend=TimingBackend())
    hooks = {"request": [on_request], "response": [on_response]}
    return httpx.AsyncClient(transport=transport, event_hooks=hooks, **client_kwargs)

Honest caveat: httpcore.AsyncNetworkBackend and AsyncStream.start_tls are internal-ish surfaces, and their signatures have shifted between minor versions. Pin your httpcore version in requirements.txt and re-verify after upgrades. The event hooks, by contrast, are stable public API — which is precisely why the harness is split this way: the fragile part is small and isolated.

To see it work, run the harness ten times against https://example.com:

import asyncio

async def main():
    async with timed_client() as client:
        for _ in range(10):
            row = await timed_get(client, "https://example.com")
            print(row)

asyncio.run(main())

You’ll see something like this in the printed rows (values from a sample run):

{'url': 'https://example.com', 'ts': 1717171717.42, 'ok': True,  'error': None,
 'dns_ms': 11.2, 'tcp_ms': 8.9, 'tls_ms': 27.4, 'ttfb_ms': 141.8, 'download_ms': 64.1}
{'url': 'https://example.com', 'ts': 1717171717.61, 'ok': True,  'error': None,
 'dns_ms': None, 'tcp_ms': None, 'tls_ms': None, 'ttfb_ms': 138.2, 'download_ms': 61.7}

The second row is the interesting one. DNS, TCP, and TLS are None because the client reused the pooled connection — the harness correctly reports “stage did not occur” instead of inventing a zero. That single distinction is what lets the percentile code later separate connection cost from request cost.

Extending the Harness to Full Page Render with Playwright Traces

Plain HTTP covers API endpoints and static pages. For JavaScript-heavy storefronts, latency doesn’t stop at the last byte of HTML — the browser still has to parse, execute, and fire load events. If you’re deciding between plain HTTP and rendering (a decision with real token and latency costs, as discussed in JS rendering vs plain HTTP), you need render timings to make it honestly.

Playwright exposes the browser’s own navigation timing entry, which is the same data DevTools shows you:

from playwright.async_api import async_playwright

async def render_stage_timings(url: str) -> dict:
    async with async_playwright() as p:
        browser = await p.chromium.launch(headless=True)
        page = await browser.new_page()
        await page.goto(url, wait_until="load")
        nav = await page.evaluate(
            "() => performance.getEntriesByType('navigation')[0]"
        )
        await browser.close()
    return {
        "ttfb_ms": nav["responseStart"],
        "dcl_ms": nav["domContentLoadedEventEnd"],
        "load_ms": nav["loadEventEnd"],
    }

responseStart is the browser-measured TTFB, domContentLoadedEventEnd marks DOM ready plus deferred scripts, and loadEventEnd is full load including images and subresources. Merging into the same schema the httpx harness emits keeps your analysis pipeline single-shaped:

def merge_render(row: dict, render: dict) -> dict:
    row["render_ttfb_ms"] = round(render["ttfb_ms"], 3)
    row["render_dcl_ms"] = round(render["dcl_ms"], 3)
    row["render_ms"] = round(render["load_ms"], 3)
    return row

One subtlety: browser timings are measured from navigation start, in the browser’s clock domain. Don’t mix them arithmetically with the httpx stage numbers from a separate request — they’re parallel measurements of the same page, not pieces of one timeline. Log them as their own fields, which is what merge_render does.

Logging Per-Stage Timings to a Queryable JSONL File

The log schema is deliberately flat: one line per request, every stage a top-level field, no nesting. Nested logs are pleasant to read and miserable to aggregate. Flat JSONL loads straight into pandas, jq, or the percentile script below with zero transformation:

import json
import os
import sys

FIELDS = [
    "url", "ts", "ok", "error",
    "dns_ms", "tcp_ms", "tls_ms", "ttfb_ms", "download_ms",
    "render_ttfb_ms", "render_dcl_ms", "render_ms",
]

def make_writer():
    dest = os.environ.get("TIMING_LOG", "stdout")
    if dest == "stdout":
        return lambda row: print(json.dumps(row))
    fh = open(dest, "a", buffering=1)  # line-buffered
    return lambda row: fh.write(json.dumps(row) + "\n")

emit = make_writer()

Switching between console debugging and file collection is then just an environment variable:

# console during development
TIMING_LOG=stdout python harness.py

# file during a real measurement run
TIMING_LOG=timings.jsonl python harness.py

A sample logged line for https://example.com:

{"url": "https://example.com", "ts": 1717171717.42, "ok": true, "error": null, "dns_ms": 11.2, "tcp_ms": 8.9, "tls_ms": 27.4, "ttfb_ms": 141.8, "download_ms": 64.1, "render_ttfb_ms": null, "render_dcl_ms": null, "render_ms": null}

Note the ts field uses wall-clock time deliberately — it’s a label for when the request happened, not a duration. All durations come from the monotonic clock, which the hardening section defends in detail.

Computing p50, p95, and p99 Per Stage with statistics and a Single Pass

Averages hide the exact behavior you care about. A stage with a mean of 40ms can still be responsible for a 3-second p99, because a handful of pathological requests — resolver timeouts, handshake retries — get averaged into invisibility. Percentiles per stage, ranked by tail, put the culprit on top.

The standard library is enough. statistics.quantiles with n=100, method="inclusive" gives you the full percentile ladder in one pass:

import json
import statistics

STAGE_FIELDS = [
    "dns_ms", "tcp_ms", "tls_ms",
    "ttfb_ms", "download_ms", "render_ms",
]

def load_rows(path: str) -> list[dict]:
    with open(path) as fh:
        return [json.loads(line) for line in fh]

def stage_percentiles(rows: list[dict]) -> dict:
    out = {}
    for field in STAGE_FIELDS:
        vals = [
            r[field] for r in rows
            if r.get("ok") and r.get(field) is not None
        ]
        if len(vals) < 2:
            out[field] = None
            continue
        q = statistics.quantiles(vals, n=100, method="inclusive")
        out[field] = {
            "count": len(vals),
            "p50": round(q[49], 1),
            "p95": round(q[94], 1),
            "p99": round(q[98], 1),
        }
    return out

Two filters are doing quiet work there: r.get("ok") drops failed requests (they’d poison the distribution with timeout values), and r.get(field) is not None drops requests where the stage simply didn’t occur, like TLS on a reused connection. The count field makes both filters visible — if tls_ms has a count of 12 out of 200 requests, you know connection reuse is working.

Sample output for 200 requests to https://store.example.com, formatted as a table:

Stage	count	p50 (ms)	p95 (ms)	p99 (ms)
dns_ms	200	11.0	48.0	210.0
tcp_ms	200	9.0	22.0	61.0
tls_ms	200	28.0	95.0	182.0
ttfb_ms	200	142.0	381.0	904.0
download_ms	200	66.0	214.0	483.0

The verdict is unambiguous: TTFB owns the tail. Nothing else comes close at p99, and no amount of DNS caching or connection tuning will touch that 904ms. That’s the kind of conclusion a single “average latency: 310ms” number would have swallowed whole.

Reading the Percentile Table: Diagnosing Three Real Latency Profiles

Percentile shapes cluster into recognizable profiles. Here are three you’ll meet repeatedly, with the fixes that actually match each one:

Profile	dns p50/p95/p99	ttfb p50/p95/p99	tls p50/p95/p99	Recommended fix
DNS-bound	40 / 180 / 900	120 / 200 / 350	25 / 40 / 70	Local resolver cache or a persistent client; check for resolver fallback timeouts
TTFB-bound	10 / 30 / 90	150 / 600 / 2400	26 / 45 / 80	Reduce request rate, spread over time, or accept it — this is the origin’s clock, not yours
TLS-bound	9 / 20 / 50	130 / 190 / 300	90 / 340 / 700	Connection pooling / session reuse; check whether something is closing connections mid-pool

An opinion you may disagree with: most teams instinctively attack DNS first, and it’s usually the wrong target. DNS is loud — big ugly p99 spikes from resolver timeouts — but it’s also the cheapest stage to fix and rarely the majority of total latency. TTFB is where scrapers actually live or die, and it’s the stage you control least. When a target is holding your connection for two seconds before responding, that’s often deliberate friction, not an accident. Spending a sprint on a DNS cache to shave 40ms off p50 while p99 TTFB sits at 2.4 seconds is optimizing the stage that feels good instead of the one that costs you.

The TLS-bound profile, by contrast, is almost always self-inflicted and embarrassingly cheap to fix. Here’s the before/after for https://example.com with 200 requests — same harness, same network, the only change being one persistent httpx.AsyncClient shared across all requests instead of a fresh client per fetch:

Measurement	tls p50	tls p95	tls p99	total p95
Fresh client per request	27.0 ms	95.0 ms	182.0 ms	412.0 ms
One shared client (pooled)	n/a (reused)	28.0 ms*	62.0 ms*	301.0 ms

*Only the handful of requests that opened fresh connections contribute TLS time at all; the count field in the percentile output makes this visible.

One connection pool, roughly 110ms off p95 total latency. No proxy changes, no concurrency tuning, no new infrastructure. If your harness shows a TLS-bound profile, fix pooling before you touch anything else.

Hardening the Harness: Clock Sources, Warmup Requests, and Outlier Hygiene

Three pitfalls will quietly corrupt your numbers if you don’t guard against them.

Clock source. The StageTimer already uses time.perf_counter_ns(), and this is not a style preference. time.time() is wall-clock time, which the OS and NTP can adjust — forward, backward, or smeared — while your harness runs. Subtract two wall-clock samples across an adjustment and a 60ms TLS handshake can report as negative, or as 300ms. perf_counter_ns is monotonic, high-resolution, and has no defined relationship to calendar time, which is exactly what you want for durations:

def mark(self, name: str) -> None:
    self.marks[name] = time.perf_counter_ns()  # monotonic, ns resolution
    # never: self.marks[name] = time.time()    # NTP-adjustable, corrupts diffs

Keep time.time() only for the ts label field, where you genuinely want calendar time.

Cold-start bias. The first request in a run pays costs nobody else does: empty DNS cache, cold TLS session tickets, first-shot TCP congestion window, and in the Playwright case, browser process startup. Either discard row zero from analysis, or better, issue one unlogged warmup request before the measured run. Warmup is two lines and removes a whole class of “why is the first request always weird” confusion.

Failed requests in percentile math. A connect timeout writes a huge value into whichever stage was in flight when it expired, and one 30-second outlier drags p99 into nonsense. The rule: log failures with full detail, but exclude them from percentile computation. The stage_percentiles function already does this via the ok filter; make the exclusion explicit and observable:

def split_rows(rows: list[dict]) -> tuple[list[dict], list[dict]]:
    usable = [r for r in rows if r.get("ok")]
    failed = [r for r in rows if not r.get("ok")]
    return usable, failed

rows = load_rows("timings.jsonl")
usable, failed = split_rows(rows)
print(f"{len(usable)} usable, {len(failed)} failed (logged, excluded from percentiles)")
stats = stage_percentiles(usable)

Run this after a batch where a few fetches to https://store.example.com died with ConnectError and you’ll see the failure count reported while the percentile table stays clean. The failure rows still matter — a rising failure rate is its own latency story, and it’s worth cross-referencing with success-rate measurement as covered in measuring your scraper’s real success rate locally. Just don’t let those rows do arithmetic.

One more hygiene item: if your client retries transparently, each “request” in your log is really the last attempt of N, and your TTFB distribution is silently conditioned on success. Either disable client-side retries during measurement runs or log attempt counts. Mixing retry policies into measured data is how teams end up confident in numbers that mean nothing.

Wrap-Up

The harness is small on purpose: a StageTimer with perf_counter_ns marks, an httpx client with event hooks and a patched network backend, an optional Playwright pass for rendered pages, a flat JSONL writer, and a percentile script built on statistics.quantiles. Every piece runs locally against example.com in an afternoon, and the output — a per-stage p50/p95/p99 table — answers questions that total-latency dashboards structurally cannot.

If you route scrapes through a managed API rather than your own HTTP client, the internal stages are hidden behind one opaque call, but the harness still earns its keep: wrap the API call in the same timer, log end-to-end latency with the identical schema, and compare it against your direct-fetch baseline to see exactly what the managed hop costs you and what it saves in retries and infrastructure.

Start with 100–200 requests against your real target list, read the percentile table, and expect the answer to be TTFB more often than you’d like. At least then you’ll know where the time goes — and where it doesn’t.