imap: Add debug logging for [un]hibernation

The logs should now clearly say when a client was hibernated and when/why
it was was unhibernated.

diff --git a/src/imap/imap-client-hibernate.c b/src/imap/imap-client-hibernate.c
index 492895e9b507a03a4e90f334eb7e7be64d73fbf2..1ebe7fb4f873ade7cda8b0a9013b2092dc49e0c2 100644 (file)
--- a/src/imap/imap-client-hibernate.c
+++ b/src/imap/imap-client-hibernate.c
@@ -238,6 +238,11 @@ bool imap_client_hibernate(struct client **_client)
        if (ret > 0) {
                /* hide the disconnect log message, because the client didn't
                   actually log out */
+               if (client->user->mail_debug) {
+                       i_debug("Successfully hibernated imap client in mailbox %s",
+                               client->mailbox == NULL ? "<none>" :
+                               mailbox_get_vname(client->mailbox));
+               }
                client->disconnected = TRUE;
                client->hibernated = TRUE;
                client_destroy(client, NULL);

diff --git a/src/imap/imap-fetch.c b/src/imap/imap-fetch.c
index 1c09b3d47e872604355628f9c6346e5ad54fc0ec..e72284a36fc82857b8d6c8a8d515d986836d0ad7 100644 (file)
--- a/src/imap/imap-fetch.c
+++ b/src/imap/imap-fetch.c
@@ -542,6 +542,7 @@ static int imap_fetch_more_int(struct imap_fetch_context *ctx, bool cancel)
 
                        str_printfa(state->cur_str, "* %u FETCH (",
                                    state->cur_mail->seq);
+                       ctx->fetched_mails_count++;
                        state->cur_first = TRUE;
                        state->cur_str_prefix_size = str_len(state->cur_str);
                        i_assert(!state->line_partial);

diff --git a/src/imap/imap-fetch.h b/src/imap/imap-fetch.h
index 8f5fd5c3867255d62c7e5227acb36ee3d2841226..5397d057b6696afcd407691c1e6b9986b3de9d8e 100644 (file)
--- a/src/imap/imap-fetch.h
+++ b/src/imap/imap-fetch.h
@@ -90,6 +90,7 @@ struct imap_fetch_context {
 
        struct imap_fetch_state state;
        ARRAY_TYPE(seq_range) fetch_failed_uids;
+       unsigned int fetched_mails_count;
 
        enum mail_error error;
        const char *errstr;

diff --git a/src/imap/imap-master-client.c b/src/imap/imap-master-client.c
index be71b4c6583e64facf9ed1a466409725bb5c82ab..54b9f520ee324c672de095878a4277ffe79ad0e2 100644 (file)
--- a/src/imap/imap-master-client.c
+++ b/src/imap/imap-master-client.c
@@ -6,7 +6,9 @@
 #include "istream-unix.h"
 #include "ostream.h"
 #include "base64.h"
+#include "str.h"
 #include "strescape.h"
+#include "str-sanitize.h"
 #include "master-service.h"
 #include "mail-storage-service.h"
 #include "imap-client.h"
@@ -257,6 +259,15 @@ imap_master_client_input_args(struct connection *conn, const char *const *args,
                master_input.state_import_bad_idle_done;
        imap_client->state_import_idle_continue =
                master_input.state_import_idle_continue;
+       if (imap_client->user->mail_debug) {
+               if (imap_client->state_import_bad_idle_done)
+                       i_debug("imap-master: Unhibernated because IDLE was stopped with BAD command");
+               else if (imap_client->state_import_idle_continue)
+                       i_debug("imap-master: Unhibernated to send mailbox changes");
+               else
+                       i_debug("imap-master: Unhibernated because IDLE was stopped with DONE");
+       }
+
        ret = imap_state_import_internal(imap_client, master_input.state->data,
                                         master_input.state->used, &error);
        if (ret <= 0) {
@@ -271,6 +282,10 @@ imap_master_client_input_args(struct connection *conn, const char *const *args,
        /* make sure all pending input gets handled */
        i_assert(imap_client->to_delayed_input == NULL);
        if (master_input.client_input->used > 0) {
+               if (imap_client->user->mail_debug) {
+                       i_debug("imap-master: Pending client input: '%s'",
+                               str_sanitize(str_c(master_input.client_input), 128));
+               }
                imap_client->to_delayed_input =
                        timeout_add(0, client_input, imap_client);
        }

diff --git a/src/imap/imap-state.c b/src/imap/imap-state.c
index 8e0afdd9b046fd8b7f6039568e7d59acfbc8b90b..50ee3b54391bea5202a0a8d2b7b25802e1b4e5f1 100644 (file)
--- a/src/imap/imap-state.c
+++ b/src/imap/imap-state.c
@@ -448,7 +448,8 @@ import_send_expunges(struct client *client,
 
 static int
 import_send_flag_changes(struct client *client,
-                        const struct mailbox_import_state *state)
+                        const struct mailbox_import_state *state,
+                        unsigned int *flag_change_count_r)
 {
        struct imap_fetch_context *fetch_ctx;
        struct mail_search_args *search_args;
@@ -456,6 +457,7 @@ import_send_flag_changes(struct client *client,
        pool_t pool;
        int ret;
 
+       *flag_change_count_r = 0;
        if (state->messages == 0)
                return 0;
 
@@ -485,6 +487,7 @@ import_send_flag_changes(struct client *client,
        while (imap_fetch_more_no_lock_update(fetch_ctx) == 0) ;
 
        ret = imap_fetch_end(fetch_ctx);
+       *flag_change_count_r = fetch_ctx->fetched_mails_count;
        imap_fetch_free(&fetch_ctx);
        return ret;
 }
@@ -560,7 +563,7 @@ import_state_mailbox_open(struct client *client,
         struct mailbox_status status;
        const struct seq_range *range;
        enum mailbox_flags flags = 0;
-       unsigned int expunge_count;
+       unsigned int expunge_count, new_mails_count = 0, flag_change_count = 0;
        uint32_t uid;
        int ret = 0;
 
@@ -656,6 +659,8 @@ import_state_mailbox_open(struct client *client,
 
        if (state->messages - expunge_count < client->messages_count) {
                /* new messages arrived */
+               new_mails_count = client->messages_count -
+                       (state->messages - expunge_count);
                client_send_line(client,
                        t_strdup_printf("* %u EXISTS", client->messages_count));
                client_send_line(client,
@@ -669,7 +674,7 @@ import_state_mailbox_open(struct client *client,
        } else {
                client_send_mailbox_flags(client, TRUE);
        }
-       if (import_send_flag_changes(client, state) < 0) {
+       if (import_send_flag_changes(client, state, &flag_change_count) < 0) {
                *error_r = "Couldn't send flag changes";
                return -1;
        }
@@ -681,6 +686,9 @@ import_state_mailbox_open(struct client *client,
                        (unsigned long long)status.highest_modseq));
                client->sync_last_full_modseq = status.highest_modseq;
        }
+       i_debug("Unhibernation sync: %u expunges, %u new messages, %u flag changes, %"PRIu64" modseq changes",
+               expunge_count, new_mails_count, flag_change_count,
+               status.highest_modseq - state->highest_modseq);
        return 0;
 }