From: Willy Tarreau <w@1wt.eu>
Date: Thu, 6 Mar 2025 17:56:13 +0000 (+0100)
Subject: BUG/MINOR: stream: fix age calculation in "show sess" output
X-Git-Tag: v3.2-dev7~17
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=1cdf2869f6757946546a2ef102ce822e95de78f8;p=thirdparty%2Fhaproxy.git

BUG/MINOR: stream: fix age calculation in "show sess" output

The "show sess" output reports an age that's based on the last byte of
the HTTP request instead of the stream creation date, due to a confusion
between logs->request_ts and the request_date sample fetch function. Most
of the time these are equal except when the request is not yet full for
any reason (e.g. wait-body). This explains why a few "show sess" could
report a few new streams aged by 99 days for example.

Let's perform the correct request timestamp calculation like the sample
fetch function does, by adding t_idle and t_handshake to the accept_ts.
Now the stream's age is correct and can be correctly used with the
"show sess older <age>" variant.

This issue was introduced in 2.9 and the fix can be backported to 3.0.
---

diff --git a/src/stream.c b/src/stream.c
index 833a51370..b489a32c3 100644
--- a/src/stream.c
+++ b/src/stream.c
@@ -3297,6 +3297,7 @@ static void __strm_dump_to_buffer(struct buffer *buf, const struct show_sess_ctx
 	char pn[INET6_ADDRSTRLEN];
 	struct connection *conn;
 	struct appctx *tmpctx;
+	uint64_t request_ts;
 
 	pfx = pfx ? pfx : "";
 
@@ -3458,9 +3459,11 @@ static void __strm_dump_to_buffer(struct buffer *buf, const struct show_sess_ctx
 	             ha_thread_info[strm->task->tid].ltid,
 		     task_in_rq(strm->task) ? ", running" : "");
 
+	request_ts = strm->logs.accept_ts;
+	request_ts += ms_to_ns(strm->logs.t_idle >= 0 ? strm->logs.t_idle + strm->logs.t_handshake : 0);
 	chunk_appendf(buf,
-		     " age=%s)\n",
-		     human_time(ns_to_sec(now_ns) - ns_to_sec(strm->logs.request_ts), 1));
+		      " age=%s)\n",
+		      human_time(ns_to_sec(now_ns) - ns_to_sec(request_ts), 1));
 
 	if (strm->txn) {
 		chunk_appendf(buf,
@@ -3845,6 +3848,7 @@ static int cli_io_handler_dump_sess(struct appctx *appctx)
 	while (1) {
 		char pn[INET6_ADDRSTRLEN];
 		struct stream *curr_strm;
+		uint64_t request_ts;
 		int done= 0;
 
 		if (ctx->bref.ref == &ha_thread_ctx[ctx->thr].streams)
@@ -3931,10 +3935,12 @@ static int cli_io_handler_dump_sess(struct appctx *appctx)
 			break;
 		}
 
+		request_ts = curr_strm->logs.accept_ts;
+		request_ts += ms_to_ns(curr_strm->logs.t_idle >= 0 ? curr_strm->logs.t_idle + curr_strm->logs.t_handshake : 0);
 		chunk_appendf(&trash,
 			     " ts=%02x epoch=%#x age=%s calls=%u rate=%u cpu=%llu lat=%llu",
 		             curr_strm->task->state, curr_strm->stream_epoch,
-		             human_time(ns_to_sec(now_ns) - ns_to_sec(curr_strm->logs.request_ts), 1),
+		             human_time(ns_to_sec(now_ns) - ns_to_sec(request_ts), 1),
 		             curr_strm->task->calls, read_freq_ctr(&curr_strm->call_rate),
 		             (unsigned long long)curr_strm->cpu_time, (unsigned long long)curr_strm->lat_time);