dovecot-2.2: dsync: Improved debug/error logging for changes dur...

dovecot at dovecot.org dovecot at dovecot.org
Tue Sep 17 23:12:17 EEST 2013


details:   http://hg.dovecot.org/dovecot-2.2/rev/393c389b1540
changeset: 16762:393c389b1540
user:      Timo Sirainen <tss at iki.fi>
date:      Tue Sep 17 23:12:03 2013 +0300
description:
dsync: Improved debug/error logging for changes during sync.

diffstat:

 src/doveadm/dsync/dsync-brain-mailbox-tree-sync.c |  27 +++++++++++++++++++++-
 src/doveadm/dsync/dsync-brain-mailbox.c           |  25 +++++++++++++++++----
 src/doveadm/dsync/dsync-brain-private.h           |   2 +-
 src/doveadm/dsync/dsync-mailbox-import.c          |  12 ++++++++-
 4 files changed, 56 insertions(+), 10 deletions(-)

diffs (203 lines):

diff -r ec9eab188dd8 -r 393c389b1540 src/doveadm/dsync/dsync-brain-mailbox-tree-sync.c
--- a/src/doveadm/dsync/dsync-brain-mailbox-tree-sync.c	Tue Sep 17 21:57:48 2013 +0300
+++ b/src/doveadm/dsync/dsync-brain-mailbox-tree-sync.c	Tue Sep 17 23:12:03 2013 +0300
@@ -111,8 +111,19 @@
 	case DSYNC_MAILBOX_TREE_SYNC_TYPE_DELETE_BOX:
 		/* make sure we're deleting the correct mailbox */
 		ret = dsync_brain_mailbox_alloc(brain, change->mailbox_guid,
-						&box);
-		if (ret <= 0) {
+						&box, &errstr);
+		if (ret < 0) {
+			i_error("Mailbox sync: Couldn't allocate mailbox GUID %s: %s",
+				guid_128_to_string(change->mailbox_guid), errstr);
+			return -1;
+		}
+		if (ret == 0) {
+			if (brain->debug) {
+				i_debug("brain %c: Mailbox GUID %s sync: "
+					"Deletion conflict: %s",
+					brain->master_brain ? 'M' : 'S',
+					mailbox_get_vname(box), errstr);
+			}
 			brain->changes_during_sync = TRUE;
 			return ret;
 		}
@@ -126,6 +137,12 @@
 		errstr = mailbox_list_get_last_error(change->ns->list, &error);
 		if (error == MAIL_ERROR_NOTFOUND ||
 		    error == MAIL_ERROR_EXISTS) {
+			if (brain->debug) {
+				i_debug("brain %c: Mailbox %s sync: "
+					"mailbox_list_delete_dir conflict: %s",
+					brain->master_brain ? 'M' : 'S',
+					mailbox_get_vname(box), errstr);
+			}
 			brain->changes_during_sync = TRUE;
 			return 0;
 		} else {
@@ -175,6 +192,12 @@
 		    error == MAIL_ERROR_NOTFOUND) {
 			/* mailbox was already created or was already deleted.
 			   let the next sync figure out what to do */
+			if (brain->debug) {
+				i_debug("brain %c: Mailbox %s sync: %s conflict: %s",
+					brain->master_brain ? 'M' : 'S',
+					mailbox_get_vname(box),
+					func_name, errstr);
+			}
 			brain->changes_during_sync = TRUE;
 			ret = 0;
 		} else {
diff -r ec9eab188dd8 -r 393c389b1540 src/doveadm/dsync/dsync-brain-mailbox.c
--- a/src/doveadm/dsync/dsync-brain-mailbox.c	Tue Sep 17 21:57:48 2013 +0300
+++ b/src/doveadm/dsync/dsync-brain-mailbox.c	Tue Sep 17 23:12:03 2013 +0300
@@ -15,20 +15,25 @@
 
 static int
 ns_mailbox_try_alloc(struct mail_namespace *ns, const guid_128_t guid,
-		     struct mailbox **box_r)
+		     struct mailbox **box_r, const char **error_r)
 {
 	struct mailbox *box;
 	enum mailbox_existence existence;
+	enum mail_error err;
 	int ret;
 
 	box = mailbox_alloc_guid(ns->list, guid, 0);
 	ret = mailbox_exists(box, FALSE, &existence);
 	if (ret < 0) {
+		*error_r = mailbox_get_last_error(box, &err);
 		mailbox_free(&box);
 		return -1;
 	}
 	if (existence != MAILBOX_EXISTENCE_SELECT) {
 		mailbox_free(&box);
+		*error_r = existence == MAILBOX_EXISTENCE_NONE ?
+			"Mailbox was already deleted" :
+			"Mailbox is no longer selectable";
 		return 0;
 	}
 	*box_r = box;
@@ -36,14 +41,14 @@
 }
 
 int dsync_brain_mailbox_alloc(struct dsync_brain *brain, const guid_128_t guid,
-			      struct mailbox **box_r)
+			      struct mailbox **box_r, const char **error_r)
 {
 	struct mail_namespace *ns;
 	int ret;
 
 	*box_r = NULL;
 	if (brain->sync_ns != NULL) {
-		ret = ns_mailbox_try_alloc(brain->sync_ns, guid, box_r);
+		ret = ns_mailbox_try_alloc(brain->sync_ns, guid, box_r, error_r);
 		if (ret < 0)
 			brain->failed = TRUE;
 		return ret;
@@ -52,7 +57,7 @@
 	for (ns = brain->user->namespaces; ns != NULL; ns = ns->next) {
 		if (!dsync_brain_want_namespace(brain, ns))
 			continue;
-		if ((ret = ns_mailbox_try_alloc(ns, guid, box_r)) != 0) {
+		if ((ret = ns_mailbox_try_alloc(ns, guid, box_r, error_r)) != 0) {
 			if (ret < 0)
 				brain->failed = TRUE;
 			return ret;
@@ -596,6 +601,7 @@
 	const struct dsync_mailbox *dsync_box;
 	struct dsync_mailbox local_dsync_box;
 	struct mailbox *box;
+	const char *error;
 	int ret;
 
 	i_assert(!brain->master_brain);
@@ -608,13 +614,22 @@
 		return TRUE;
 	}
 
-	if (dsync_brain_mailbox_alloc(brain, dsync_box->mailbox_guid, &box) < 0) {
+	if (dsync_brain_mailbox_alloc(brain, dsync_box->mailbox_guid,
+				      &box, &error) < 0) {
+		i_error("Couldn't allocate mailbox GUID %s: %s",
+			guid_128_to_string(dsync_box->mailbox_guid), error);
 		i_assert(brain->failed);
 		return TRUE;
 	}
 	if (box == NULL) {
 		/* mailbox was probably deleted/renamed during sync */
 		//FIXME: verify this from log, and if not log an error.
+		if (brain->debug) {
+			i_debug("brain %c: Mailbox GUID %s sync: "
+				"Mailbox was lost during sync",
+				brain->master_brain ? 'M' : 'S',
+				guid_128_to_string(dsync_box->mailbox_guid));
+		}
 		brain->changes_during_sync = TRUE;
 		dsync_brain_slave_send_mailbox_lost(brain, dsync_box);
 		return TRUE;
diff -r ec9eab188dd8 -r 393c389b1540 src/doveadm/dsync/dsync-brain-private.h
--- a/src/doveadm/dsync/dsync-brain-private.h	Tue Sep 17 21:57:48 2013 +0300
+++ b/src/doveadm/dsync/dsync-brain-private.h	Tue Sep 17 23:12:03 2013 +0300
@@ -113,7 +113,7 @@
 
 void dsync_brain_sync_mailbox_deinit(struct dsync_brain *brain);
 int dsync_brain_mailbox_alloc(struct dsync_brain *brain, const guid_128_t guid,
-			      struct mailbox **box_r);
+			      struct mailbox **box_r, const char **error_r);
 void dsync_brain_mailbox_update_pre(struct dsync_brain *brain,
 				    struct mailbox *box,
 				    const struct dsync_mailbox *local_box,
diff -r ec9eab188dd8 -r 393c389b1540 src/doveadm/dsync/dsync-mailbox-import.c
--- a/src/doveadm/dsync/dsync-mailbox-import.c	Tue Sep 17 21:57:48 2013 +0300
+++ b/src/doveadm/dsync/dsync-mailbox-import.c	Tue Sep 17 23:12:03 2013 +0300
@@ -2020,9 +2020,10 @@
 }
 
 static int
-reassign_uids_in_seq_range(struct mailbox *box,
+reassign_uids_in_seq_range(struct dsync_mailbox_importer *importer,
 			   const ARRAY_TYPE(seq_range) *unwanted_uids)
 {
+	struct mailbox *box = importer->box;
 	const enum mailbox_transaction_flags trans_flags =
 		MAILBOX_TRANSACTION_FLAG_EXTERNAL |
 		MAILBOX_TRANSACTION_FLAG_ASSIGN_UIDS;
@@ -2032,6 +2033,7 @@
 	struct mail_search_context *search_ctx;
 	struct mail_save_context *save_ctx;
 	struct mail *mail;
+	unsigned int renumber_count = 0;
 	int ret = 1;
 
 	if (array_count(unwanted_uids) == 0)
@@ -2058,6 +2060,7 @@
 		} else if (ret > 0) {
 			ret = 0;
 		}
+		renumber_count++;
 	}
 	if (mailbox_search_deinit(&search_ctx) < 0) {
 		i_error("Mailbox %s: mail search failed: %s",
@@ -2072,6 +2075,11 @@
 			mailbox_get_last_error(box, NULL));
 		ret = -1;
 	}
+	if (ret == 0 && importer->debug) {
+		i_debug("Mailbox %s: Renumbered %u of %u unwanted UIDs",
+			mailbox_get_vname(box),
+			renumber_count, array_count(unwanted_uids));
+	}
 	return ret;
 }
 
@@ -2119,7 +2127,7 @@
 			seq_range_array_remove(&unwanted_uids, saved_uids[i]);
 	}
 
-	ret = reassign_uids_in_seq_range(importer->box, &unwanted_uids);
+	ret = reassign_uids_in_seq_range(importer, &unwanted_uids);
 	if (ret == 0) {
 		*changes_during_sync_r = TRUE;
 		/* conflicting changes during sync, revert our last-common-uid


More information about the dovecot-cvs mailing list