tree 1926e50b2b71d86dbd1445ecbb02e078f1bd9367
parent 90a7c03ec0bc405fd9514a0a65dccc15b8c4a993
author Willy Tarreau <w@1wt.eu> 1536141408 +0200
committer Willy Tarreau <w@1wt.eu> 1536157823 +0200
encoding latin1

BUG/MEDIUM: session: fix reporting of handshake processing time in the logs

The handshake processing time used to be stored per stream, which was
valid when there was exactly one stream per session. With H2 and
multiplexing it's not the case anymore and the reported handshake times
are wrong in the logs as it's computed between the TCP accept() and the
stream creation. Let's first move the handshake where it belongs, which
is the session.

However, this is not enough because we don't want to report an excessive
idle time either for H2 (since many requests use the connection).

So the solution used here is to have the stream retrieve sess->tv_accept
and the handshake duration when the stream is created, and let the mux
immediately reset them. This way, the handshake time becomes zero for the
second and subsequent requests in H2 (which was already the case in H1),
and the idle time exactly counts how long the connection remained unused
while it could be used, so in H1 it runs from the end of the previous
response and in H2 it runs from the end of the previous request since the
channel is already available.

This patch will need to be backported to 1.8.