Our address lookups took one second or three and the service said it had answered in forty milliseconds

On a Monday in October, a marketing email was sent to six hundred thousand customers, causing checkout to slow down for around forty minutes. The checkout team discovered the issue stemmed from the address lookup service, which suggests addresses as customers type their postcode. The client side histogram indicated two peaks, just over one second and just over three seconds.

The address service claimed it responded in forty milliseconds, and its CPU never exceeded forty percent. Both histograms were accurate. The address service only begins timing when one of its gunicorn workers handles a request. The delay occurred before the request was accepted, in a queue that the application does not see. When a client connects, Linux completes the handshake and places the connection in the listen socket's accept queue until the application accepts it.

The socket's backlog is limited by net.core.somaxconn, and gunicorn requested a value of 2048. However, the three virtual machines were running Ubuntu 18.04 with kernel 4.15, where the default somaxconn was 128. When the accept queue is full, the kernel discards new connection attempts without responding. The client's TCP sends its SYN request again after one second, then two seconds thereafter, forming two peaks - one second and three seconds - indicative of a retransmission timer rather than a slow process. nstat showed TcpExtListenOverflows increasing by thousands per minute, and ss -ltn revealed a send queue of 128 on the listening port, which is the backlog for a listening socket.

The team adjusted net.core.somaxconn to 4096 in sysctl.d and restarted gunicorn, as the socket retains the backlog it was given when it called listen. They also transitioned to async workers, preventing a burst from waiting behind a fixed number of synchronous ones. The VMs will be rebuilt on the latest release. Node_exporter now gathers TcpExt_ListenOverflows, and they alert on any increase.

Checkout's client side latency is displayed alongside the address service's numbers on the dashboard, making the gap between them evident to the owning team. A service can only measure what it has accepted; the queue was in the kernel, holding a sixteenth of what gunicorn requested.