Mercurial > dovecot > core-2.2
changeset 18398:8146fdc0de34
lib-index: Added reason_r parameter to mail_transaction_log_view_set()
This is used to improve some of the error messages about index corruption.
author | Timo Sirainen <tss@iki.fi> |
---|---|
date | Mon, 06 Apr 2015 12:07:32 +0900 |
parents | ee001c131952 |
children | 6bde7868cffd |
files | src/doveadm/dsync/dsync-transaction-log-scan.c src/lib-index/mail-index-modseq.c src/lib-index/mail-index-sync-update.c src/lib-index/mail-index-sync.c src/lib-index/mail-index-view-sync.c src/lib-index/mail-transaction-log-view.c src/lib-index/mail-transaction-log.h src/lib-index/test-mail-transaction-log-view.c src/lib-storage/mailbox-get.c src/lib-storage/test-mailbox-get.c |
diffstat | 10 files changed, 81 insertions(+), 39 deletions(-) [+] |
line wrap: on
line diff
--- a/src/doveadm/dsync/dsync-transaction-log-scan.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/doveadm/dsync/dsync-transaction-log-scan.c Mon Apr 06 12:07:32 2015 +0900 @@ -350,6 +350,7 @@ { uint32_t log_seq, end_seq; uoff_t log_offset, end_offset; + const char *reason; bool reset; int ret; @@ -371,7 +372,7 @@ ret = mail_transaction_log_view_set(log_view, log_seq, log_offset, end_seq, end_offset, - &reset); + &reset, &reason); if (ret != 0) return ret; } @@ -390,13 +391,14 @@ } ret = mail_transaction_log_view_set(log_view, log_seq, log_offset, - end_seq, end_offset, &reset); + end_seq, end_offset, + &reset, &reason); if (ret == 0) { /* we shouldn't get here. _view_set_all() already reserved all the log files, the _view_set() only removed unwanted ones. */ - i_error("%s: Couldn't set transaction log view (seq %u..%u)", - view->index->filepath, log_seq, end_seq); + i_error("%s: Couldn't set transaction log view (seq %u..%u): %s", + view->index->filepath, log_seq, end_seq, reason); ret = -1; } if (ret < 0) @@ -566,6 +568,7 @@ struct mail_transaction_log_view *log_view; const struct mail_transaction_header *hdr; const void *data; + const char *reason; bool reset, found = FALSE; i_assert(uid > 0); @@ -578,7 +581,7 @@ scan->last_log_seq, scan->last_log_offset, (uint32_t)-1, (uoff_t)-1, - &reset) > 0) { + &reset, &reason) > 0) { while (!found && mail_transaction_log_view_next(log_view, &hdr, &data) > 0) { switch (hdr->type & MAIL_TRANSACTION_TYPE_MASK) {
--- a/src/lib-index/mail-index-modseq.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-index/mail-index-modseq.c Mon Apr 06 12:07:32 2015 +0900 @@ -403,6 +403,7 @@ const struct mail_index_modseq_header *hdr; const struct mail_transaction_header *thdr; const void *tdata; + const char *reason; uint32_t ext_map_idx; uint32_t end_seq; uoff_t end_offset; @@ -437,12 +438,12 @@ ret = mail_transaction_log_view_set(ctx->log_view, I_MAX(1, hdr->log_seq), hdr->log_offset, - end_seq, end_offset, &reset); + end_seq, end_offset, &reset, &reason); if (ret <= 0) { /* missing files / error - try with only the last file */ ret = mail_transaction_log_view_set(ctx->log_view, end_seq, 0, end_seq, end_offset, - &reset); + &reset, &reason); /* since we don't know if we skipped some changes, set all modseqs to beginning of the latest file. */ cur_modseq = mail_transaction_log_view_get_prev_modseq(
--- a/src/lib-index/mail-index-sync-update.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-index/mail-index-sync-update.c Mon Apr 06 12:07:32 2015 +0900 @@ -911,6 +911,7 @@ const void *tdata; uint32_t prev_seq; uoff_t start_offset, prev_offset; + const char *reason; int ret; bool had_dirty, reset; @@ -952,14 +953,15 @@ view = mail_index_view_open_with_map(index, map); ret = mail_transaction_log_view_set(view->log_view, map->hdr.log_file_seq, start_offset, - (uint32_t)-1, (uoff_t)-1, &reset); + (uint32_t)-1, (uoff_t)-1, + &reset, &reason); if (ret <= 0) { mail_index_view_close(&view); 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, index->filepath, - map->hdr.log_file_seq, start_offset); + "seq=%u offset=%"PRIuUOFF_T": %s", index->filepath, + map->hdr.log_file_seq, start_offset, reason); (void)mail_index_fsck(index); } /* can't use it. sync by re-reading index. */
--- a/src/lib-index/mail-index-sync.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-index/mail-index-sync.c Mon Apr 06 12:07:32 2015 +0900 @@ -284,6 +284,7 @@ { uint32_t log_seq; uoff_t log_offset; + const char *reason; bool reset; int ret; @@ -291,15 +292,15 @@ ret = mail_transaction_log_view_set(view->log_view, start_file_seq, start_file_offset, - log_seq, log_offset, &reset); + log_seq, log_offset, &reset, &reason); if (ret < 0) return -1; if (ret == 0) { /* either corrupted or the file was deleted for some reason. either way, we can't go forward */ mail_index_set_error(view->index, - "Unexpected transaction log desync with index %s", - view->index->filepath); + "Unexpected transaction log desync with index %s: %s", + view->index->filepath, reason); return 0; } return 1; @@ -529,6 +530,7 @@ const void *data; uint32_t log_seq; uoff_t log_offset; + const char *reason; bool reset; int ret; @@ -544,7 +546,8 @@ if (mail_transaction_log_view_set(view->log_view, view->map->hdr.log_file_seq, view->map->hdr.log_file_tail_offset, - log_seq, log_offset, &reset) <= 0) { + log_seq, log_offset, + &reset, &reason) <= 0) { /* let the actual syncing handle the error */ return TRUE; }
--- a/src/lib-index/mail-index-view-sync.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-index/mail-index-view-sync.c Mon Apr 06 12:07:32 2015 +0900 @@ -48,6 +48,7 @@ const struct mail_index_header *hdr = &view->index->map->hdr; uint32_t start_seq, end_seq; uoff_t start_offset, end_offset; + const char *reason; int ret; start_seq = view->log_file_expunge_seq; @@ -71,7 +72,7 @@ ret = mail_transaction_log_view_set(view->log_view, start_seq, start_offset, end_seq, end_offset, - reset_r); + reset_r, &reason); if (ret <= 0) return ret; @@ -489,7 +490,9 @@ struct mail_index_view *view = ctx->view; uint32_t seq; uoff_t offset; + const char *reason; bool reset; + int ret; /* replace the view's map */ view->index->map->refcount++; @@ -501,9 +504,15 @@ view->log_file_head_offset = offset = view->map->hdr.log_file_head_offset; - if (mail_transaction_log_view_set(view->log_view, seq, offset, - seq, offset, &reset) <= 0) + ret = mail_transaction_log_view_set(view->log_view, seq, offset, + seq, offset, &reset, &reason); + if (ret < 0) return -1; + if (ret == 0) { + mail_index_set_error(view->index, "Failed to fix view for %s: %s", + view->index->filepath, reason); + return 0; + } view->inconsistent = FALSE; return 0; }
--- a/src/lib-index/mail-transaction-log-view.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-index/mail-transaction-log-view.c Mon Apr 06 12:07:32 2015 +0900 @@ -61,7 +61,7 @@ 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, - bool *reset_r) + bool *reset_r, const char **reason_r) { struct mail_transaction_log_file *file, *const *files; uoff_t start_offset, end_offset; @@ -70,10 +70,12 @@ int ret; *reset_r = FALSE; + *reason_r = NULL; if (view->log == NULL) { /* transaction log is closed already. this log view shouldn't be used anymore. */ + *reason_r = "Log already closed"; return -1; } @@ -82,6 +84,9 @@ start from the beginning */ if (view->log->files->hdr.prev_file_seq != 0) { /* but it doesn't */ + *reason_r = t_strdup_printf( + "Wanted log beginning, but found prev_file_seq=%u", + view->log->files->hdr.prev_file_seq); return 0; } @@ -124,10 +129,11 @@ if (min_file_seq == max_file_seq && min_file_offset > max_file_offset) { /* log file offset is probably corrupted in the index file. */ - mail_transaction_log_view_set_corrupted(view, - "file_seq=%u, min_file_offset (%"PRIuUOFF_T + *reason_r = t_strdup_printf( + "Invalid offset: file_seq=%u, min_file_offset (%"PRIuUOFF_T ") > max_file_offset (%"PRIuUOFF_T")", min_file_seq, min_file_offset, max_file_offset); + mail_transaction_log_view_set_corrupted(view, "%s", *reason_r); return -1; } @@ -142,8 +148,11 @@ ret = mail_transaction_log_find_file(view->log, seq, nfs_flush, &file); if (ret <= 0) { - if (ret < 0) + if (ret < 0) { + *reason_r = t_strdup_printf( + "Failed to find file seq=%u", seq); return -1; + } /* not found / corrupted */ file = NULL; @@ -166,6 +175,9 @@ if (file == NULL || 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); return 0; } @@ -198,18 +210,20 @@ if (min_file_offset < view->tail->hdr.hdr_size) { /* log file offset is probably corrupted in the index file. */ - mail_transaction_log_view_set_corrupted(view, - "file_seq=%u, min_file_offset (%"PRIuUOFF_T + *reason_r = t_strdup_printf( + "Invalid min_file_offset: file_seq=%u, min_file_offset (%"PRIuUOFF_T ") < hdr_size (%u)", min_file_seq, min_file_offset, view->tail->hdr.hdr_size); + mail_transaction_log_view_set_corrupted(view, "%s", *reason_r); return -1; } if (max_file_offset < view->head->hdr.hdr_size) { /* log file offset is probably corrupted in the index file. */ - mail_transaction_log_view_set_corrupted(view, - "file_seq=%u, min_file_offset (%"PRIuUOFF_T + *reason_r = t_strdup_printf( + "Invalid max_file_offset: file_seq=%u, min_file_offset (%"PRIuUOFF_T ") < hdr_size (%u)", max_file_seq, max_file_offset, view->head->hdr.hdr_size); + mail_transaction_log_view_set_corrupted(view, "%s", *reason_r); return -1; } @@ -246,8 +260,13 @@ max_file_offset : (uoff_t)-1; ret = mail_transaction_log_file_map(file, start_offset, end_offset); - if (ret <= 0) + if (ret <= 0) { + *reason_r = t_strdup_printf( + "Failed to map file seq=%u " + "offset=%"PRIuUOFF_T"..%"PRIuUOFF_T" (ret=%d)", + file->hdr.file_seq, start_offset, end_offset, ret); return ret; + } if (file->hdr.prev_file_seq == 0) { /* this file resets the index. @@ -266,10 +285,11 @@ if (min_file_seq == view->head->hdr.file_seq && min_file_offset > view->head->sync_offset) { /* log file offset is probably corrupted in the index file. */ - mail_transaction_log_view_set_corrupted(view, - "file_seq=%u, min_file_offset (%"PRIuUOFF_T + *reason_r = t_strdup_printf( + "Invalid offset: file_seq=%u, min_file_offset (%"PRIuUOFF_T ") > sync_offset (%"PRIuUOFF_T")", min_file_seq, min_file_offset, view->head->sync_offset); + mail_transaction_log_view_set_corrupted(view, "%s", *reason_r); return -1; } @@ -292,8 +312,10 @@ view->broken = FALSE; if (mail_transaction_log_file_get_highest_modseq_at(view->cur, - view->cur_offset, &view->prev_modseq) < 0) + view->cur_offset, &view->prev_modseq) < 0) { + *reason_r = "Failed to get modseq"; return -1; + } i_assert(view->cur_offset <= view->cur->sync_offset); return 1;
--- a/src/lib-index/mail-transaction-log.h Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-index/mail-transaction-log.h Mon Apr 06 12:07:32 2015 +0900 @@ -227,7 +227,7 @@ 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, - bool *reset_r); + bool *reset_r, const char **reason_r); /* Scan through all of the log files that we can find. Returns -1 if error, 0 if ok. */ int mail_transaction_log_view_set_all(struct mail_transaction_log_view *view);
--- a/src/lib-index/test-mail-transaction-log-view.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-index/test-mail-transaction-log-view.c Mon Apr 06 12:07:32 2015 +0900 @@ -124,6 +124,7 @@ void *oldfile; uint32_t seq; uoff_t offset, last_log_size; + const char *reason; bool reset; test_begin("init"); @@ -151,7 +152,7 @@ /* we have files 1-3 opened */ test_begin("set all"); - test_assert(mail_transaction_log_view_set(view, 0, 0, (uint32_t)-1, (uoff_t)-1, &reset) == 1 && + test_assert(mail_transaction_log_view_set(view, 0, 0, (uint32_t)-1, (uoff_t)-1, &reset, &reason) == 1 && reset && view_is_file_refed(1) && view_is_file_refed(2) && view_is_file_refed(3) && !mail_transaction_log_view_is_corrupted(view)); @@ -168,7 +169,7 @@ test_end(); test_begin("set first"); - test_assert(mail_transaction_log_view_set(view, 0, 0, 0, 0, &reset) == 1); + test_assert(mail_transaction_log_view_set(view, 0, 0, 0, 0, &reset, &reason) == 1); mail_transaction_log_view_get_prev_pos(view, &seq, &offset); test_assert(seq == 1 && offset == sizeof(struct mail_transaction_log_header)); test_assert(mail_transaction_log_view_next(view, &hdr, &data) == 0); @@ -177,7 +178,7 @@ test_end(); test_begin("set end"); - test_assert(mail_transaction_log_view_set(view, 3, last_log_size, (uint32_t)-1, (uoff_t)-1, &reset) == 1); + test_assert(mail_transaction_log_view_set(view, 3, last_log_size, (uint32_t)-1, (uoff_t)-1, &reset, &reason) == 1); mail_transaction_log_view_get_prev_pos(view, &seq, &offset); test_assert(seq == 3 && offset == last_log_size); test_assert(mail_transaction_log_view_next(view, &hdr, &data) == 0); @@ -199,16 +200,16 @@ /* --- first file has been removed --- */ test_begin("set 2-3"); - test_assert(mail_transaction_log_view_set(view, 2, 0, (uint32_t)-1, (uoff_t)-1, &reset) == 1); + test_assert(mail_transaction_log_view_set(view, 2, 0, (uint32_t)-1, (uoff_t)-1, &reset, &reason) == 1); test_end(); test_begin("missing log handing"); - test_assert(mail_transaction_log_view_set(view, 0, 0, (uint32_t)-1, (uoff_t)-1, &reset) == 0); + test_assert(mail_transaction_log_view_set(view, 0, 0, (uint32_t)-1, (uoff_t)-1, &reset, &reason) == 0); test_end(); test_begin("closed log handling"); view->log = NULL; - test_assert(mail_transaction_log_view_set(view, 0, 0, (uint32_t)-1, (uoff_t)-1, &reset) == -1); + test_assert(mail_transaction_log_view_set(view, 0, 0, (uint32_t)-1, (uoff_t)-1, &reset, &reason) == -1); view->log = log; test_end();
--- a/src/lib-storage/mailbox-get.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-storage/mailbox-get.c Mon Apr 06 12:07:32 2015 +0900 @@ -71,6 +71,7 @@ struct mail_transaction_log_view *log_view; uint32_t log_seq, tail_seq = 0; uoff_t log_offset; + const char *reason; bool reset; int ret; @@ -90,14 +91,14 @@ ret = mail_transaction_log_view_set(log_view, log_seq, log_offset, box->view->log_file_head_seq, box->view->log_file_head_offset, - &reset); + &reset, &reason); if (ret == 0) { mail_transaction_log_get_tail(box->index->log, &tail_seq); i_assert(tail_seq > log_seq); ret = mail_transaction_log_view_set(log_view, tail_seq, 0, box->view->log_file_head_seq, box->view->log_file_head_offset, - &reset); + &reset, &reason); i_assert(ret != 0); } if (ret <= 0) {
--- a/src/lib-storage/test-mailbox-get.c Mon Apr 06 11:39:34 2015 +0900 +++ b/src/lib-storage/test-mailbox-get.c Mon Apr 06 12:07:32 2015 +0900 @@ -40,7 +40,7 @@ int mail_transaction_log_view_set(struct mail_transaction_log_view *view ATTR_UNUSED, uint32_t min_file_seq ATTR_UNUSED, uoff_t min_file_offset ATTR_UNUSED, uint32_t max_file_seq ATTR_UNUSED, uoff_t max_file_offset ATTR_UNUSED, - bool *reset_r ATTR_UNUSED) { + bool *reset_r ATTR_UNUSED, const char **reason_r ATTR_UNUSED) { if (min_file_seq < 99) return 0; return 1;