Hi Milan, Janusz,
I suspect I managed to reliably trigger the issue you were facing and
found a good explanation for it. It is caused by unprocessed bytes at
the end of the H1 stream. I manage to reproduce it if I chain two layers
of haproxy with the last one sending stats. It does not happen with a
single layer, so the scheduling matters a lot (I think it's important
that the final CRLF is present in the same response packet as the final
chunk).
Could you please try the attached patch to see if you're on the same
issue ?
Thanks,
Willy
>From 00610960a196f01b6e6b549e29eb1cf2426d253a Mon Sep 17 00:00:00 2001
From: Willy Tarreau <w...@1wt.eu>
Date: Thu, 19 Jul 2018 10:58:28 +0200
Subject: BUG/MEDIUM: h2: never leave pending data in the output buffer on
close
We currently don't process trailers on H2, but this has an impact : on
chunked HTTP/1 responses, we decide to emit the ES bit once we see the
0CRLF. From this point the stream switches to the CLOSED state, which
aborts processing of the remaining bytes. Thus the extra CRLF which ends
trailers is not processed and remains in the buffer. This prevents the
stream from being notified about end of transmission, which in turn keeps
the mux busy and prevents the connection from quitting.
The case of the trailers is not the root cause of this issue, though it
is what triggers it. The root cause is that upon error and/or close, once
we know we're not going to process any more data, we must absolutely flush
any remaining bytes from the output buffer, otherwise there is no way the
stream can quit. This is what this patch does.
It looks very likely related to the issues reported and debugged by
Janusz Dziemidowicz and Milan Petruzelka.
One way to reproduce it is to chain two proxies with the last one emitting
chunked data (typically using the stats page) :
global
stats socket /tmp/sock1 mode 666 level admin
stats timeout 1h
tune.ssl.default-dh-param 1024
tune.bufsize 16384
defaults
mode http
timeout connect 4s
timeout client 10s
timeout server 20s
listen px1
bind :4443 ssl crt rsa+dh2048.pem npn h2 alpn h2
server s1 127.0.0.1:4445
listen px2
bind :4444 ssl crt rsa+dh2048.pem npn h2 alpn h2
bind :4445
stats uri /
Then use curl to fetch the stats through px1 :
curl --http2 -k "https://127.0.0.1:4443/";
When curl is sent to the first one, "show sess" issued to the CLI will
show a remaining session during the client timeout. When curl is aimed at
port 4444 (px2), there is no such remaining session.
This fix needs to be backported to 1.8.
---
src/mux_h2.c | 15 +++++++++++++++
1 file changed, 15 insertions(+)
diff --git a/src/mux_h2.c b/src/mux_h2.c
index 0d0101e..47df89e 100644
--- a/src/mux_h2.c
+++ b/src/mux_h2.c
@@ -3302,6 +3302,14 @@ static int h2s_frt_make_resp_data(struct h2s *h2s,
struct buffer *buf)
/* we may need to add END_STREAM */
/* FIXME: we should also detect shutdown(w) below, but how ? Maybe we
* could rely on the MSG_MORE flag as a hint for this ?
+ *
+ * FIXME: what we do here is not correct because we send end_stream
+ * before knowing if we'll have to send a HEADERS frame for the
+ * trailers. More importantly we're not consuming the trailing CRLF
+ * after the end of trailers, so it will be left to the caller to
+ * eat it. The right way to do it would be to measure trailers here
+ * and to send ES only if there are no trailers.
+ *
*/
if (((h1m->flags & H1_MF_CLEN) && !(h1m->curr_len - size)) ||
!h1m->curr_len || h1m->state >= HTTP_MSG_DONE)
@@ -3404,6 +3412,13 @@ static int h2_snd_buf(struct conn_stream *cs, struct
buffer *buf, int flags)
}
}
+ if (h2s->st >= H2_SS_ERROR) {
+ /* trim any possibly pending data after we close (extra CR-LF,
+ * unprocessed trailers, abnormal extra data, ...)
+ */
+ bo_del(buf, buf->o);
+ }
+
/* RST are sent similarly to frame acks */
if (h2s->st == H2_SS_ERROR || h2s->flags & H2_SF_RST_RCVD) {
cs->flags |= CS_FL_ERROR;
--
1.7.12.1
