Chapter 26 — The 40-millisecond mystery

Practice (20 min)

A. Check whether your tools set it. Many do:

# Linux -- watch a program's socket options as it runs
strace -f -e trace=setsockopt curl -s https://example.com 2>&1 | grep -i nodelay

B. Measure a suspiciously round latency. If you have a local service, time many small requests:

for i in $(seq 1 20); do
  curl -s -o /dev/null -w '%{time_total}\n' http://localhost:8000/
done | sort -n

Values clustered at 0.04 s with a local server = the fingerprint.

C. Recognise the sibling problem. Also watch for delays that are exact multiples of common timers: 200 ms (retransmission timeout, Chapter 22), 1 s / 3 s / 7 s (SYN retries, Chapter 21), 5 s (a dead DNS server, Chapter 18). Suspiciously round numbers in latency are always a timer, never a coincidence.

Build it in Go (20 min) — the 40 ms mystery, on demand

In Go, the fix above is already applied. Every TCP connection Go creates has TCP_NODELAY set by default. That's why Go services rarely hit this bug, and why it's confusing when they talk to a peer written in something else. To see the problem, this lab turns Nagle back on with SetNoDelay(false) and uses the classic "write-write-read" pattern:

// nagle: reproduce Chapter 26's "40 ms mystery" on purpose.
//
// Go sets TCP_NODELAY on every TCP connection by default (Nagle OFF), so
// Go programs rarely hit this -- unless someone turns Nagle back on, or the
// peer is a program in another language. Here we turn it on deliberately.
//
//	go run ./nagle
package main

import (
	"bufio"
	"fmt"
	"net"
	"slices"
	"time"
)

func main() {
	ln, err := net.Listen("tcp", "127.0.0.1:0")
	if err != nil {
		panic(err)
	}
	go echoServer(ln)

	for _, noDelay := range []bool{true, false} {
		c, err := net.Dial("tcp", ln.Addr().String())
		if err != nil {
			panic(err)
		}
		tc := c.(*net.TCPConn)
		tc.SetNoDelay(noDelay) // false = Nagle's algorithm ON
		r := bufio.NewReader(c)

		var lat []time.Duration
		for i := 0; i < 20; i++ {
			start := time.Now()
			// The classic bad pattern: header and body in TWO small writes,
			// then wait for a reply ("write-write-read").
			c.Write([]byte("HEADER:"))
			c.Write([]byte("body\n"))
			if _, err := r.ReadString('\n'); err != nil {
				panic(err)
			}
			lat = append(lat, time.Since(start))
		}
		c.Close()
		slices.Sort(lat)
		fmt.Printf("TCP_NODELAY=%-5v  p50=%-10v max=%v\n", noDelay, lat[len(lat)/2], lat[len(lat)-1])
	}
	fmt.Println("\nIf NODELAY=false is ~40ms (Linux) or higher, you just met Nagle + delayed ACK.")
	fmt.Println("Fix: one write per message (bufio.Writer + Flush), or keep NODELAY on.")
}

func echoServer(ln net.Listener) {
	for {
		c, err := ln.Accept()
		if err != nil {
			return
		}
		go func() {
			defer c.Close()
			r := bufio.NewReader(c)
			for {
				line, err := r.ReadString('\n')
				if err != nil {
					return
				}
				c.Write([]byte(line))
			}
		}()
	}
}

$ go run ./nagle                  # Linux
TCP_NODELAY=true   p50=5.709µs    max=49.25µs
TCP_NODELAY=false  p50=43.952667ms max=46.074958ms

Four orders of magnitude, caused by one socket option and two small writes. On macOS loopback the effect often doesn't appear, because delayed ACK behaves differently there. Run it on Linux (or in the container from Section 0.8) to see the real fingerprint.

What to notice:

• The fix in the output, "one write per message", is the cleanest one. bufio.Writer collects the header and body and Flush() sends them in a single write(), so Nagle never has a small packet to hold back.
• SetNoDelay is a thin wrapper around setsockopt(fd, IPPROTO_TCP, TCP_NODELAY, ...), the same call the Python snippet above makes.

Exercises:

1. Keep SetNoDelay(false) but wrap the connection in a bufio.Writer and Flush() after the body. Does the 40 ms disappear?
2. Run the server under strace -e trace=setsockopt and confirm Go set TCP_NODELAY on the accepted connection too.
3. Throughput is 1 / 44 ms ≈ 23 requests per second per connection. Find the "suspiciously round number" in that.