Mercurial > dovecot > core-2.2
changeset 21087:3b909cd1264b
lib-index: Improve error messages when transaction log is unexpectedly lost
author | Timo Sirainen <timo.sirainen@dovecot.fi> |
---|---|
date | Fri, 11 Nov 2016 17:00:39 +0200 |
parents | 9e3dcad11d5f |
children | 617c400a8324 |
files | src/lib-index/mail-index-map-read.c src/lib-index/mail-index-private.h src/lib-index/mail-index-sync-private.h src/lib-index/mail-index-sync-update.c src/lib-index/mail-index.c src/lib-index/mail-transaction-log-view.c |
diffstat | 6 files changed, 59 insertions(+), 17 deletions(-) [+] |
line wrap: on
line diff
--- a/src/lib-index/mail-index-map-read.c Thu Nov 10 23:00:59 2016 +0200 +++ b/src/lib-index/mail-index-map-read.c Fri Nov 11 17:00:39 2016 +0200 @@ -296,7 +296,8 @@ /* returns -1 = error, 0 = index files are unusable, 1 = index files are usable or at least repairable */ -static int mail_index_map_latest_file(struct mail_index *index) +static int +mail_index_map_latest_file(struct mail_index *index, const char **reason_r) { struct mail_index_map *old_map, *new_map; struct stat st; @@ -305,7 +306,9 @@ const char *error; int ret, try; - ret = mail_index_reopen_if_changed(index); + *reason_r = NULL; + + ret = mail_index_reopen_if_changed(index, reason_r); if (ret <= 0) { if (ret < 0) return -1; @@ -361,6 +364,7 @@ } T_END; if (ret != 0 || try == 2) { if (ret < 0) { + *reason_r = "Corrupted index file"; unusable = TRUE; ret = 0; } @@ -391,12 +395,14 @@ mail_index_unmap(&index->map); index->map = new_map; + *reason_r = "Index mapped"; return 1; } int mail_index_map(struct mail_index *index, enum mail_index_sync_handler_type type) { + const char *reason; int ret; i_assert(!index->mapping); @@ -410,7 +416,7 @@ if (index->initial_mapped) { /* we're not creating/opening the index. sync this as a view from transaction log. */ - ret = mail_index_sync_map(&index->map, type, FALSE); + ret = mail_index_sync_map(&index->map, type, FALSE, "initial mapping"); } else { ret = 0; } @@ -421,7 +427,7 @@ logs (which we'll also do even if the reopening succeeds). if index files are unusable (e.g. major version change) don't even try to use the transaction log. */ - ret = mail_index_map_latest_file(index); + ret = mail_index_map_latest_file(index, &reason); if (ret > 0) { /* if we're creating the index file, we don't have any logs yet */ @@ -429,7 +435,7 @@ /* and update the map with the latest changes from transaction log */ ret = mail_index_sync_map(&index->map, type, - TRUE); + TRUE, reason); } } else if (ret == 0 && !index->readonly) { /* make sure we don't try to open the file again */
--- a/src/lib-index/mail-index-private.h Thu Nov 10 23:00:59 2016 +0200 +++ b/src/lib-index/mail-index-private.h Fri Nov 11 17:00:39 2016 +0200 @@ -257,7 +257,8 @@ int mail_index_try_open_only(struct mail_index *index); void mail_index_close_file(struct mail_index *index); -int mail_index_reopen_if_changed(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);
--- a/src/lib-index/mail-index-sync-private.h Thu Nov 10 23:00:59 2016 +0200 +++ b/src/lib-index/mail-index-sync-private.h Fri Nov 11 17:00:39 2016 +0200 @@ -53,7 +53,8 @@ enum mail_index_sync_handler_type type); void mail_index_sync_map_deinit(struct mail_index_sync_map_ctx *sync_map_ctx); int mail_index_sync_map(struct mail_index_map **map, - enum mail_index_sync_handler_type type, bool force); + enum mail_index_sync_handler_type type, bool force, + const char *sync_reason); int mail_index_sync_record(struct mail_index_sync_map_ctx *ctx, const struct mail_transaction_header *hdr,
--- a/src/lib-index/mail-index-sync-update.c Thu Nov 10 23:00:59 2016 +0200 +++ b/src/lib-index/mail-index-sync-update.c Fri Nov 11 17:00:39 2016 +0200 @@ -899,7 +899,8 @@ #endif int mail_index_sync_map(struct mail_index_map **_map, - enum mail_index_sync_handler_type type, bool force) + enum mail_index_sync_handler_type type, bool force, + const char *sync_reason) { struct mail_index_map *map = *_map; struct mail_index *index = map->index; @@ -963,8 +964,10 @@ if (force && ret == 0) { /* the seq/offset is probably broken */ mail_index_set_error(index, "Index %s: Lost log for " - "seq=%u offset=%"PRIuUOFF_T": %s", index->filepath, - map->hdr.log_file_seq, start_offset, reason); + "seq=%u offset=%"PRIuUOFF_T": %s " + "(initial_mapped=%d, reason=%s)", index->filepath, + map->hdr.log_file_seq, start_offset, reason, + index->initial_mapped, sync_reason); (void)mail_index_fsck(index); } /* can't use it. sync by re-reading index. */
--- a/src/lib-index/mail-index.c Thu Nov 10 23:00:59 2016 +0200 +++ b/src/lib-index/mail-index.c Fri Nov 11 17:00:39 2016 +0200 @@ -689,21 +689,27 @@ } } -int mail_index_reopen_if_changed(struct mail_index *index) +int mail_index_reopen_if_changed(struct mail_index *index, + const char **reason_r) { struct stat st1, st2; + int ret; - if (MAIL_INDEX_IS_IN_MEMORY(index)) + if (MAIL_INDEX_IS_IN_MEMORY(index)) { + *reason_r = "in-memory index"; return 0; + } if (index->fd == -1) - return mail_index_try_open_only(index); + goto final; if ((index->flags & MAIL_INDEX_OPEN_FLAG_NFS_FLUSH) != 0) nfs_flush_file_handle_cache(index->filepath); if (nfs_safe_stat(index->filepath, &st2) < 0) { - if (errno == ENOENT) + if (errno == ENOENT) { + *reason_r = "index not found via stat()"; return 0; + } mail_index_set_syscall_error(index, "stat()"); return -1; } @@ -714,17 +720,26 @@ return -1; } /* deleted/recreated, reopen */ + *reason_r = "index is stale"; } else if (st1.st_ino == st2.st_ino && CMP_DEV_T(st1.st_dev, st2.st_dev)) { /* the same file */ + *reason_r = "index unchanged"; return 1; + } else { + *reason_r = "index inode changed"; } /* new file, new locks. the old fd can keep its locks, they don't matter anymore as no-one's going to modify the file. */ mail_index_close_file(index); - return mail_index_try_open_only(index); +final: + if ((ret = mail_index_try_open_only(index)) == 0) + *reason_r = "index not found via open()"; + else if (ret > 0) + *reason_r = "index opened"; + return ret; } int mail_index_refresh(struct mail_index *index)
--- a/src/lib-index/mail-transaction-log-view.c Thu Nov 10 23:00:59 2016 +0200 +++ b/src/lib-index/mail-transaction-log-view.c Fri Nov 11 17:00:39 2016 +0200 @@ -2,6 +2,7 @@ #include "lib.h" #include "array.h" +#include "str.h" #include "mail-index-private.h" #include "mail-transaction-log-view-private.h" @@ -58,6 +59,20 @@ i_free(view); } +static const char * +mail_transaction_log_get_file_seqs(struct mail_transaction_log *log) +{ + struct mail_transaction_log_file *file; + string_t *str = t_str_new(32); + + if (log->files == NULL) + return ""; + + for (file = log->files; file != NULL; file = file->next) + str_printfa(str, ",%u", file->hdr.file_seq); + return str_c(str) + 1; +} + int mail_transaction_log_view_set(struct mail_transaction_log_view *view, uint32_t min_file_seq, uoff_t min_file_offset, uint32_t max_file_seq, uoff_t max_file_offset, @@ -176,8 +191,9 @@ file->hdr.file_seq > max_file_seq) { /* missing files in the middle */ *reason_r = t_strdup_printf( - "Missing middle file seq=%u (between %u..%u)", - seq, min_file_seq, max_file_seq); + "Missing middle file seq=%u (between %u..%u, we have seqs %s)", + seq, min_file_seq, max_file_seq, + mail_transaction_log_get_file_seqs(view->log)); return 0; }