From: Timo Sirainen <timo.sirainen@dovecot.fi>
Date: Mon, 16 May 2016 21:00:43 +0000 (+0300)
Subject: imap: Include sync timing information in tagged command replies.
X-Git-Tag: 2.3.0.rc1~3734
X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=5ceeb24b0d12e3368a78e17ce4b14d1c900fb223;p=thirdparty%2Fdovecot%2Fcore.git

imap: Include sync timing information in tagged command replies.
Show it only when it's larger than 0 to avoid unnecessary output.
---

diff --git a/src/imap/imap-client.c b/src/imap/imap-client.c
index 6392d5ff76..b504601564 100644
--- a/src/imap/imap-client.c
+++ b/src/imap/imap-client.c
@@ -480,6 +480,7 @@ client_cmd_append_timing_stats(struct client_command_context *cmd,
 {
 	unsigned int msecs_in_cmd, msecs_in_ioloop;
 	uint64_t ioloop_wait_usecs;
+	unsigned int msecs_since_cmd;
 
 	if (cmd->start_time.tv_sec == 0)
 		return;
@@ -488,12 +489,19 @@ client_cmd_append_timing_stats(struct client_command_context *cmd,
 	msecs_in_cmd = (cmd->running_usecs + 999) / 1000;
 	msecs_in_ioloop = (ioloop_wait_usecs -
 			   cmd->start_ioloop_wait_usecs + 999) / 1000;
+	msecs_since_cmd = timeval_diff_msecs(&ioloop_timeval,
+					     &cmd->last_run_timeval);
 
 	if (str_data(str)[str_len(str)-1] == '.')
 		str_truncate(str, str_len(str)-1);
-	str_printfa(str, " (%d.%03d + %d.%03d secs).",
+	str_printfa(str, " (%d.%03d + %d.%03d ",
 		    msecs_in_cmd / 1000, msecs_in_cmd % 1000,
 		    msecs_in_ioloop / 1000, msecs_in_ioloop % 1000);
+	if (msecs_since_cmd > 0) {
+		str_printfa(str, "+ %d.%03d ",
+			    msecs_since_cmd / 1000, msecs_since_cmd % 1000);
+	}
+	str_append(str, "secs).");
 }
 
 void client_send_tagline(struct client_command_context *cmd, const char *data)
@@ -721,6 +729,7 @@ struct client_command_context *client_command_alloc(struct client *client)
 	cmd->client = client;
 	cmd->pool = client->command_pool;
 	cmd->start_time = ioloop_timeval;
+	cmd->last_run_timeval = ioloop_timeval;
 	cmd->start_ioloop_wait_usecs = io_loop_get_wait_usecs(current_ioloop);
 	p_array_init(&cmd->module_contexts, cmd->pool, 5);
 
diff --git a/src/imap/imap-client.h b/src/imap/imap-client.h
index 394b59cc19..9b5415e26f 100644
--- a/src/imap/imap-client.h
+++ b/src/imap/imap-client.h
@@ -79,6 +79,9 @@ struct client_command_context {
 	/* time when command handling was started - typically this is after
 	   reading all the parameters. */
 	struct timeval start_time;
+	/* time when command handling was last finished. this is before
+	   mailbox syncing is done. */
+	struct timeval last_run_timeval;
 	/* io_loop_get_wait_usecs()'s value when the command was started */
 	uint64_t start_ioloop_wait_usecs;
 	/* how many usecs this command itself has spent running */
diff --git a/src/imap/imap-sync.c b/src/imap/imap-sync.c
index 50ef1f3048..27f31d0543 100644
--- a/src/imap/imap-sync.c
+++ b/src/imap/imap-sync.c
@@ -762,6 +762,7 @@ bool cmd_sync(struct client_command_context *cmd, enum mailbox_sync_flags flags,
 	if (cmd->cancel)
 		return TRUE;
 
+	cmd->last_run_timeval = ioloop_timeval;
 	if (client->mailbox == NULL) {
 		/* no mailbox selected, no point in delaying the sync */
 		if (tagline != NULL)