diff -r 96c8632775df src/lib-index/mail-index-sync-update.c
--- a/src/lib-index/mail-index-sync-update.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-index/mail-index-sync-update.c	Mon May 04 16:35:01 2009 -0400
@@ -227,6 +227,19 @@
 	}
 }
 
+static const char *sync_type(struct mail_index_sync_map_ctx *ctx)
+{
+	switch (ctx->type) {
+	case MAIL_INDEX_SYNC_HANDLER_FILE:
+		return "sync=file";
+	case MAIL_INDEX_SYNC_HANDLER_HEAD:
+		return "sync=head";
+	case MAIL_INDEX_SYNC_HANDLER_VIEW:
+		return "sync=view";
+	}
+	return "sync=????";
+}
+
 static int
 sync_expunge(const struct mail_transaction_expunge *e, unsigned int count,
 	     struct mail_index_sync_map_ctx *ctx)
@@ -236,13 +249,21 @@
 	uint32_t seq_count, seq, seq1, seq2;
 	unsigned int i;
 
+	i_debug("%s: sync_expunge", sync_type(ctx));
 	for (i = 0; i < count; i++, e++) {
+		for (seq = e->uid1; seq <= e->uid2; seq++)
+			i_debug("%s: sync_expunge: uid=%u", sync_type(ctx), seq);
 		if (!mail_index_lookup_seq_range(ctx->view, e->uid1, e->uid2,
 						 &seq1, &seq2)) {
 			/* everything expunged already */
 			continue;
 		}
 
+		for (seq = seq1; seq <= seq2; seq++) {
+			rec = MAIL_INDEX_MAP_IDX(map, seq-1);
+			i_debug("%s: sync_expunge loop: uid=%u", sync_type(ctx), rec->uid);
+		}
+		i_debug("%s: ---", sync_type(ctx));
 		sync_expunge_call_handlers(ctx, seq1, seq2);
 
 		map = mail_index_sync_get_atomic_map(ctx);
@@ -460,6 +481,9 @@
 	case MAIL_TRANSACTION_EXPUNGE|MAIL_TRANSACTION_EXPUNGE_PROT: {
 		const struct mail_transaction_expunge *rec = data, *end;
 
+		i_debug("%s: expunge: external = %d", sync_type(ctx),
+			(hdr->type & MAIL_TRANSACTION_EXTERNAL) != 0);
+
 		if ((hdr->type & MAIL_TRANSACTION_EXTERNAL) == 0) {
 			/* this is simply a request for expunge */
 			break;
@@ -788,6 +812,8 @@
 	mail_transaction_log_view_get_prev_pos(view->log_view,
 					       &prev_seq, &prev_offset);
 
+	i_debug("mail_index_sync_map: begin");
+
 	mail_index_sync_map_init(&sync_map_ctx, view, type);
 	if (reset) {
 		/* Reset the entire index. Leave only indexid and
@@ -866,6 +892,11 @@
 
 	i_assert(index->map == map || type == MAIL_INDEX_SYNC_HANDLER_VIEW);
 
+	i_debug("mail_index_sync_map: finished "
+		"seq=%u head_offset=%u tail_offset=%u",
+		map->hdr.log_file_seq, map->hdr.log_file_head_offset,
+		map->hdr.log_file_tail_offset);
+
 	if (mail_index_map_check_header(map) <= 0) {
 		mail_index_set_error(index,
 			"Synchronization corrupted index header: %s",
diff -r 96c8632775df src/lib-index/mail-index-sync.c
--- a/src/lib-index/mail-index-sync.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-index/mail-index-sync.c	Mon May 04 16:35:01 2009 -0400
@@ -197,6 +197,7 @@
 	/* read all transactions from log into a transaction in memory.
 	   skip the external ones, they're already synced to mailbox and
 	   included in our view */
+	i_debug("read_and_sort");
 	while ((ret = mail_transaction_log_view_next(ctx->view->log_view,
 						     &ctx->hdr,
 						     &ctx->data)) > 0) {
@@ -208,6 +209,7 @@
 				mail_index_sync_update_mailbox_pos(ctx);
 		} T_END;
 	}
+	i_debug("/read_and_sort");
 
 	/* create an array containing all expunge, flag and keyword update
 	   arrays so we can easily go through all of the changes. */
@@ -331,11 +333,13 @@
 			   uint32_t log_file_seq, uoff_t log_file_offset)
 {
 	const struct mail_index_header *hdr;
-	uint32_t seq;
-	uoff_t offset;
+	uint32_t seq = 0;
+	uoff_t offset = 0;
 	bool locked = FALSE;
 	int ret;
 
+	i_debug("mail_index_sync_begin_init");
+
 	/* if we require changes, don't lock transaction log yet. first check
 	   if there's anything to sync. */
 	if ((flags & MAIL_INDEX_SYNC_FLAG_REQUIRE_CHANGES) == 0) {
@@ -383,6 +387,11 @@
 	}
 
 	hdr = &index->map->hdr;
+	i_debug("mail_index_sync_commit begin: "
+		"seq=%u head_offset=%u tail_offset=%u "
+		"(head seq=%u offset=%"PRIuUOFF_T")",
+		hdr->log_file_seq, hdr->log_file_head_offset,
+		hdr->log_file_tail_offset, seq, offset);
 	if (hdr->log_file_tail_offset > hdr->log_file_head_offset ||
 	    hdr->log_file_seq > seq ||
 	    (hdr->log_file_seq == seq && hdr->log_file_tail_offset > offset)) {
@@ -677,6 +686,8 @@
 
 	*_ctx = NULL;
 
+	i_debug("mail_index_sync_commit end");
+
 	ctx->index->syncing = FALSE;
 	mail_transaction_log_sync_unlock(ctx->index->log);
 
@@ -769,6 +780,7 @@
 {
 	if ((*ctx)->ext_trans != NULL)
 		mail_index_transaction_rollback(&(*ctx)->ext_trans);
+	i_debug("mail_index_sync_rollback");
 	mail_index_sync_end(ctx);
 }
 
diff -r 96c8632775df src/lib-index/mail-index-transaction.c
--- a/src/lib-index/mail-index-transaction.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-index/mail-index-transaction.c	Mon May 04 16:35:01 2009 -0400
@@ -755,6 +755,7 @@
 void mail_index_expunge(struct mail_index_transaction *t, uint32_t seq)
 {
 	i_assert(seq > 0);
+	i_debug("expunge: seq=%u", seq);
 	if (seq >= t->first_new_seq) {
 		/* we can handle only the last append. otherwise we'd have to
 		   renumber sequences and that gets tricky. for now this is
diff -r 96c8632775df src/lib-index/mail-transaction-log-append.c
--- a/src/lib-index/mail-transaction-log-append.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-index/mail-transaction-log-append.c	Mon May 04 16:35:01 2009 -0400
@@ -657,6 +657,10 @@
 	}
 	buffer_free(&ctx.output);
 
+	i_debug("transaction: seq=%u: %llu .. %llu (ext %d)",
+		file->hdr.file_seq, append_offset, file->sync_offset,
+		(t->flags & MAIL_INDEX_TRANSACTION_FLAG_EXTERNAL) != 0);
+
 	if ((t->flags & MAIL_INDEX_TRANSACTION_FLAG_HIDE) != 0) {
 		/* mark the area covered by this transaction hidden */
 		mail_index_view_add_hidden_transaction(view, file->hdr.file_seq,
diff -r 96c8632775df src/lib-index/mail-transaction-log-file.c
--- a/src/lib-index/mail-transaction-log-file.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-index/mail-transaction-log-file.c	Mon May 04 16:35:01 2009 -0400
@@ -42,6 +42,7 @@
 			t_strdup_vprintf(fmt, va), file->sync_offset);
 	} T_END;
 	va_end(va);
+	sleep(3600);
 }
 
 struct mail_transaction_log_file *
diff -r 96c8632775df src/lib-index/mail-transaction-log-private.h
--- a/src/lib-index/mail-transaction-log-private.h	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-index/mail-transaction-log-private.h	Mon May 04 16:35:01 2009 -0400
@@ -14,7 +14,7 @@
 /* Rotate when log is older than ROTATE_TIME and larger than MIN_SIZE */
 #define MAIL_TRANSACTION_LOG_ROTATE_MIN_SIZE (1024*32)
 /* If log is larger than MAX_SIZE, rotate regardless of the time */
-#define MAIL_TRANSACTION_LOG_ROTATE_MAX_SIZE (1024*1024)
+#define MAIL_TRANSACTION_LOG_ROTATE_MAX_SIZE (1024*64)
 #define MAIL_TRANSACTION_LOG_ROTATE_TIME (60*5)
 
 /* Delete .log.2 files older than this many seconds */
diff -r 96c8632775df src/lib-index/mail-transaction-log-view.c
--- a/src/lib-index/mail-transaction-log-view.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-index/mail-transaction-log-view.c	Mon May 04 16:35:01 2009 -0400
@@ -293,6 +293,10 @@
 	view->max_file_offset = I_MIN(max_file_offset, view->head->sync_offset);
 	view->broken = FALSE;
 
+	i_debug("view: %u,%llu .. %u,%llu",
+		view->min_file_seq, view->min_file_offset,
+		view->max_file_seq, view->max_file_offset);
+
 	i_assert(view->cur_offset <= view->cur->sync_offset);
 	return 1;
 }
diff -r 96c8632775df src/lib-storage/index/maildir/maildir-save.c
--- a/src/lib-storage/index/maildir/maildir-save.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-storage/index/maildir/maildir-save.c	Mon May 04 16:35:01 2009 -0400
@@ -681,6 +681,7 @@
 		/* assign the UIDs if we happen to get a lock */
 		sync_flags |= MAILDIR_UIDLIST_SYNC_TRYLOCK;
 	}
+	i_debug("maildir_transaction_save_commit_pre");
 	ret = maildir_uidlist_sync_init(ctx->mbox->uidlist, sync_flags,
 					&ctx->uidlist_sync_ctx);
 	if (ret <= 0 &&
@@ -754,6 +755,7 @@
 			ret = maildir_uidlist_sync_next(ctx->uidlist_sync_ctx,
 							dest, flags);
 			i_assert(ret > 0);
+			i_debug("save pre: sync: %s ret=%d", dest, ret);
 		} T_END;
 	}
 
@@ -797,11 +799,13 @@
 		maildir_transaction_save_rollback(ctx);
 		return -1;
 	}
+	i_debug("/maildir_transaction_save_commit_pre");
 	return ret;
 }
 
 void maildir_transaction_save_commit_post(struct maildir_save_context *ctx)
 {
+	i_debug("maildir_transaction_save_commit_post");
 	ctx->ctx.transaction = NULL; /* transaction is already freed */
 
 	if (ctx->locked)
diff -r 96c8632775df src/lib-storage/index/maildir/maildir-sync-index.c
--- a/src/lib-storage/index/maildir/maildir-sync-index.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-storage/index/maildir/maildir-sync-index.c	Mon May 04 16:35:01 2009 -0400
@@ -14,6 +14,33 @@
 #include <stdlib.h>
 #include <unistd.h>
 
+#include <sys/time.h>
+#include <stdio.h>
+#include <unistd.h>
+#include "ioloop.h"
+void i_debug(const char *format, ...)
+{
+       static FILE *f = NULL;
+       va_list args;
+       struct timeval tv;
+
+       gettimeofday(&tv, NULL);
+
+       va_start(args, format);
+       t_push();
+       if (!f) {
+               const char *dir = t_strdup_printf("/tmp/dovecot/%d", (int)ioloop_time/10);
+               mkdir(dir, 0700);
+               f = fopen(t_strdup_printf("%s/%d", dir, getpid()), "a+");
+               setbuf(f, NULL);
+       }
+       fprintf(f, "%10u.%06u PID=%s %s\n",
+               (unsigned)tv.tv_sec, (unsigned)tv.tv_usec,
+               dec2str(getpid()), t_strdup_vprintf(format, args));
+       t_pop();
+       va_end(args);
+}
+
 struct maildir_index_sync_context {
         struct maildir_mailbox *mbox;
 	struct maildir_sync_context *maildir_sync_ctx;
@@ -43,8 +70,10 @@
 			   struct maildir_index_sync_context *ctx)
 {
 	struct mailbox *box = &mbox->ibox.box;
+	int ret = unlink(path);
 
-	if (unlink(path) == 0) {
+	i_debug("maildir_expunge: %s -> %d", path, ret);
+	if (ret == 0) {
 		if (box->v.sync_notify != NULL) {
 			box->v.sync_notify(box, ctx->uid,
 					   MAILBOX_SYNC_TYPE_EXPUNGE);
@@ -390,6 +419,8 @@
 	i_assert(!mbox->syncing_commit);
 	i_assert(maildir_uidlist_is_locked(mbox->uidlist));
 
+	i_debug("maildir_sync_index: partial=%d", partial);
+
 	first_uid = 1;
 	hdr = mail_index_get_header(view);
 	uid_validity = maildir_uidlist_get_uid_validity(mbox->uidlist);
@@ -411,6 +442,11 @@
 	}
 	hdr_next_uid = hdr->next_uid;
 
+	for (seq = 1; seq <= hdr->messages_count; seq++) {
+		mail_index_lookup_uid(view, seq, &uid);
+		i_debug("index: seq=%u : uid=%u", seq, uid);
+	}
+
 	mbox->syncing_commit = TRUE;
 	seq = prev_uid = 0; first_recent_uid = I_MAX(hdr->first_recent_uid, 1);
 	t_array_init(&ctx->keywords, MAILDIR_MAX_KEYWORDS);
@@ -431,8 +467,11 @@
 		ctx->seq = ++seq;
 		ctx->uid = uid;
 
+		i_debug("seq=%u uid=%u name=%s flags=%x", seq, uid, filename, uflags);
 		if (seq > hdr->messages_count) {
+			i_debug(" - idx new: %s", filename);
 			if (uid < hdr_next_uid) {
+				i_debug(" - idx new racing: %u < %u", uid, hdr->next_uid);
 				maildir_handle_uid_insertion(ctx, uflags,
 							     filename, uid);
 				seq--;
@@ -467,11 +506,13 @@
 		rec = mail_index_lookup(view, seq);
 		if (uid > rec->uid) {
 			/* expunged */
+			i_debug(" - idx expunged: uid=%u (%u > %u)", rec->uid, uid, rec->uid);
 			mail_index_expunge(trans, seq);
 			goto again;
 		}
 
 		if (uid < rec->uid) {
+			i_debug(" - idx racing: uid=%u (%u < %u)", rec->uid, uid, rec->uid);
 			maildir_handle_uid_insertion(ctx, uflags,
 						     filename, uid);
 			seq--;
@@ -480,6 +521,7 @@
 
 		index_sync_changes_read(ctx->sync_changes, rec->uid, &expunged);
 		if (expunged) {
+			i_debug("maildir_sync_index: expunge: %u", uid);
 			if (maildir_file_do(mbox, ctx->uid,
 					    maildir_expunge, ctx) >= 0) {
 				/* successful expunge */
@@ -586,6 +628,7 @@
 			offsetof(struct mail_index_header, first_recent_uid),
 			&first_recent_uid, sizeof(first_recent_uid), FALSE);
 	}
+	i_debug("/maildir_sync_index, full_rescan=%d", full_rescan);
 	return ret < 0 ? -1 : (full_rescan ? 0 : 1);
 }
 
diff -r 96c8632775df src/lib-storage/index/maildir/maildir-sync.c
--- a/src/lib-storage/index/maildir/maildir-sync.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-storage/index/maildir/maildir-sync.c	Mon May 04 16:35:01 2009 -0400
@@ -369,6 +369,7 @@
 	bool move_new, check_touch, dir_changed = FALSE;
 
 	path = new_dir ? ctx->new_dir : ctx->cur_dir;
+	i_debug("scanning dir %s", path);
 	for (i = 0;; i++) {
 		dirp = opendir(path);
 		if (dirp != NULL)
@@ -472,6 +473,7 @@
 
 		ret = maildir_uidlist_sync_next(ctx->uidlist_sync_ctx,
 						dp->d_name, flags);
+		i_debug("found: %s, move=%d, ret=%d", dp->d_name, move_new, ret);
 		if (ret <= 0) {
 			if (ret < 0)
 				break;
@@ -485,6 +487,7 @@
 				break;
 		}
 	}
+	i_debug("----");
 
 	if (errno != 0) {
 		mail_storage_set_critical(storage,
@@ -681,6 +684,8 @@
 
 	*lost_files_r = FALSE;
 
+	i_debug("maildir_sync_context: forced=%d", forced);
+
 	if (forced)
 		new_changed = cur_changed = TRUE;
 	else {
@@ -834,9 +839,11 @@
 	int ret;
 
 	T_BEGIN {
+		i_debug("maildir_storage_sync_force");
 		ctx = maildir_sync_context_new(mbox, MAILBOX_SYNC_FLAG_FAST);
 		ret = maildir_sync_context(ctx, TRUE, &uid, &lost_files);
 		maildir_sync_deinit(ctx);
+		i_debug("/maildir_storage_sync_force");
 	} T_END;
 
 	if (uid != 0) {
@@ -862,6 +869,7 @@
 	if (!box->opened)
 		index_storage_mailbox_open(&mbox->ibox);
 
+	i_debug("maildir_storage_sync_init");
 	if (index_mailbox_want_full_sync(&mbox->ibox, flags)) {
 		T_BEGIN {
 			ctx = maildir_sync_context_new(mbox, flags);
@@ -879,6 +887,8 @@
 		}
 	}
 
+	i_debug("/maildir_storage_sync_init");
+
 	return index_mailbox_sync_init(box, flags, ret < 0);
 }
 
diff -r 96c8632775df src/lib-storage/index/maildir/maildir-uidlist.c
--- a/src/lib-storage/index/maildir/maildir-uidlist.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-storage/index/maildir/maildir-uidlist.c	Mon May 04 16:35:01 2009 -0400
@@ -179,6 +179,7 @@
 	uidlist->lock_count++;
 	uidlist->locked_refresh = FALSE;
 
+	i_debug("uidlist locked");
 	if (refresh) {
 		/* make sure we have the latest changes before
 		   changing anything */
@@ -219,6 +220,7 @@
 	if (--uidlist->lock_count > 0)
 		return;
 
+	i_debug("uidlist unlocked");
 	uidlist->locked_refresh = FALSE;
 	(void)file_dotlock_delete(&uidlist->dotlock);
 }
@@ -429,6 +431,21 @@
 	return TRUE;
 }
 
+static void recs_check(struct maildir_uidlist *uidlist)
+{
+	struct maildir_uidlist_rec *const *recs;
+	unsigned int i, count;
+
+	recs = array_get(&uidlist->records, &count);
+	for (i = 1; i < count; i++) {
+		if (recs[i]->uid == (uint32_t)-1)
+			break;
+		i_assert(recs[i-1]->uid < recs[i]->uid);
+	}
+	for (; i < count; i++)
+		i_assert(recs[i]->uid == (uint32_t)-1);
+}
+
 static bool maildir_uidlist_next(struct maildir_uidlist *uidlist,
 				 const char *line)
 {
@@ -496,6 +513,7 @@
 			uidlist->path, uidlist->read_line_count, line);
 		return FALSE;
 	}
+	i_debug("read: uid=%u %s", rec->uid, line);
 
 	old_rec = hash_lookup(uidlist->files, line);
 	if (old_rec == NULL) {
@@ -512,6 +530,7 @@
 
 		   we'll waste a bit of memory here by allocating the record
 		   twice, but that's not really a problem.  */
+		i_debug("read: conflict uid=%u", uid);
 		rec->filename = old_rec->filename;
 		hash_insert(uidlist->files, rec->filename, rec);
 		uidlist->unsorted = TRUE;
@@ -523,6 +542,7 @@
 			  "%s (uid %u -> %u)",
 			  uidlist->path, uidlist->read_line_count, line,
 			  old_rec->uid, uid);
+		sleep(3600);
 		/* Delete the old UID */
 		maildir_uidlist_records_array_delete(uidlist, old_rec);
 		/* Replace the old record with this new one */
@@ -535,6 +555,7 @@
 	if (count > 0 && recs[count-1]->uid > uid) {
 		/* we most likely have some records in the array that we saved
 		   ourself without refreshing uidlist */
+		i_debug("read: unsorted");
 		uidlist->unsorted = TRUE;
 	}
 
@@ -636,6 +657,7 @@
 
 	recs = array_get_modifiable(&uidlist->records, &count);
 	qsort(recs, count, sizeof(*recs), maildir_uid_cmp);
+	recs_check(uidlist);
 
 	uidlist->unsorted = FALSE;
 }
@@ -682,6 +704,17 @@
 		last_read_offset = uidlist->last_read_offset;
 		uidlist->last_read_offset = 0;
 	}
+	i_debug("refresh: last_read_offset=%u, last_seen_uid=%u",
+		(int)last_read_offset, uidlist->last_seen_uid);
+	{
+		struct maildir_uidlist_rec *const *recs;
+		unsigned int i, count;
+		recs = array_get(&uidlist->records, &count);
+		for (i = 0; i < count; i++) {
+			i_debug("existing: uid=%u %s", recs[i]->uid, recs[i]->filename);
+		}
+		i_debug("-");
+	}
 
 	if (fstat(fd, &st) < 0) {
                 close_keep_errno(fd);
@@ -759,6 +792,9 @@
 		uidlist->fd_size = st.st_size;
 		uidlist->last_read_offset = input->v_offset;
 		maildir_uidlist_update_hdr(uidlist, &st);
+		i_debug("refreshed: ino=%u size=%u last_read_offset=%u",
+			(int)st.st_ino, (int)st.st_size,
+			(int)uidlist->last_read_offset);
         } else if (!*retry_r) {
                 /* I/O error */
                 if (input->stream_errno == ESTALE && try_retry)
@@ -838,6 +874,7 @@
 		return 1;
 	} else {
 		/* unchanged */
+		i_debug("has_changed: no, ino=%u size=%u", (int)st.st_ino, (int)st.st_size);
 		return 0;
 	}
 }
@@ -851,13 +888,18 @@
 	if (uidlist->fd != -1) {
 		ret = maildir_uidlist_has_changed(uidlist, &recreated);
 		if (ret <= 0) {
+			i_debug("refresh: uidlist not changed (%d)", ret);
 			if (UIDLIST_IS_LOCKED(uidlist))
 				uidlist->locked_refresh = TRUE;
 			return ret;
 		}
 
-		if (recreated)
+		if (recreated) {
+			i_debug("refresh: uidlist recreated");
 			maildir_uidlist_close(uidlist);
+		}
+	} else {
+		i_debug("refresh: uidlist not opened yet");
 	}
 
         for (i = 0; ; i++) {
@@ -874,6 +916,7 @@
 		if (UIDLIST_IS_LOCKED(uidlist))
 			uidlist->locked_refresh = TRUE;
 	}
+	i_debug("refresh: ret=%d", ret);
         return ret;
 }
 
@@ -1156,6 +1199,7 @@
 				p += len + 1;
 			}
 		}
+		i_debug("uidlist write: uid=%u %s", rec->uid, rec->filename);
 		str_printfa(str, " :%s\n", rec->filename);
 		o_stream_send(output, str_data(str), str_len(str));
 	}
@@ -1194,6 +1238,7 @@
 
 	i_assert(uidlist->initial_read);
 
+	i_debug("uidlist rewrite");
 	control_dir = mailbox_list_get_path(box->storage->list, box->name,
 					    MAILBOX_LIST_PATH_TYPE_CONTROL);
 	temp_path = t_strconcat(control_dir,
@@ -1260,6 +1305,7 @@
 		uidlist->last_read_offset = st.st_size;
 		uidlist->recreate = FALSE;
 		maildir_uidlist_update_hdr(uidlist, &st);
+		i_debug("rewrite: ino=%u size=%u", (int)st.st_ino, (int)st.st_size);
 	}
 	if (ret < 0)
 		(void)close(fd);
@@ -1350,6 +1396,7 @@
 		return -1;
 	}
 
+	i_debug("uidlist appending");
 	if (maildir_uidlist_write_fd(uidlist, uidlist->fd, uidlist->path,
 				     ctx->first_unwritten_pos, &file_size) < 0)
 		return -1;
@@ -1363,9 +1410,13 @@
 		i_warning("%s: file size changed unexpectedly after write",
 			  uidlist->path);
 	} else if (uidlist->locked_refresh) {
+		i_debug("post-append: updated size=%lld", st.st_size);
 		uidlist->fd_size = st.st_size;
 		uidlist->last_read_offset = st.st_size;
 		maildir_uidlist_update_hdr(uidlist, &st);
+	} else {
+		i_debug("post-append: not updated, size=%lld (keep: size=%u last_read_offset=%u)",
+			st.st_size, (int)uidlist->fd_size, (int)uidlist->last_read_offset);
 	}
 	return 0;
 }
@@ -1455,6 +1506,7 @@
 		/* doesn't exist in uidlist */
 		if (!ctx->locked) {
 			/* we can't add it, so just ignore it */
+			i_debug("sync_next_partial: uidlist not locked, ignoring %s", filename);
 			return;
 		}
 		if (ctx->first_nouid_pos == (unsigned int)-1)
@@ -1473,7 +1525,11 @@
 			    struct maildir_uidlist_rec, 1);
 		rec->uid = (uint32_t)-1;
 		array_append(&uidlist->records, &rec, 1);
+		recs_check(uidlist);
 		uidlist->change_counter++;
+		i_debug("sync_next_partial: uidlist assigning new uid %s", filename);
+	} else {
+		i_debug("sync_next_partial: uidlist exists uid=%u %s", rec->uid, filename);
 	}
 
 	rec->flags = (rec->flags | flags) & ~MAILDIR_UIDLIST_REC_FLAG_NONSYNCED;
@@ -1531,12 +1587,14 @@
 		if ((rec->flags & (MAILDIR_UIDLIST_REC_FLAG_NEW_DIR |
 				   MAILDIR_UIDLIST_REC_FLAG_MOVED)) == 0) {
 			/* possibly duplicate */
+			i_debug("sync_next: possible duplicate uid=%u %s", rec->uid, filename);
 			return 0;
 		}
 
 		/* probably was in new/ and now we're seeing it in cur/.
 		   remove new/moved flags so if this happens again we'll know
 		   to check for duplicates. */
+		i_debug("sync_next: moved to cur? uid=%u %s", rec->uid, filename);
 		rec->flags &= ~(MAILDIR_UIDLIST_REC_FLAG_NEW_DIR |
 				MAILDIR_UIDLIST_REC_FLAG_MOVED);
 	} else {
@@ -1549,7 +1607,9 @@
 			*rec = *old_rec;
 			rec->extensions =
 				ext_dup(ctx->record_pool, rec->extensions);
+			i_debug("sync_next: keeping uid=%u %s", rec->uid, filename);
 		} else {
+			i_debug("sync_next: new file %s", filename);
 			rec->uid = (uint32_t)-1;
 			ctx->new_files_count++;
 			ctx->changed = TRUE;
@@ -1579,6 +1639,7 @@
 	i_assert(rec != NULL);
 	i_assert(rec->uid != (uint32_t)-1);
 
+	i_debug("sync_remove: uid=%u %s", rec->uid, filename);
 	hash_remove(ctx->uidlist->files, filename);
 	idx = maildir_uidlist_records_array_delete(ctx->uidlist, rec);
 
@@ -1652,6 +1713,8 @@
 	      sizeof(*recs), maildir_time_cmp);
 
 	for (dest = ctx->first_nouid_pos; dest < count; dest++) {
+		i_debug("uidlist assign uid: %s -> uid=%u",
+			recs[dest]->filename, ctx->uidlist->next_uid);
 		i_assert(recs[dest]->uid == (uint32_t)-1);
 		recs[dest]->uid = ctx->uidlist->next_uid++;
 		recs[dest]->flags &= ~MAILDIR_UIDLIST_REC_FLAG_MOVED;
@@ -1680,6 +1743,18 @@
 	uidlist->records = ctx->records;
 	ctx->records.arr.buffer = NULL;
 
+	{
+		struct maildir_uidlist_rec *const *recs;
+		unsigned int i, count;
+
+		i_debug("swapping to:");
+		recs = array_get(&uidlist->records, &count);
+		for (i = 0; i < count; i++) {
+			i_debug("uid=%u %s", recs[i]->uid, recs[i]->filename);
+		}
+		i_debug("-");
+	}
+
 	hash_destroy(&uidlist->files);
 	uidlist->files = ctx->files;
 	ctx->files = NULL;
@@ -1699,6 +1774,9 @@
 
 void maildir_uidlist_sync_finish(struct maildir_uidlist_sync_ctx *ctx)
 {
+	i_debug("sync finish, partial=%d changed=%d locked=%d failed=%d new_count=%u",
+		ctx->partial, ctx->changed, ctx->locked, ctx->failed, ctx->new_files_count);
+
 	if (!ctx->partial) {
 		if (!ctx->failed)
 			maildir_uidlist_swap(ctx);
diff -r 96c8632775df src/lib-storage/index/maildir/maildir-util.c
--- a/src/lib-storage/index/maildir/maildir-util.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib-storage/index/maildir/maildir-util.c	Mon May 04 16:35:01 2009 -0400
@@ -24,8 +24,10 @@
 	int ret;
 
 	ret = maildir_uidlist_lookup(mbox->uidlist, uid, &flags, &fname);
-	if (ret <= 0)
+	if (ret <= 0) {
+		i_debug("maildir_file_do_try: %u not found", uid);
 		return ret == 0 ? -2 : -1;
+	}
 
 	if ((flags & MAILDIR_UIDLIST_REC_FLAG_NEW_DIR) != 0) {
 		/* probably in new/ dir */
diff -r 96c8632775df src/lib/failures.c
--- a/src/lib/failures.c	Mon May 04 16:34:21 2009 -0400
+++ b/src/lib/failures.c	Mon May 04 16:35:01 2009 -0400
@@ -157,6 +157,7 @@
 			i_error("Raw backtrace: %s", backtrace);
 	}
 
+	sleep(3600);
 	if (type == LOG_TYPE_PANIC)
 		abort();
 	else
