lib-index: Log a debug message with reason whenever recreating dovecot.index

diff --git a/src/lib-index/mail-index-fsck.c b/src/lib-index/mail-index-fsck.c
index a8157c241bbd73ceb7a18a68cd1c4cbfbc4ca099..9147eebc2c79f911b526cb7cb2847e23ad2670ee 100644 (file)
--- a/src/lib-index/mail-index-fsck.c
+++ b/src/lib-index/mail-index-fsck.c
@@ -472,7 +472,7 @@ int mail_index_fsck(struct mail_index *index)
                mail_index_fsck_map(index, map);
        } T_END;
 
-       mail_index_write(index, FALSE);
+       mail_index_write(index, FALSE, "fscking");
 
        if (!orig_locked)
                mail_transaction_log_sync_unlock(index->log, "fscking");

diff --git a/src/lib-index/mail-index-private.h b/src/lib-index/mail-index-private.h
index dfe29297a02052f3e1b3cecd239ef2ea549940a0..67e63d2a7fd63b7a9c2674d1f2de53e5b6fb65b3 100644 (file)
--- a/src/lib-index/mail-index-private.h
+++ b/src/lib-index/mail-index-private.h
@@ -249,7 +249,8 @@ void mail_index_close_file(struct mail_index *index);
 int mail_index_reopen_if_changed(struct mail_index *index,
                                 const char **reason_r);
 /* Update/rewrite the main index file from index->map */
-void mail_index_write(struct mail_index *index, bool want_rotate);
+void mail_index_write(struct mail_index *index, bool want_rotate,
+                     const char *reason);
 
 void mail_index_flush_read_cache(struct mail_index *index, const char *path,
                                 int fd, bool locked);

diff --git a/src/lib-index/mail-index-sync.c b/src/lib-index/mail-index-sync.c
index a8237bd27f6b314a32f6639fd786b1ba1e16ea19..d90fcbcc74f5c17925a3392bd909d9e324515e35 100644 (file)
--- a/src/lib-index/mail-index-sync.c
+++ b/src/lib-index/mail-index-sync.c
@@ -830,7 +830,7 @@ mail_index_sync_update_mailbox_offset(struct mail_index_sync_ctx *ctx)
        }
 }
 
-static bool mail_index_sync_want_index_write(struct mail_index *index)
+static bool mail_index_sync_want_index_write(struct mail_index *index, const char **reason_r)
 {
        uint32_t log_diff;
 
@@ -839,18 +839,35 @@ static bool mail_index_sync_want_index_write(struct mail_index *index)
                /* dovecot.index points to an old .log file. we were supposed
                   to rewrite the dovecot.index when rotating the log, so
                   we shouldn't usually get here. */
+               *reason_r = "points to old .log file";
                return TRUE;
        }
 
        log_diff = index->map->hdr.log_file_tail_offset -
                index->last_read_log_file_tail_offset;
-       if (log_diff > index->optimization_set.index.rewrite_max_log_bytes ||
-           (index->index_min_write &&
-            log_diff > index->optimization_set.index.rewrite_min_log_bytes))
+       if (log_diff > index->optimization_set.index.rewrite_max_log_bytes) {
+               *reason_r = t_strdup_printf(
+                       ".log read %u..%u > rewrite_max_log_bytes %"PRIuUOFF_T,
+                       index->map->hdr.log_file_tail_offset,
+                       index->last_read_log_file_tail_offset,
+                       index->optimization_set.index.rewrite_max_log_bytes);
                return TRUE;
+       }
+       if (index->index_min_write &&
+           log_diff > index->optimization_set.index.rewrite_min_log_bytes) {
+               *reason_r = t_strdup_printf(
+                       ".log read %u..%u > rewrite_min_log_bytes %"PRIuUOFF_T,
+                       index->map->hdr.log_file_tail_offset,
+                       index->last_read_log_file_tail_offset,
+                       index->optimization_set.index.rewrite_min_log_bytes);
+               return TRUE;
+       }
 
-       if (index->need_recreate != NULL)
+       if (index->need_recreate != NULL) {
+               *reason_r = t_strdup_printf("Need to recreate index: %s",
+                                           index->need_recreate);
                return TRUE;
+       }
        return FALSE;
 }
 
@@ -859,6 +876,7 @@ int mail_index_sync_commit(struct mail_index_sync_ctx **_ctx)
         struct mail_index_sync_ctx *ctx = *_ctx;
        struct mail_index *index = ctx->index;
        struct mail_cache_compress_lock *cache_lock = NULL;
+       const char *reason = NULL;
        uint32_t next_uid;
        bool want_rotate, index_undeleted, delete_index;
        int ret = 0, ret2;
@@ -956,12 +974,12 @@ int mail_index_sync_commit(struct mail_index_sync_ctx **_ctx)
           However, it's still safe to do the rotation because external
           transactions don't require syncing. */
        want_rotate = ctx->fully_synced &&
-               mail_transaction_log_want_rotate(index->log);
+               mail_transaction_log_want_rotate(index->log, &reason);
        if (ret == 0 &&
-           (want_rotate || mail_index_sync_want_index_write(index))) {
+           (want_rotate || mail_index_sync_want_index_write(index, &reason))) {
                i_free(index->need_recreate);
                index->index_min_write = FALSE;
-               mail_index_write(index, want_rotate);
+               mail_index_write(index, want_rotate, reason);
        }
        mail_index_sync_end(_ctx);
        return ret;

diff --git a/src/lib-index/mail-index-write.c b/src/lib-index/mail-index-write.c
index 473c4e1805fb9790ba746d6f6f2142a62c1f3d87..791cf9f1ce06890b3619f09363bbb721cd435aaa 100644 (file)
--- a/src/lib-index/mail-index-write.c
+++ b/src/lib-index/mail-index-write.c
@@ -116,7 +116,8 @@ static int mail_index_recreate(struct mail_index *index)
        return ret;
 }
 
-void mail_index_write(struct mail_index *index, bool want_rotate)
+void mail_index_write(struct mail_index *index, bool want_rotate,
+                     const char *reason)
 {
        struct mail_index_header *hdr = &index->map->hdr;
 
@@ -152,6 +153,8 @@ void mail_index_write(struct mail_index *index, bool want_rotate)
        }
 
        if (!MAIL_INDEX_IS_IN_MEMORY(index)) {
+               e_debug(index->event, "Recreating %s because: %s",
+                       index->filepath, reason);
                if (mail_index_recreate(index) < 0) {
                        (void)mail_index_move_to_memory(index);
                        return;

diff --git a/src/lib-index/mail-transaction-log-private.h b/src/lib-index/mail-transaction-log-private.h
index 79e800fda4b7d6c28b99bf00bf463ce0246ee75e..27202bd033de4e02bb43b2fcfaafb078313a4591 100644 (file)
--- a/src/lib-index/mail-transaction-log-private.h
+++ b/src/lib-index/mail-transaction-log-private.h
@@ -131,7 +131,8 @@ int mail_transaction_log_file_move_to_memory(struct mail_transaction_log_file *f
 
 void mail_transaction_logs_clean(struct mail_transaction_log *log);
 
-bool mail_transaction_log_want_rotate(struct mail_transaction_log *log);
+bool mail_transaction_log_want_rotate(struct mail_transaction_log *log,
+                                     const char **reason_r);
 int mail_transaction_log_rotate(struct mail_transaction_log *log, bool reset);
 int mail_transaction_log_lock_head(struct mail_transaction_log *log,
                                   const char *lock_reason);

diff --git a/src/lib-index/mail-transaction-log.c b/src/lib-index/mail-transaction-log.c
index 1133a83bb018017e7a86dcba1ad99137f642e884..87c861f9f96581711684ba44a407af8f32789201 100644 (file)
--- a/src/lib-index/mail-transaction-log.c
+++ b/src/lib-index/mail-transaction-log.c
@@ -231,22 +231,31 @@ void mail_transaction_logs_clean(struct mail_transaction_log *log)
        i_assert(log->head == NULL || log->files != NULL);
 }
 
-bool mail_transaction_log_want_rotate(struct mail_transaction_log *log)
+bool mail_transaction_log_want_rotate(struct mail_transaction_log *log,
+                                     const char **reason_r)
 {
        struct mail_transaction_log_file *file = log->head;
 
-       if (file->need_rotate)
+       if (file->need_rotate != NULL) {
+               *reason_r = t_strdup(file->need_rotate);
                return TRUE;
+       }
 
        if (file->hdr.major_version < MAIL_TRANSACTION_LOG_MAJOR_VERSION ||
            (file->hdr.major_version == MAIL_TRANSACTION_LOG_MAJOR_VERSION &&
             file->hdr.minor_version < MAIL_TRANSACTION_LOG_MINOR_VERSION)) {
                /* upgrade immediately to a new log file format */
+               *reason_r = t_strdup_printf(
+                       ".log file format version %u.%u is too old",
+                       file->hdr.major_version, file->hdr.minor_version);
                return TRUE;
        }
 
        if (file->sync_offset > log->index->optimization_set.log.max_size) {
                /* file is too large, definitely rotate */
+               *reason_r = t_strdup_printf(
+                       ".log file size %"PRIuUOFF_T" > max_size %"PRIuUOFF_T,
+                       file->sync_offset, log->index->optimization_set.log.max_size);
                return TRUE;
        }
        if (file->sync_offset < log->index->optimization_set.log.min_size) {
@@ -254,8 +263,15 @@ bool mail_transaction_log_want_rotate(struct mail_transaction_log *log)
                return FALSE;
        }
        /* rotate if the timestamp is old enough */
-       return file->hdr.create_stamp <
-               ioloop_time - log->index->optimization_set.log.min_age_secs;
+       if (file->hdr.create_stamp <
+           ioloop_time - log->index->optimization_set.log.min_age_secs) {
+               *reason_r = t_strdup_printf(
+                       ".log create_stamp %u is older than %u secs",
+                       file->hdr.create_stamp,
+                       log->index->optimization_set.log.min_age_secs);
+               return TRUE;
+       }
+       return FALSE;
 }
 
 int mail_transaction_log_rotate(struct mail_transaction_log *log, bool reset)