dovecot-2.2: dsync: Added more debug output

[dovecot at dovecot.org]

details:   http://hg.dovecot.org/dovecot-2.2/rev/bb5deb884303
changeset: 17271:bb5deb884303
user:      Timo Sirainen <tss at iki.fi>
date:      Fri Apr 25 17:28:39 2014 +0300
description:
dsync: Added more debug output

diffstat:

 src/doveadm/dsync/dsync-brain-mailbox.c |  20 +++++++++++++
 src/doveadm/dsync/dsync-brain.c         |  48 ++++++++++++++++++++++++++++++--
 2 files changed, 64 insertions(+), 4 deletions(-)

diffs (131 lines):

diff -r 5798bb0167b9 -r bb5deb884303 src/doveadm/dsync/dsync-brain-mailbox.c
--- a/src/doveadm/dsync/dsync-brain-mailbox.c	Fri Apr 25 16:35:51 2014 +0300
+++ b/src/doveadm/dsync/dsync-brain-mailbox.c	Fri Apr 25 17:28:39 2014 +0300
@@ -374,6 +374,16 @@
 		/* if mailbox's last_common_* state equals the current state,
 		   we can skip the mailbox */
 		if (!dsync_brain_has_mailbox_state_changed(brain, &dsync_box)) {
+			if (brain->debug) {
+				i_debug("brain %c: Skipping mailbox %s with unchanged state "
+					"uidvalidity=%u uidnext=%u highestmodseq=%llu highestpvtmodseq=%llu",
+					brain->master_brain ? 'M' : 'S',
+					guid_128_to_string(dsync_box.mailbox_guid),
+					dsync_box.uid_validity,
+					dsync_box.uid_next,
+					(unsigned long long)dsync_box.highest_modseq,
+					(unsigned long long)dsync_box.highest_pvt_modseq);
+			}
 			mailbox_free(&box);
 			return 0;
 		}
@@ -658,6 +668,11 @@
 			return TRUE;
 		}
 		/* another process just deleted this mailbox? */
+		if (brain->debug) {
+			i_debug("brain %c: Skipping lost mailbox %s",
+				brain->master_brain ? 'M' : 'S',
+				guid_128_to_string(dsync_box->mailbox_guid));
+		}
 		dsync_brain_slave_send_mailbox_lost(brain, dsync_box);
 		return TRUE;
 	}
@@ -670,6 +685,11 @@
 
 	if (!dsync_boxes_need_sync(brain, &local_dsync_box, dsync_box)) {
 		/* no fields appear to have changed, skip this mailbox */
+		if (brain->debug) {
+			i_debug("brain %c: Skipping unchanged mailbox %s",
+				brain->master_brain ? 'M' : 'S',
+				guid_128_to_string(dsync_box->mailbox_guid));
+		}
 		mailbox_free(&box);
 		return TRUE;
 	}
diff -r 5798bb0167b9 -r bb5deb884303 src/doveadm/dsync/dsync-brain.c
--- a/src/doveadm/dsync/dsync-brain.c	Fri Apr 25 16:35:51 2014 +0300
+++ b/src/doveadm/dsync/dsync-brain.c	Fri Apr 25 17:28:39 2014 +0300
@@ -33,6 +33,8 @@
 	"done"
 };
 
+static void dsync_brain_mailbox_states_dump(struct dsync_brain *brain);
+
 static const char *dsync_brain_get_proctitle(struct dsync_brain *brain)
 {
 	string_t *str = t_str_new(128);
@@ -174,13 +176,20 @@
 	brain->master_brain = TRUE;
 	dsync_brain_set_flags(brain, flags);
 
-	if (sync_type == DSYNC_BRAIN_SYNC_TYPE_STATE &&
-	    dsync_mailbox_states_import(brain->mailbox_states,
-					brain->pool, set->state, &error) < 0) {
+	if (sync_type != DSYNC_BRAIN_SYNC_TYPE_STATE)
+		;
+	else if (dsync_mailbox_states_import(brain->mailbox_states, brain->pool,
+					     set->state, &error) < 0) {
 		hash_table_clear(brain->mailbox_states, FALSE);
 		i_error("Saved sync state is invalid, "
 			"falling back to full sync: %s", error);
 		brain->sync_type = sync_type = DSYNC_BRAIN_SYNC_TYPE_FULL;
+	} else {
+		if (brain->debug) {
+			i_debug("brain %c: Imported mailbox states:",
+				brain->master_brain ? 'M' : 'S');
+			dsync_brain_mailbox_states_dump(brain);
+		}
 	}
 	dsync_brain_mailbox_trees_init(brain);
 
@@ -597,6 +606,26 @@
 	return ret;
 }
 
+static void dsync_brain_mailbox_states_dump(struct dsync_brain *brain)
+{
+	struct hash_iterate_context *iter;
+	struct dsync_mailbox_state *state;
+	uint8_t *guid;
+
+	iter = hash_table_iterate_init(brain->mailbox_states);
+	while (hash_table_iterate(iter, brain->mailbox_states, &guid, &state)) {
+		i_debug("brain %c: Mailbox %s state: uidvalidity=%u uid=%u modseq=%llu pvt_modseq=%llu changes_during_sync=%d",
+			brain->master_brain ? 'M' : 'S',
+			guid_128_to_string(guid),
+			state->last_uidvalidity,
+			state->last_common_uid,
+			(unsigned long long)state->last_common_modseq,
+			(unsigned long long)state->last_common_pvt_modseq,
+			state->changes_during_sync);
+	}
+	hash_table_iterate_deinit(&iter);
+}
+
 void dsync_brain_get_state(struct dsync_brain *brain, string_t *output)
 {
 	struct hash_iterate_context *iter;
@@ -622,11 +651,22 @@
 		node = dsync_mailbox_tree_lookup_guid(brain->local_mailbox_tree,
 						      guid);
 		if (node == NULL ||
-		    node->existence != DSYNC_MAILBOX_NODE_EXISTS)
+		    node->existence != DSYNC_MAILBOX_NODE_EXISTS) {
+			if (brain->debug) {
+				i_debug("brain %c: Removed state for deleted mailbox %s",
+					brain->master_brain ? 'M' : 'S',
+					guid_128_to_string(guid));
+			}
 			hash_table_remove(brain->mailbox_states, guid);
+		}
 	}
 	hash_table_iterate_deinit(&iter);
 
+	if (brain->debug) {
+		i_debug("brain %c: Exported mailbox states:",
+			brain->master_brain ? 'M' : 'S');
+		dsync_brain_mailbox_states_dump(brain);
+	}
 	dsync_mailbox_states_export(brain->mailbox_states, output);
 }