Hello,

I discovered an issue with %Ti that appears to date back to when it
was introduced.

If you have TCP content inspection enabled on your frontend, for example:
    stick-table type string len 64 size 100k expire 60s
    tcp-request inspect-delay 1s
    tcp-request content track-sc1 hdr(X-Session)

%Ti will always be -1, because the msg_state is already at
HTTP_MSG_BODY when http_wait_for_request is called for the first time.

It would be great if this could be backported to at least 1.7.

Thanks,
Rian
From 646c3b6714daa0fb1f8e13dd4830549893bb1e80 Mon Sep 17 00:00:00 2001
From: Rian McGuire <[email protected]>
Date: Tue, 24 Apr 2018 11:19:21 -0300
Subject: [PATCH] BUG/MINOR: log: t_idle (%Ti) is not set for some requests

If TCP content inspection is used, msg_state can be >= HTTP_MSG_ERROR
the first time http_wait_for_request is called. t_idle was being left
unset in that case.
---
 src/proto_http.c | 10 ++++------
 1 file changed, 4 insertions(+), 6 deletions(-)

diff --git a/src/proto_http.c b/src/proto_http.c
index 8370889b..6730375e 100644
--- a/src/proto_http.c
+++ b/src/proto_http.c
@@ -1619,18 +1619,16 @@ int http_wait_for_request(struct stream *s, struct channel *req, int an_bit)
 	/* we're speaking HTTP here, so let's speak HTTP to the client */
 	s->srv_error = http_return_srv_error;
 
+	/* If there is data available for analysis, log the end of the idle time. */
+	if (buffer_not_empty(req->buf) && s->logs.t_idle == -1)
+		s->logs.t_idle = tv_ms_elapsed(&s->logs.tv_accept, &now) - s->logs.t_handshake;
+
 	/* There's a protected area at the end of the buffer for rewriting
 	 * purposes. We don't want to start to parse the request if the
 	 * protected area is affected, because we may have to move processed
 	 * data later, which is much more complicated.
 	 */
 	if (buffer_not_empty(req->buf) && msg->msg_state < HTTP_MSG_ERROR) {
-
-		/* This point is executed when some data is avalaible for analysis,
-		 * so we log the end of the idle time. */
-		if (s->logs.t_idle == -1)
-			s->logs.t_idle = tv_ms_elapsed(&s->logs.tv_accept, &now) - s->logs.t_handshake;
-
 		if (txn->flags & TX_NOT_FIRST) {
 			if (unlikely(!channel_is_rewritable(req))) {
 				if (req->flags & (CF_SHUTW|CF_SHUTW_NOW|CF_WRITE_ERROR|CF_WRITE_TIMEOUT))
-- 
2.17.0

Reply via email to