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.

(cherry picked from commit 1cdf2869f6757946546a2ef102ce822e95de78f8)
Signed-off-by: Willy Tarreau <w@1wt.eu>

diff --git a/src/stream.c b/src/stream.c
index 75b08a3..eb88edd 100644 (file)
--- a/src/stream.c
+++ b/src/stream.c
@@ -3287,6 +3287,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 : "";
 
@@ -3437,9 +3438,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,
@@ -3824,6 +3827,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)
@@ -3910,10 +3914,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);