Le 07/03/2017 à 20:51, Jon Simpson a écrit :
On 7 March 2017 at 08:48:37, Christopher Faulet (cfau...@haproxy.com
<mailto:cfau...@haproxy.com>) wrote:
Thanks for these info. By checking how you named your trace filters, I
guess you use the HTTP compression. If I'm right, I think I found a bug
with the help of your logs.
The bug is triggered when your HTTP server replies before the end of the
request. I guess it always sends its 401 responses just after reading
requests headers. So it is timing issue from the HAProxy point of view.
This should work of course. If I'm right, the bug only appears when a
filter is used. So a temporary workaround, waiting my fix, is to disable
the HTTP compression.
I'll try to fix it very soon, I just need to talk with Willy to do it
the right way. I will keep you informed.
--
Christopher Faulet
Hi Christopher,
Yes - you’re right, in our normal configuration the compression filter
is enabled.
I was able to continue replicating the issue even without the
compression filter when testing/generating those logs, but that was with
the trace filter enabled - so there was always a filter. When I remove
all filters (both trace & compression) the issue doesn’t reproduce in my
test environment any more, so I think your theory is correct.
Thanks for tracking it down - much appreciated :)
Hi Jon,
Here is a patch that should fix your bug. It was trickier than expected.
Could you confirm that it fix your bug ?
--
Christopher Faulet
>From 0e47d5db9cca60d3633fd4e1183948298a3fe07e Mon Sep 17 00:00:00 2001
From: Christopher Faulet <cfau...@haproxy.com>
Date: Fri, 10 Mar 2017 11:52:44 +0100
Subject: [PATCH] BUG/MEDIUM: filters: Fix channels synchronization in
flt_end_analyze
X-Bogosity: Ham, tests=bogofilter, spamicity=0.000000, version=1.2.4
When a filter is used, there are 2 channel's analyzers to surround all the
others, flt_start_analyze and flt_end_analyze. This is the good place to acquire
and release resources used by filters, when needed. In addition, the last one is
used to synchronize the both channels, especially for HTTP streams. We must wait
that the analyze is finished for the both channels for an HTTP transaction
before restarting it for the next one.
But this part was buggy, leading to unexpected behaviours. First, depending on
which channel ends first, the request or the response can be switch in a
"forward forever" mode. Then, the HTTP transaction can be cleaned up too early,
while a processing is still in progress on a channel.
To fix the bug, the flag CF_FLT_ANALYZE has been added. It is set on channels in
flt_start_analyze and is kept if at least one filter is still analyzing the
channel. So, we can trigger the channel syncrhonization if this flag was removed
on the both channels. In addition, the flag TX_WAIT_CLEANUP has been added on
the transaction to know if the transaction must be cleaned up or not during
channels syncrhonization. This way, we are sure to reset everything once all the
processings are finished.
This patch should be backported in 1.7.
---
include/types/channel.h | 3 ++-
include/types/proto_http.h | 7 ++++++-
src/filters.c | 52 ++++++++++++++++++++++++++++------------------
src/proto_http.c | 19 +++++++----------
4 files changed, 48 insertions(+), 33 deletions(-)
diff --git a/include/types/channel.h b/include/types/channel.h
index 76f1ca0..03bb4e2 100644
--- a/include/types/channel.h
+++ b/include/types/channel.h
@@ -116,7 +116,8 @@
#define CF_NEVER_WAIT 0x08000000 /* never wait for sending data (permanent) */
#define CF_WAKE_ONCE 0x10000000 /* pretend there is activity on this channel (one-shoot) */
-/* unused: 0x20000000, 0x40000000 */
+#define CF_FLT_ANALYZE 0x20000000 /* at least one filter is still analyzing this channel */
+/* unused: 0x40000000 */
#define CF_ISRESP 0x80000000 /* 0 = request channel, 1 = response channel */
/* Masks which define input events for stream analysers */
diff --git a/include/types/proto_http.h b/include/types/proto_http.h
index 66f7397..9987c33 100644
--- a/include/types/proto_http.h
+++ b/include/types/proto_http.h
@@ -68,7 +68,12 @@
#define TX_CACHE_COOK 0x00002000 /* a cookie in the response is cacheable */
#define TX_CACHE_SHIFT 12 /* bit shift */
-/* Unused: 0x4000, 0x8000, 0x10000, 0x20000, 0x80000 */
+/* Unused: 0x4000, 0x8000 */
+
+#define TX_WAIT_CLEANUP 0x0010000 /* this transaction is waiting for a clean up */
+
+/* Unused: 0x20000, 0x80000 */
+
/* indicate how we *want* the connection to behave, regardless of what is in
* the headers. We have 4 possible values right now :
diff --git a/src/filters.c b/src/filters.c
index 9ec794a..fa63991 100644
--- a/src/filters.c
+++ b/src/filters.c
@@ -693,6 +693,9 @@ flt_start_analyze(struct stream *s, struct channel *chn, unsigned int an_bit)
/* If this function is called, this means there is at least one filter,
* so we do not need to check the filter list's emptiness. */
+ /* Set flag on channel to tell that the channel is filtered */
+ chn->flags |= CF_FLT_ANALYZE;
+
RESUME_FILTER_LOOP(s, chn) {
if (!(chn->flags & CF_ISRESP)) {
if (an_bit == AN_REQ_FLT_START_BE &&
@@ -819,6 +822,11 @@ flt_end_analyze(struct stream *s, struct channel *chn, unsigned int an_bit)
{
int ret = 1;
+ /* Check if all filters attached on the stream have finished their
+ * processing on this channel. */
+ if (!(chn->flags & CF_FLT_ANALYZE))
+ goto sync;
+
RESUME_FILTER_LOOP(s, chn) {
FLT_NXT(filter, chn) = 0;
FLT_FWD(filter, chn) = 0;
@@ -831,27 +839,31 @@ flt_end_analyze(struct stream *s, struct channel *chn, unsigned int an_bit)
}
} RESUME_FILTER_END;
-end:
- ret = handle_analyzer_result(s, chn, an_bit, ret);
-
- /* Check if 'channel_end_analyze' callback has been called for the
- * request and the response. */
- if (!(s->req.analysers & AN_REQ_FLT_END) && !(s->res.analysers & AN_RES_FLT_END)) {
- /* When we are waiting for a new request, so we must reset
- * stream analyzers. The input must not be closed the request
- * channel, else it is useless to wait. */
- if (s->txn && (s->txn->flags & TX_WAIT_NEXT_RQ) && !channel_input_closed(&s->req)) {
- s->req.analysers = strm_li(s) ? strm_li(s)->analysers : 0;
- s->res.analysers = 0;
-
- /* Remove backend filters from the list */
- flt_stream_release(s, 1);
- }
-
+ end:
+ /* We don't remove yet this analyzer because we need to synchronize the
+ * both channels. So here, we just remove the flag CF_FLT_ANALYZE. */
+ ret = handle_analyzer_result(s, chn, 0, ret);
+ if (ret)
+ chn->flags &= ~CF_FLT_ANALYZE;
+
+ sync:
+ /* Now we can check if filters have finished their work on the both
+ * channels */
+ if (!(s->req.flags & CF_FLT_ANALYZE) && !(s->res.flags & CF_FLT_ANALYZE)) {
+ /* Sync channels by removing this analyzer for the both channels */
+ s->req.analysers &= ~AN_REQ_FLT_END;
+ s->res.analysers &= ~AN_RES_FLT_END;
+
+ /* Clean up the HTTP transaction if needed */
+ if (s->txn && (s->txn->flags & TX_WAIT_CLEANUP))
+ http_end_txn_clean_session(s);
+
+ /* Remove backend filters from the list */
+ flt_stream_release(s, 1);
}
- else if (ret) {
- /* Analyzer ends only for one channel. So wake up the stream to
- * be sure to process it for the other side as soon as
+ else {
+ /* This analyzer ends only for one channel. So wake up the
+ * stream to be sure to process it for the other side as soon as
* possible. */
task_wakeup(s->task, TASK_WOKEN_MSG);
}
diff --git a/src/proto_http.c b/src/proto_http.c
index 2d567c1..89d335a 100644
--- a/src/proto_http.c
+++ b/src/proto_http.c
@@ -5310,15 +5310,8 @@ void http_end_txn_clean_session(struct stream *s)
else
si_idle_conn(&s->si[1], &srv->idle_conns);
}
-
- if (HAS_FILTERS(s)) {
- s->req.analysers &= AN_REQ_FLT_END;
- s->res.analysers &= AN_RES_FLT_END;
- }
- else {
- s->req.analysers = strm_li(s) ? strm_li(s)->analysers : 0;
- s->res.analysers = 0;
- }
+ s->req.analysers = strm_li(s) ? strm_li(s)->analysers : 0;
+ s->res.analysers = 0;
}
@@ -5674,8 +5667,12 @@ int http_resync_states(struct stream *s)
s->req.flags |= CF_WAKE_WRITE;
else if (channel_congested(&s->res))
s->res.flags |= CF_WAKE_WRITE;
- else
- http_end_txn_clean_session(s);
+ else {
+ s->req.analysers = AN_REQ_FLT_END;
+ s->res.analysers = AN_RES_FLT_END;
+ txn->flags |= TX_WAIT_CLEANUP;
+ return 1;
+ }
}
return txn->req.msg_state != old_req_state ||
--
2.9.3
