[BUG] http: fix incorrect error reporting during data transfers
We've had several issues related to data transfers. First, if a
client aborted an upload before the server started to respond, it
would get a 502 followed by a 400. The same was true (in the other
way around) if the server suddenly aborted while the client was
uploading the data.
The flags reported in the logs were misleading. Request errors could
be reported while the transfer was stopped during the data phase. The
status codes could also be overwritten by a 400 eventhough the start
of the response was transferred to the client.
The stats were also wrong in case of data aborts. The server or the
client could sometimes be miscredited for being the author of the
abort depending on where the abort was detected. Some client aborts
could also be accounted as request errors and some server aborts as
response errors.
Now it seems like all such issues are fixed. Since we don't have a
specific state for data flowing from the client to the server
before the server responds, we're still counting the client aborted
transfers as "CH", and they become "CD" when the server starts to
respond. Ideally a "P" state would be desired.
This patch should be backported to 1.4.
diff --git a/doc/configuration.txt b/doc/configuration.txt
index af23d31..6f30014 100644
--- a/doc/configuration.txt
+++ b/doc/configuration.txt
@@ -8792,11 +8792,20 @@
so that it does not happen anymore. This status is very rare and
might happen when the global "ulimit-n" parameter is forced by hand.
+ PD The proxy blocked an incorrectly formatted chunked encoded message in
+ a request or a response, after the server has emitted its headers. In
+ most cases, this will indicate an invalid message from the server to
+ the client.
+
PH The proxy blocked the server's response, because it was invalid,
incomplete, dangerous (cache control), or matched a security filter.
In any case, an HTTP 502 error is sent to the client. One possible
cause for this error is an invalid syntax in an HTTP header name
- containing unauthorized characters.
+ containing unauthorized characters. It is also possible but quite
+ rare, that the proxy blocked a chunked-encoding request from the
+ client due to an invalid syntax, before the server responded. In this
+ case, an HTTP 400 error is sent to the client and reported in the
+ logs.
PR The proxy blocked the client's HTTP request, either because of an
invalid HTTP syntax, in which case it returned an HTTP 400 error to
diff --git a/src/proto_http.c b/src/proto_http.c
index ed31323..4e9f206 100644
--- a/src/proto_http.c
+++ b/src/proto_http.c
@@ -4428,10 +4428,7 @@
/* request errors are most likely due to
* the server aborting the transfer.
*/
- if (!(s->flags & SN_ERR_MASK))
- s->flags |= SN_ERR_SRVCL;
- if (!(s->flags & SN_FINST_MASK))
- s->flags |= SN_FINST_D;
+ goto aborted_xfer;
}
if (msg->err_pos >= 0)
http_capture_bad_message(&s->fe->invalid_req, s, req, msg, old_state, s->be);
@@ -4468,19 +4465,25 @@
if (req->flags & BF_SHUTR) {
if (!(s->flags & SN_ERR_MASK))
s->flags |= SN_ERR_CLICL;
- if (!(s->flags & SN_FINST_MASK))
- s->flags |= SN_FINST_D;
- goto return_bad_req;
+ if (!(s->flags & SN_FINST_MASK)) {
+ if (txn->rsp.msg_state < HTTP_MSG_ERROR)
+ s->flags |= SN_FINST_H;
+ else
+ s->flags |= SN_FINST_D;
+ }
+
+ s->fe->counters.cli_aborts++;
+ if (s->fe != s->be)
+ s->be->counters.cli_aborts++;
+ if (s->srv)
+ s->srv->counters.cli_aborts++;
+
+ goto return_bad_req_stats_ok;
}
/* waiting for the last bits to leave the buffer */
- if (req->flags & BF_SHUTW) {
- if (!(s->flags & SN_ERR_MASK))
- s->flags |= SN_ERR_SRVCL;
- if (!(s->flags & SN_FINST_MASK))
- s->flags |= SN_FINST_D;
- goto return_bad_req;
- }
+ if (req->flags & BF_SHUTW)
+ goto aborted_xfer;
/* When TE: chunked is used, we need to get there again to parse remaining
* chunks even if the client has closed, so we don't want to set BF_DONTCLOSE.
@@ -4492,20 +4495,57 @@
return 0;
return_bad_req: /* let's centralize all bad requests */
- txn->req.msg_state = HTTP_MSG_ERROR;
- txn->status = 400;
- /* Note: we don't send any error if some data were already sent */
- stream_int_retnclose(req->prod, (txn->rsp.msg_state < HTTP_MSG_BODY) ? error_message(s, HTTP_ERR_400) : NULL);
- req->analysers = 0;
s->fe->counters.failed_req++;
if (s->listener->counters)
s->listener->counters->failed_req++;
+ return_bad_req_stats_ok:
+ txn->req.msg_state = HTTP_MSG_ERROR;
+ if (txn->status) {
+ /* Note: we don't send any error if some data were already sent */
+ stream_int_retnclose(req->prod, NULL);
+ } else {
+ txn->status = 400;
+ stream_int_retnclose(req->prod, error_message(s, HTTP_ERR_400));
+ }
+ req->analysers = 0;
+ s->rep->analysers = 0; /* we're in data phase, we want to abort both directions */
if (!(s->flags & SN_ERR_MASK))
s->flags |= SN_ERR_PRXCOND;
- if (!(s->flags & SN_FINST_MASK))
- s->flags |= SN_FINST_R;
- http_silent_debug(__LINE__, s);
+ if (!(s->flags & SN_FINST_MASK)) {
+ if (txn->rsp.msg_state < HTTP_MSG_ERROR)
+ s->flags |= SN_FINST_H;
+ else
+ s->flags |= SN_FINST_D;
+ }
+ return 0;
+
+ aborted_xfer:
+ txn->req.msg_state = HTTP_MSG_ERROR;
+ if (txn->status) {
+ /* Note: we don't send any error if some data were already sent */
+ stream_int_retnclose(req->prod, NULL);
+ } else {
+ txn->status = 502;
+ stream_int_retnclose(req->prod, error_message(s, HTTP_ERR_502));
+ }
+ req->analysers = 0;
+ s->rep->analysers = 0; /* we're in data phase, we want to abort both directions */
+
+ s->fe->counters.srv_aborts++;
+ if (s->fe != s->be)
+ s->be->counters.srv_aborts++;
+ if (s->srv)
+ s->srv->counters.srv_aborts++;
+
+ if (!(s->flags & SN_ERR_MASK))
+ s->flags |= SN_ERR_SRVCL;
+ if (!(s->flags & SN_FINST_MASK)) {
+ if (txn->rsp.msg_state < HTTP_MSG_ERROR)
+ s->flags |= SN_FINST_H;
+ else
+ s->flags |= SN_FINST_D;
+ }
return 0;
}
@@ -5429,10 +5469,7 @@
/* response errors are most likely due to
* the client aborting the transfer.
*/
- if (!(s->flags & SN_ERR_MASK))
- s->flags |= SN_ERR_CLICL;
- if (!(s->flags & SN_FINST_MASK))
- s->flags |= SN_FINST_D;
+ goto aborted_xfer;
}
if (msg->err_pos >= 0)
http_capture_bad_message(&s->be->invalid_rep, s, res, msg, old_state, s->fe);
@@ -5452,9 +5489,12 @@
s->be->counters.srv_aborts++;
if (s->srv)
s->srv->counters.srv_aborts++;
- goto return_bad_res;
+ goto return_bad_res_stats_ok;
}
+ if (res->flags & BF_SHUTW)
+ goto aborted_xfer;
+
/* we need to obey the req analyser, so if it leaves, we must too */
if (!s->req->analysers)
goto return_bad_res;
@@ -5481,21 +5521,42 @@
return 0;
return_bad_res: /* let's centralize all bad responses */
+ s->be->counters.failed_resp++;
+ if (s->srv)
+ s->srv->counters.failed_resp++;
+
+ return_bad_res_stats_ok:
txn->rsp.msg_state = HTTP_MSG_ERROR;
/* don't send any error message as we're in the body */
stream_int_retnclose(res->cons, NULL);
res->analysers = 0;
- s->be->counters.failed_resp++;
- if (s->srv) {
- s->srv->counters.failed_resp++;
+ s->req->analysers = 0; /* we're in data phase, we want to abort both directions */
+ if (s->srv)
health_adjust(s->srv, HANA_STATUS_HTTP_HDRRSP);
- }
if (!(s->flags & SN_ERR_MASK))
s->flags |= SN_ERR_PRXCOND;
if (!(s->flags & SN_FINST_MASK))
s->flags |= SN_FINST_D;
- http_silent_debug(__LINE__, s);
+ return 0;
+
+ aborted_xfer:
+ txn->rsp.msg_state = HTTP_MSG_ERROR;
+ /* don't send any error message as we're in the body */
+ stream_int_retnclose(res->cons, NULL);
+ res->analysers = 0;
+ s->req->analysers = 0; /* we're in data phase, we want to abort both directions */
+
+ s->fe->counters.cli_aborts++;
+ if (s->fe != s->be)
+ s->be->counters.cli_aborts++;
+ if (s->srv)
+ s->srv->counters.cli_aborts++;
+
+ if (!(s->flags & SN_ERR_MASK))
+ s->flags |= SN_ERR_CLICL;
+ if (!(s->flags & SN_FINST_MASK))
+ s->flags |= SN_FINST_D;
return 0;
}