Mehdi Akiki
Published on

What a Connection Pool Saves, and the Stale Connection It Gives You Back

Authors
  • Mehdi Akiki avatar
    Name
    Mehdi Akiki
    Twitter

Investigation · Part 10 of 10 · Following a TCP connection

On my first try, reusing the connection made every request 60 times slower:

== one connection: total 43.95 s, per request median 43.372 ms, p90 46.644 ms, p99 46.870 ms
...
== a new connection each: total 0.73 s, per request median 0.693 ms, p90 1.070 ms, p99 1.499 ms

These are 1000 small HTTP requests on my laptop to the HTTP server of the Python standard library, first on one connection, then with a new connection each. A pool should make requests faster, so this looked wrong. It was not, and it was the last surprise of this series.

This is the last part of a series that followed one TCP connection, from what happens when a program calls connect() to its close. A connection pool is the place where a program decides to not close it, and to use it again. So this part uses almost everything from the earlier ones.

A pool is a connection that you keep

HTTP/1.1 is made for this. RFC 9112 says it directly: "HTTP/1.1 defaults to the use of "persistent connections", allowing multiple requests and responses to be carried over a single connection." Python's http.client.HTTPConnection keeps its socket open between requests, so one HTTPConnection object is already a pool of one connection.

My server is http.server with protocol_version = "HTTP/1.1" (so that it keeps connections open), in its own process, with a handler that answers hello and a Content-Length.

Why the reused connection was slow

43.37 ms per request, and p90 at 46.6 ms. I knew these numbers from part 3 about Nagle and delayed ACK: 13 and 14 ticks of the kernel clock, a delayed ACK timer.

The server writes each response in two pieces. http.server collects the status line and the headers, and end_headers() writes them with one call. Then my handler writes the body with a second call. And the server does not set TCP_NODELAY: in socketserver, the class attribute disable_nagle_algorithm is False by default. So it is the case of part 3, in the other direction. The body is small, the headers are not acknowledged yet, so Nagle keeps the body. The client reads the headers, waits for the body, has nothing to send, and delays its ACK.

Why were new connections fast, then? Because at the start of a connection the receiver acknowledges at once (part 3 saw the same: its first request was fast every time). Each new connection got only one response, before the delayed ACKs started.

With disable_nagle_algorithm = True in the handler, the server sets TCP_NODELAY on each connection:

== one connection: total 0.18 s, per request median 0.149 ms, p90 0.220 ms, p99 0.586 ms
  first 3 requests: 3.206 0.770 0.646 ms
  TIME-WAIT after it: client side 1, server side 0; counters of the whole machine: TcpOutRsts +0, TcpExtTCPAbortOnData +0
== a new connection each: total 0.59 s, per request median 0.557 ms, p90 0.846 ms, p99 1.172 ms
  first 3 requests: 1.329 0.775 1.045 ms
  TIME-WAIT after it: client side 1001, server side 0; counters of the whole machine: TcpOutRsts +0, TcpExtTCPAbortOnData +0

Now the reused connection is the fast one. So before you measure a pool, check first how the server writes.

What the pool saves

All the numbers, with TCP_NODELAY on the server:

1000 GET requestsone connectiona new connection each
HTTP, median per request0.149 ms0.557 ms
HTTPS, median per request0.204 ms4.336 ms
HTTP, TIME-WAIT left after11001
HTTPS, TIME-WAIT left after00

For plain HTTP over loopback, a new connection costs about 0.4 ms more per request. Not only the connect() of part 1, a few microseconds, but also a new socket on both sides, a new thread in this threading server, and the Python objects around them. For HTTPS, the difference is 4.1 ms per request, the full TLS handshake of part 9 with the RSA certificate, for each request. Reuse made HTTPS 21 times faster.

And loopback is the best case: on a real network, a pool also saves one round trip for TCP and one for TLS on every request after the first one.

The TIME-WAIT line is the other saving. With a new connection for each request, my client closed first 1000 times, so 1000 sockets stayed in TIME-WAIT for the next minute (plus the one of the first batch), the problem of part 7. With reuse, one.

For HTTPS both numbers are 0, and this surprised me. The counters explain it: TcpOutRsts +1000 and TcpExtTCPAbortOnData +1000 for 1000 connections. Each one ended with a reset. I traced the server for one connection, from the moment its read returned the end of file:

read(4, "", 5)                  = 0
write(4, ""..., 24)             = 24
shutdown(4, SHUT_WR)            = -1 ENOTCONN (Transport endpoint is not connected)
close(4)                        = 0

The server read the end of file of the client, and then it wrote one more TLS record of 24 bytes (24 bytes is exactly the size of one encrypted TLS 1.3 alert: 5 bytes of header, 2 of alert, 1 of type and the 16-byte tag. So it is probably an alert, but I cannot see which one). This record arrived at a socket that the client had already closed, so the client kernel answered with a RST, like the write after close in part 6. A reset leaves no TIME-WAIT, and the server's shutdown() found the connection already gone. Nothing failed for the programs, but it is not a clean end.

The stale connection

Now the problem of every pool. A connection that waits in the pool can be closed by the other side at any moment, and RFC 9112 says it plainly: "Connections can be closed at any time, with or without intention." Servers close idle connections to save their own resources. I gave my server an idle timeout of 1 second (the timeout attribute of the handler), made one request, waited 2 seconds, and looked at the connection:

== GET: request 1 on a new connection: ok; then 2 s without requests
  ss for this connection:
    CLOSE-WAIT 1      0      127.0.0.1:57602 127.0.0.1:21104
    FIN-WAIT-2 0      0      127.0.0.1:21104 127.0.0.1:57602
  check before reuse: select() says readable: True, recv(1, MSG_PEEK) returns b''
  request 2 (GET): http.client.RemoteDisconnected: Remote end closed connection without response
    raised in client.py, in _read_status()

The server closed, so its socket is in FIN-WAIT-2, and mine is in CLOSE-WAIT, with the FIN of the server waiting in Recv-Q (the 1). The pool does not know it. For the program, the socket is still there, and nothing happened. Then the next request:

  • HTTP, GET: RemoteDisconnected. The request was sent (the first write after a close succeeds, part 6), and when the client read the response it found the end of file.
  • HTTP, POST of 1 MiB: BrokenPipeError, raised in send(). The first write went out, the server kernel answered with a RST, and the next write of the same request failed with EPIPE.
  • HTTPS, GET: BrokenPipeError, but raised in ssl.py, in read(), while reading the response.
  • HTTPS, POST: BrokenPipeError, raised in send().

Four stale connections gave two errors from four different places, and the cause was the same every time.

The check line shows that the pool could know it before the request: the socket was already readable, and recv(1, MSG_PEEK) returned an empty result, the end of file. A pool can test this when it takes a connection out. But it is a race: the server can close one microsecond after the test. The other usual protections are an idle timeout in the pool that is shorter than the one of the server, and a retry. The retry is the dangerous one.

Which retry is safe

After one of these errors, the natural reaction is to try again, on a new connection. Here is my client doing exactly this, once, for a payment. My server counts the payments:

== the connection was idle for 2 s and the server closed it; before: payments 0
  attempt 1: BrokenPipeError: [Errno 32] Broken pipe
  attempt 2: payment 1 done
  after: payments 1
== the server makes the payment and loses the answer; before: payments 1
  attempt 1: RemoteDisconnected: Remote end closed connection without response
  attempt 2: payment 3 done
  after: payments 3
== the same with an Idempotency-Key; before: payments 3
  attempt 1: RemoteDisconnected: Remote end closed connection without response
  attempt 2: payment 4 done
  after: payments 4

In the first case the retry was correct. The server had closed the connection before the request came, it never saw it, and one payment was made.

In the second case, the server made the payment and then closed the connection without an answer, like a server that crashes or a proxy that times out at the wrong moment. The client got an error, retried, and the server made a second payment. So the same customer paid two times.

And the client cannot see the difference. In this run the first case gave BrokenPipeError and the second RemoteDisconnected, but the stale GET of the previous section also gave RemoteDisconnected, and with TLS the same situation gave other errors. The error says "the connection broke". It does not say "your request was not applied".

This is why HTTP gives the rule in RFC 9110: "Idempotent methods are distinguished because the request can be repeated automatically if a communication failure occurs before the client is able to read the server's response." GET, PUT, DELETE are idempotent. A POST that pays is not, and the client "SHOULD NOT automatically retry a request with a non-idempotent method unless it has some means to know that the request semantics are actually idempotent, regardless of the method, or some means to detect that the original request was never applied."

The third case is such a means: the client sent an Idempotency-Key, the server stored its answer under this key, and the retry got this stored answer, "payment 4 done", instead of a new payment. One payment. I wrote about how to build this in What an Idempotency Key Is. My server here keeps the keys in a dictionary, enough for a demonstration and nothing more.

So a pool can retry on a fresh connection by itself only when the request is idempotent, or when the request carries a key that makes it idempotent. For everything else, the error must go up to code that knows what the request means. The same rule came back at the end of the series about database indexes, in Keeping a Derived Index in Sync Outside the Database: a process that can send an update twice needs an update that is safe to apply twice.

The whole connection

Since the first part, I followed one connection through the kernel. connect() returned after a handshake that the server's kernel made alone, or waited 133 seconds for a server that never answered. The connection then waited in the accept queue, where it can be connected for seconds before the server program knows, or even never. Its first small writes met Nagle and delayed ACK and waited 43 ms. Its bytes arrived as a stream without boundaries, so the reader needs its own framing. When the reader stopped, the socket buffers filled and slowed the writer, until a queue without a limit broke this. At the end, close() sent a FIN or a RST depending on unread data, and the side that closed first kept the connection in TIME-WAIT for one minute. Around it, the name cost more than the connection on loopback, TLS cost milliseconds of CPU for each new connection, and in this part the pool saved most of it, and gave back a connection that was already dead.

What I keep from all of it: a socket call that returns quickly tells you what your kernel did, not what the other program did. connect() returned before the server program accepted, send() returned before anything was delivered, and a reused connection looked alive after the server had closed it. Each time, ss, strace and the counters showed the answer without one captured packet.

The outputs of this part are p10-bench.txt, p10-stale.txt, p10-retry.txt and p10-tlsclose.txt, and the program is p10_pool.py in the fixture of the series, with the run.sh that runs all ten parts.

Sources