OnCallReady

Lesson 9.27 · TCP, TLS & HTTP · 12 min read

Where latency lives: curl -w and the road to the first byte

In plain words

Imagine timing a pizza order. You look up the phone number (30 seconds), the phone rings until someone answers (1 minute), you prove you're a regular customer (1 minute), you place the order and wait until the first slice arrives (5 minutes). If you only know "it took 7.5 minutes", you can't complain to the right person. If you have the timestamps, you know the kitchen was the slow part, not the phone line.

curl -w gives you those timestamps: time_namelookup (DNS), time_connect (TCP), time_appconnect (TLS), time_starttransfer (first byte). They are cumulative, so you read the gaps between them. The gap before the first byte is the server thinking.

Why this matters

"The app is slow" usually arrives as one number: "3 seconds". That number is the sum of several phases - DNS, TCP, TLS, the server thinking, the download - each owned by someone different. curl can time every phase separately, so you can hand the problem to the right owner with evidence.

What you need to know already: DNS lookups (Chapter 8), the TCP handshake and RTT (9.1), the TLS handshake (9.15), curl -w and connection reuse (9.21), reverse proxies (9.23), and the SLO and percentile ideas from Chapter 0.

The format file

-w accepts @FILE to read its format from a file, so you can keep a reusable timing template. TTFB = time to first byte: when the first byte of the response arrived.

# you write this file in the next mission
cat ~/oncall-lab/labs/1b-networking/curl-format.txt
    dns:      %{time_namelookup}\n
    tcp:      %{time_connect}\n
    tls:      %{time_appconnect}\n
    ttfb:     %{time_starttransfer}\n
    total:    %{time_total}\n
    code:     %{http_code}\n
curl -w @curl-format.txt -o /dev/null -s https://example.com/
    dns:      0.030412
    tcp:      0.126520
    tls:      0.222611
    ttfb:     0.341901
    total:    0.342001
    code:     200

The values are cumulative from the start. You read the gaps:

dns              0.030   30 ms resolving the name
tcp - dns        0.096   one round trip for the handshake: the RTT is ~96 ms
tls - tcp        0.096   one more RTT: TLS 1.3
ttfb - tls       0.119   one RTT for the request + ~23 ms of server time
total - ttfb     0.0001  tiny body

For plain http, time_appconnect is 0 - compute the server time from time_connect instead. Other variables worth knowing: %{time_pretransfer} (everything before the request goes out), %{time_redirect} (time spent on redirects with -L), %{remote_ip}, %{num_connects}, %{http_version}, %{errormsg}.

The shapes of slow

dns large              resolver problem: dead first nameserver (5 s!, 8.26), the
                       ndots search tax (8.27), a slow upstream resolver
tcp - dns large        distance (RTT), or SYN retransmits: exactly 1 s, 3 s, 7 s
                       extra = lost SYNs
tls - tcp large        TLS 1.2 (two RTTs), a slow handshake (big RSA keys, a
                       struggling server), some clients checking whether the
                       certificate was revoked (OCSP)
ttfb - tls large       THE APPLICATION. It had the request and thought about it.
                       Nothing on the network will fix this.
total - ttfb large     a large body or a slow link; check %{size_download}

The "exactly 1 s" pattern deserves its own line: a connect time of ~1.03 s when the RTT is 30 ms means the first SYN was lost and the kernel's retransmit timer (1 s) fired. At ~3 s, two SYNs were lost. Packet loss has a signature.

Latency is not one number

Measure more than once, and look at the spread:

# cart.lab, from the latency lab in this chapter
for i in 1 2 3 4 5; do curl -w '%{time_starttransfer}\n' -o /dev/null -s http://cart.lab/api/cart; done
0.041
0.043
1.912
0.040
1.887

Two slow out of five is a different problem from five slow: a slow backend behind a round-robin LB (9.23), a cache miss path (the answer was not in the app's cache and had to be computed), the JVM pausing to clean up memory (garbage collection, 5.13). The average of those five (0.78 s) describes none of the requests. That is why SLOs are written on percentiles (Chapter 0).

Then go one hop further

A slow ttfb through a proxy means the proxy or what is behind it. Time each hop separately:

curl -w @curl-format.txt -o /dev/null -s http://cart.lab/api/cart/quote        via nginx
curl -w @curl-format.txt -o /dev/null -s http://127.0.0.1:8082/api/cart/quote  the app directly
curl -w @curl-format.txt -o /dev/null -s http://pricing.lab/api/price           what the app calls

If the direct call is as slow as the proxied one, nginx is innocent. If the app's own dependency shows the same ttfb, the app is innocent too - it is waiting. You have just traced a latency problem through three services with one command.

From a URL to the first byte (the interview question)

"Walk me through what happens between typing https://shop.lab/cart and the first byte arriving." A strong answer names each step and what can go wrong there:

  1. Parse the URL: scheme https, host shop.lab, port 443, path /cart.
  2. Resolve shop.lab (8.16): the application calls getaddrinfo -> nsswitch -> /etc/hosts -> resolv.conf -> the stub resolver -> caches -> the recursive chain. (NXDOMAIN, stale caches, split horizon, ndots.) time_namelookup.
  3. Route: the kernel picks an interface and next hop (ip route get), ARPs for the gateway.
  4. TCP handshake: SYN, SYN-ACK, ACK - one RTT. (Refused, timeout, SYN retransmits, port exhaustion.) time_connect.
  5. TLS handshake: ClientHello with SNI and ALPN, the server's chain, verification against the trust store, key exchange - one RTT on 1.3. (Missing intermediate, expiry, SAN, MTU black hole.) time_appconnect.
  6. Request: GET /cart with Host, sent over HTTP/2 if ALPN agreed.
  7. Through the stack on the far side: a load balancer (L4 or L7), maybe a WAF, one or more reverse proxies; X-Forwarded-For added; routing by host and path.
  8. The application does its work: its own DNS, connection pools, database, downstream calls - each with the same seven steps inside.
  9. First byte of the response. time_starttransfer.

Then say which of those you would measure first when it is slow, and with what - which is the rest of this chapter.

What you can now do

Why it helps

"The app is slow" is one of the most common tickets a platform team gets, and it usually arrives as a single number. curl -w splits it: 5 seconds in DNS points at a dead first nameserver or the ndots search tax; a connect of exactly 1 or 3 seconds means lost SYNs; a large gap before the first byte means the application, and no network change will help.

Running it through nginx, then against the app directly, then against the app's dependency, shows which of three services owns the latency in a couple of minutes, with numbers you can paste into the incident channel. Measuring several times and looking at the spread is also how you explain to a team why the SLO is on p99, not the average.

FAQ

Why are the curl -w timings cumulative?

Each variable is measured from the start of the transfer, so time_connect already includes DNS, and time_appconnect includes DNS and TCP. You get the cost of each phase by subtracting: TCP is time_connect - time_namelookup, TLS is time_appconnect - time_connect, server time plus one round trip is time_starttransfer - time_appconnect. For plain HTTP, time_appconnect is 0, so subtract time_connect instead.

How do I estimate the round-trip time from curl output?

The TCP handshake takes one round trip, so time_connect - time_namelookup is roughly the RTT. On TLS 1.3 the handshake adds about one more RTT; on TLS 1.2 two. The request itself costs another RTT before the first byte comes back, so the server's own processing time is approximately time_starttransfer - time_appconnect minus one RTT.

My connect time is almost exactly 1 second. Is the server far away?

Probably not. A connect time of about 1.03 seconds when the normal RTT is 30 ms means the first SYN was lost and the kernel's initial retransmission timer, 1 second, fired. About 3 seconds means two SYNs were lost. Packet loss has this recognisable signature. Look for congestion, a flaky link, an overloaded accept queue, or a stateful device dropping the first packet of a flow.

Why not just average the timings?

Because averages hide the shape. Five requests of 0.04, 0.04, 1.9, 0.04 and 1.9 seconds average 0.78, which describes none of them. Two slow out of five usually means one slow backend behind a round-robin load balancer, a cache miss path, or the JVM pausing for garbage collection. That's why SLOs are written on percentiles like p95 or p99, and why you always measure more than once.

What does time to first byte actually measure?

time_starttransfer is the moment the first byte of the response arrived, measured from the start. After you subtract DNS, TCP and TLS, what's left is one round trip for the request plus everything the far side did: load balancers, proxies, the application, and all the calls it made. A large gap here is the application or something behind it. Time each hop separately to find which one.

In an interview Junior

An API is slow. How do you figure out whether it is the network or the application?

Time each phase with curl -w (the values are cumulative, so read the gaps):

curl -s -o /dev/null -w 'dns %{time_namelookup} tcp %{time_connect} tls %{time_appconnect} ttfb %{time_starttransfer} total %{time_total}\n' https://api.lab/

Measure several times and look at the spread, not the average. Then time each hop separately - through the proxy, the app directly, the app's dependency - to find which one owns the latency.

Also asked: How do you measure how long each part of an HTTP request takes? · Why do you look at percentiles rather than averages for latency? · Why is a new connection per request slower than reusing one?

Practise this lesson in the terminal Free, in your browser - a real Ubuntu terminal to try it in, with missions that check your work.