diff --git a/doc/configuration.txt b/doc/configuration.txt index 1348891bb..3853d406f 100644 --- a/doc/configuration.txt +++ b/doc/configuration.txt @@ -18243,6 +18243,7 @@ Please refer to the table below for currently defined variables : | H | %Tr | Tr (response time) | numeric | | | %Ts | timestamp | numeric | | | %Tt | Tt | numeric | + | | %Tu | Tu | numeric | | | %Tw | Tw | numeric | | | %U | bytes_uploaded (from client to server) | numeric | | | %ac | actconn | numeric | @@ -18410,6 +18411,7 @@ Timings events in HTTP mode: : Th Ti TR Tw Tc Tr Td : Ti ... :<---- Tq ---->: : :<-------------- Tt -------------->: + :<-- -----Tu--------------->: :<--------- Ta --------->: Timings events in TCP mode: @@ -18506,6 +18508,15 @@ Timings events in TCP mode: mode, "Ti", "Tq" and "Tr" have to be excluded too. Note that "Tt" can never be negative and that for HTTP, Tt is simply equal to (Th+Ti+Ta). + - Tu: total estimated time as seen from client, between the moment the proxy + accepted it and the moment both ends were closed, without idle time. + This is useful to roughly measure end-to-end time as a user would see it, + without idle time pollution from keep-alive time between requests. This + timer in only an estimation of time seen by user as it assumes network + latency is the same in both directions. The exception is when the "logasap" + option is specified. In this case, it only equals (Th+TR+Tw+Tc+Tr), and is + prefixed with a '+' sign. + These timers provide precious indications on trouble causes. Since the TCP protocol defines retransmit delays of 3, 6, 12... seconds, we know for sure that timers close to multiples of 3s are nearly always related to lost packets diff --git a/include/types/log.h b/include/types/log.h index c348caa1e..868c08f01 100644 --- a/include/types/log.h +++ b/include/types/log.h @@ -104,6 +104,7 @@ enum { LOG_FMT_TR, LOG_FMT_TD, LOG_FMT_TT, + LOG_FMT_TU, LOG_FMT_STATUS, LOG_FMT_CCLIENT, LOG_FMT_CSERVER, diff --git a/src/log.c b/src/log.c index bacc04ed5..5d672942c 100644 --- a/src/log.c +++ b/src/log.c @@ -152,6 +152,7 @@ static const struct logformat_type logformat_keywords[] = { { "Td", LOG_FMT_TD, PR_MODE_TCP, LW_BYTES, NULL }, /* Td = Tt - (Tq + Tw + Tc + Tr) */ { "Ts", LOG_FMT_TS, PR_MODE_TCP, LW_INIT, NULL }, /* timestamp GMT */ { "Tt", LOG_FMT_TT, PR_MODE_TCP, LW_BYTES, NULL }, /* Tt */ + { "Tu", LOG_FMT_TU, PR_MODE_TCP, LW_BYTES, NULL }, /* Tu = Tt -Ti */ { "Tw", LOG_FMT_TW, PR_MODE_TCP, LW_BYTES, NULL }, /* Tw */ { "U", LOG_FMT_BYTES_UP, PR_MODE_TCP, LW_BYTES, NULL }, /* bytes from client to server */ { "ac", LOG_FMT_ACTCONN, PR_MODE_TCP, LW_BYTES, NULL }, /* actconn */ @@ -2460,6 +2461,17 @@ int sess_build_logline(struct session *sess, struct stream *s, char *dst, size_t last_isspace = 0; break; + case LOG_FMT_TU: // %Tu = total time seen by user = Tt - Ti + if (!(fe->to_log & LW_BYTES)) + LOGCHAR('+'); + ret = ltoa_o(logs->t_close - (logs->t_idle >= 0 ? logs->t_idle : 0), + tmplog, dst + maxsize - tmplog); + if (ret == NULL) + goto out; + tmplog = ret; + last_isspace = 0; + break; + case LOG_FMT_STATUS: // %ST ret = ltoa_o(txn ? txn->status : 0, tmplog, dst + maxsize - tmplog); if (ret == NULL)