changeset 21874:02be39ae109d

lib-http: client: Implemented means to obtain request statistics.
author Stephan Bosch <stephan.bosch@dovecot.fi>
date Wed, 29 Mar 2017 01:25:21 +0200
parents ed955a3b0766
children 7c51ff56653a
files src/lib-http/http-client-connection.c src/lib-http/http-client-request.c src/lib-http/http-client.h
diffstat 3 files changed, 114 insertions(+), 29 deletions(-) [+]
line wrap: on
line diff
--- a/src/lib-http/http-client-connection.c	Fri Mar 31 23:12:47 2017 +0300
+++ b/src/lib-http/http-client-connection.c	Wed Mar 29 01:25:21 2017 +0200
@@ -222,40 +222,14 @@
 http_client_connection_get_timing_info(struct http_client_connection *conn)
 {
 	struct http_client_request *const *requestp;
-	unsigned int sent_msecs, total_msecs, connected_msecs;
+	unsigned int connected_msecs;
 	string_t *str = t_str_new(64);
 
 	if (array_count(&conn->request_wait_list) > 0) {
 		requestp = array_idx(&conn->request_wait_list, 0);
-		sent_msecs = timeval_diff_msecs(&ioloop_timeval, &(*requestp)->sent_time);
-		total_msecs = timeval_diff_msecs(&ioloop_timeval, &(*requestp)->submit_time);
 
-		str_printfa(str, "Request sent %u.%03u secs ago",
-			    sent_msecs/1000, sent_msecs%1000);
-		if ((*requestp)->attempts > 0) {
-			str_printfa(str, ", %u attempts in %u.%03u secs",
-				    (*requestp)->attempts + 1,
-				    total_msecs/1000, total_msecs%1000);
-		}
-		int other_ioloop_msecs = (ioloop_global_wait_usecs -
-			(*requestp)->sent_global_ioloop_usecs + 999) / 1000;
-		if (conn->client->ioloop != NULL) {
-			int http_ioloop_msecs =
-				(io_wait_timer_get_usecs(conn->io_wait_timer) -
-				 (*requestp)->sent_http_ioloop_usecs + 999) / 1000;
-			other_ioloop_msecs -= http_ioloop_msecs;
-			str_printfa(str, ", %d.%03d in http ioloop",
-				    http_ioloop_msecs/1000, http_ioloop_msecs%1000);
-		}
-		str_printfa(str, ", %d.%03d in other ioloops",
-			    other_ioloop_msecs/1000, other_ioloop_msecs%1000);
-
-		int lock_msecs = (file_lock_wait_get_total_usecs() -
-				  (*requestp)->sent_lock_usecs + 999) / 1000;
-		if (lock_msecs > 0) {
-			str_printfa(str, ", %d.%03d in locks",
-				    lock_msecs/1000, lock_msecs%1000);
-		}
+		str_append(str, "Request ");
+		http_client_request_append_stats_text(*requestp, str);
 	} else {
 		str_append(str, "No requests");
 		if (conn->conn.last_input != 0) {
--- a/src/lib-http/http-client-request.c	Fri Mar 31 23:12:47 2017 +0300
+++ b/src/lib-http/http-client-request.c	Wed Mar 29 01:25:21 2017 +0200
@@ -582,6 +582,93 @@
 	return req->state;
 }
 
+void http_client_request_get_stats(struct http_client_request *req,
+	struct http_client_request_stats *stats_r)
+{
+	struct http_client *client = req->client;
+	int diff_msecs;
+	uint64_t wait_usecs;
+
+	i_zero(stats_r);
+	if (!req->submitted)
+		return;
+
+	/* total elapsed time since message was submitted */
+	diff_msecs = timeval_diff_msecs(&ioloop_timeval, &req->submit_time);
+	stats_r->total_msecs = (unsigned int)I_MAX(diff_msecs, 0);
+
+	/* elapsed time since message was last sent */
+	if (req->sent_time.tv_sec > 0) {
+		diff_msecs = timeval_diff_msecs(&ioloop_timeval, &req->sent_time);
+		stats_r->sent_msecs = (unsigned int)I_MAX(diff_msecs, 0);
+	}
+
+	if (req->conn != NULL) {
+		/* time spent in other ioloops */
+		i_assert(ioloop_global_wait_usecs >= req->sent_global_ioloop_usecs);
+		stats_r->other_ioloop_msecs = (unsigned int)
+			(ioloop_global_wait_usecs - req->sent_global_ioloop_usecs + 999) / 1000;
+
+		/* time spent in the http-client's own ioloop */
+		if (client->ioloop != NULL) {
+			wait_usecs = io_wait_timer_get_usecs(req->conn->io_wait_timer);
+			i_assert(wait_usecs >= req->sent_http_ioloop_usecs);
+			stats_r->http_ioloop_msecs = (unsigned int)
+				(wait_usecs - req->sent_http_ioloop_usecs + 999) / 1000;
+
+			i_assert(stats_r->other_ioloop_msecs >= stats_r->http_ioloop_msecs);
+			stats_r->other_ioloop_msecs -= stats_r->http_ioloop_msecs;
+		}
+	}
+
+	/* total time spent on waiting for file locks */
+	wait_usecs = file_lock_wait_get_total_usecs();
+	i_assert(wait_usecs >= req->sent_lock_usecs);
+	stats_r->lock_msecs = (unsigned int)
+		(wait_usecs - req->sent_lock_usecs + 999) / 1000;
+
+	/* number of attempts for this request */
+	stats_r->attempts = req->attempts;
+
+}
+
+void http_client_request_append_stats_text(struct http_client_request *req,
+	string_t *str)
+{
+	struct http_client_request_stats stats;
+
+	if (!req->submitted) {
+		str_append(str, "not yet submitted");
+		return;
+	}
+
+	http_client_request_get_stats(req, &stats);
+
+	if (stats.sent_msecs > 0) {
+		str_printfa(str, "sent %u.%03u secs ago",
+			    stats.sent_msecs/1000, stats.sent_msecs%1000);
+	} else {
+		str_append(str, "not yet sent");
+	}
+	if (stats.attempts > 0) {
+		str_printfa(str, ", %u attempts in %u.%03u secs",
+			    stats.attempts + 1,
+			    stats.total_msecs/1000, stats.total_msecs%1000);
+	}
+	if (stats.http_ioloop_msecs > 0) {
+		str_printfa(str, ", %u.%03u in http ioloop",
+			    stats.http_ioloop_msecs/1000,
+			    stats.http_ioloop_msecs%1000);
+	}
+	str_printfa(str, ", %u.%03u in other ioloops",
+		    stats.other_ioloop_msecs/1000, stats.other_ioloop_msecs%1000);
+
+	if (stats.lock_msecs > 0) {
+		str_printfa(str, ", %u.%03u in locks",
+			    stats.lock_msecs/1000, stats.lock_msecs%1000);
+	}
+}
+
 enum http_response_payload_type
 http_client_request_get_payload_type(struct http_client_request *req)
 {
--- a/src/lib-http/http-client.h	Fri Mar 31 23:12:47 2017 +0300
+++ b/src/lib-http/http-client.h	Wed Mar 29 01:25:21 2017 +0200
@@ -183,6 +183,23 @@
 	struct ostream *output;
 };
 
+struct http_client_request_stats {
+	/* Total elapsed time since message was submitted */
+	unsigned int total_msecs;
+	/* Elapsed time since message was last sent */
+	unsigned int sent_msecs;
+
+	/* Time spent in other ioloops */
+	unsigned int other_ioloop_msecs;
+	/* Time spent in the http-client's own ioloop */
+	unsigned int http_ioloop_msecs;
+	/* Total time spent on waiting for file locks */
+	unsigned int lock_msecs;
+
+	/* Number of attempts for this request */
+	unsigned int attempts;
+};
+
 typedef void
 http_client_request_callback_t(const struct http_response *response,
 			       void *context);
@@ -347,6 +364,13 @@
 http_client_request_get_state(const struct http_client_request *req)
 	ATTR_PURE;
 
+/* get statistics for the request */
+void http_client_request_get_stats(struct http_client_request *req,
+	struct http_client_request_stats *stats);
+/* append text with request statistics to provided string buffer */
+void http_client_request_append_stats_text(struct http_client_request *req,
+	string_t *str);
+
 /* submit the request. It is queued for transmission to the service */
 void http_client_request_submit(struct http_client_request *req);