changeset 21928:d8719e363c86

lib-http: Improve request stats text. It's important to know how long the request was in queue before it was sent. Also the "n attempts in m secs" makes more sense if it was counting only the time after the initial request was sent, not including the queuing time. If there is more than 1 attempt, log separately how long all the attempts were waited on vs. how long the last attempt took.
author Timo Sirainen <timo.sirainen@dovecot.fi>
date Mon, 10 Apr 2017 13:02:17 +0300
parents 5d2bc1c47fd0
children f778045077e6
files src/lib-http/http-client-request.c
diffstat 1 files changed, 13 insertions(+), 8 deletions(-) [+]
line wrap: on
line diff
--- a/src/lib-http/http-client-request.c	Mon Apr 10 12:59:08 2017 +0300
+++ b/src/lib-http/http-client-request.c	Mon Apr 10 13:02:17 2017 +0300
@@ -650,17 +650,22 @@
 
 	http_client_request_get_stats(req, &stats);
 
-	if (stats.last_sent_msecs > 0) {
-		str_printfa(str, "sent %u.%03u secs ago",
-			    stats.last_sent_msecs/1000, stats.last_sent_msecs%1000);
-	} else {
-		str_append(str, "not yet sent");
-	}
-	if (stats.attempts > 0) {
+	str_printfa(str, "queued %u.%03u secs ago",
+		    stats.total_msecs/1000, stats.total_msecs%1000);
+
+	if (stats.first_sent_msecs == 0)
+		str_append(str, ", not yet sent");
+	else {
 		str_printfa(str, ", %u attempts in %u.%03u secs",
 			    stats.attempts + 1,
-			    stats.total_msecs/1000, stats.total_msecs%1000);
+			    stats.first_sent_msecs/1000, stats.first_sent_msecs%1000);
+		if (stats.attempts > 0) {
+			str_printfa(str, ", %u.%03u in last attempt",
+				    stats.last_sent_msecs/1000,
+				    stats.last_sent_msecs%1000);
+		}
 	}
+
 	if (stats.http_ioloop_msecs > 0) {
 		str_printfa(str, ", %u.%03u in http ioloop",
 			    stats.http_ioloop_msecs/1000,