imap: Include info about last command in disconnection log line.

Only if LOGOUT isn't sent, because that's already visible.

diff --git a/src/imap/imap-client.c b/src/imap/imap-client.c
index 7917a053b6467234a5ecbef7b32826c9f54b8af7..516f23f560c1adad75eaa1d9b7b13d15f1df9c6d 100644 (file)
--- a/src/imap/imap-client.c
+++ b/src/imap/imap-client.c
@@ -26,6 +26,10 @@
 
 #include <unistd.h>
 
+/* If the last command took longer than this to run, log statistics on
+   where the time was spent. */
+#define IMAP_CLIENT_DISCONNECT_LOG_STATS_CMD_MIN_RUNNING_MSECS 1000
+
 extern struct mail_storage_callbacks mail_storage_callbacks;
 extern struct imap_client_vfuncs imap_client_vfuncs;
 
@@ -298,6 +302,33 @@ client_command_stats_append(string_t *str,
        str_append(str, " B out");
 }
 
+static const char *client_get_last_command_status(struct client *client)
+{
+       if (client->logged_out)
+               return "";
+       if (client->last_cmd_name == NULL)
+               return " (No commands sent)";
+
+       /* client disconnected without sending LOGOUT. if the last command
+          took over 1 second to run, log it. */
+       const struct client_command_stats *stats = &client->last_cmd_stats;
+
+       string_t *str = t_str_new(128);
+       int last_run_secs = timeval_diff_msecs(&ioloop_timeval,
+                                              &stats->last_run_timeval);
+       str_printfa(str, " (%s finished %d.%03d secs ago",
+                   client->last_cmd_name, last_run_secs/1000,
+                   last_run_secs%1000);
+
+       if (timeval_diff_msecs(&stats->last_run_timeval, &stats->start_time) >=
+           IMAP_CLIENT_DISCONNECT_LOG_STATS_CMD_MIN_RUNNING_MSECS) {
+               str_append(str, " - ");
+               client_command_stats_append(str, stats, "", 0);
+       }
+       str_append_c(str, ')');
+       return str_c(str);
+}
+
 static const char *client_get_commands_status(struct client *client)
 {
        struct client_command_context *cmd, *last_cmd = NULL;
@@ -307,7 +338,7 @@ static const char *client_get_commands_status(struct client *client)
        const char *cond_str;
 
        if (client->command_queue == NULL)
-               return "";
+               return client_get_last_command_status(client);
 
        i_zero(&all_stats);
        str = t_str_new(128);
@@ -328,7 +359,7 @@ static const char *client_get_commands_status(struct client *client)
                last_cmd = cmd;
        }
        if (last_cmd == NULL)
-               return "";
+               return client_get_last_command_status(client);
 
        cond = io_loop_find_fd_conditions(current_ioloop, client->fd_out);
        if ((cond & (IO_READ | IO_WRITE)) == (IO_READ | IO_WRITE))
@@ -435,6 +466,8 @@ static void client_default_destroy(struct client *client, const char *reason)
 
        imap_client_count--;
        DLLIST_REMOVE(&imap_clients, client);
+
+       i_free(client->last_cmd_name);
        pool_unref(&client->pool);
 
        master_service_client_connection_destroyed(master_service);
@@ -815,6 +848,10 @@ void client_command_free(struct client_command_context **_cmd)
                client_send_tagline(cmd, "NO Command cancelled.");
        }
 
+       i_free(client->last_cmd_name);
+       client->last_cmd_name = i_strdup(cmd->name);
+       client->last_cmd_stats = cmd->stats;
+
        if (!cmd->param_error)
                client->bad_counter = 0;
 

diff --git a/src/imap/imap-client.h b/src/imap/imap-client.h
index a8ae2d7d042a05407c485377fe1d023d8888a40d..b363b3e5895ceb266c1076d83d7c3d5c9ffa273c 100644 (file)
--- a/src/imap/imap-client.h
+++ b/src/imap/imap-client.h
@@ -159,6 +159,9 @@ struct client {
        struct client_command_context *command_queue;
        unsigned int command_queue_size;
 
+       char *last_cmd_name;
+       struct client_command_stats last_cmd_stats;
+
        uint64_t sync_last_full_modseq;
        uint64_t highest_fetch_modseq;
        ARRAY_TYPE(seq_range) fetch_failed_uids;