Index: dbox-mail.c =================================================================== RCS file: /var/lib/cvs/dovecot/src/lib-storage/index/dbox/dbox-mail.c,v retrieving revision 1.9.2.2 diff -u -r1.9.2.2 dbox-mail.c --- dbox-mail.c 12 Jun 2006 08:24:03 -0000 1.9.2.2 +++ dbox-mail.c 23 Jul 2006 16:49:29 -0000 @@ -133,6 +133,7 @@ "broken for uid %u in dbox %s", file_seq, *offset_r, mail->mail.mail.uid, mbox->path); + abort(); if (dbox_sync(mbox, TRUE) < 0) return -1; Index: dbox-save.c =================================================================== RCS file: /var/lib/cvs/dovecot/src/lib-storage/index/dbox/dbox-save.c,v retrieving revision 1.10.2.5 diff -u -r1.10.2.5 dbox-save.c --- dbox-save.c 23 Jul 2006 15:37:55 -0000 1.10.2.5 +++ dbox-save.c 23 Jul 2006 16:49:29 -0000 @@ -15,6 +15,8 @@ #include +void i_debug(const char *format, ...) __attr_format__(1, 2); + struct dbox_save_context { struct mail_save_context ctx; @@ -219,6 +221,8 @@ mail_index_update_ext(ctx->trans, ctx->seq, mbox->dbox_offset_ext_idx, &ctx->hdr_offset, NULL); + i_debug("seq=%u: append at file=%u offset=%llu", + ctx->seq, ctx->file->file_seq, ctx->hdr_offset); if (t->first_saved_mail_seq == 0) t->first_saved_mail_seq = ctx->seq; @@ -339,6 +343,8 @@ i_assert(ret > 0); /* it's in memory, shouldn't fail! */ DEC2HEX(hdr.uid_hex, uid); + i_debug("seq=%u: assigned uid=%u, file=%u, offset=%llu", + seq, uid, file_seq, offset); file = dbox_uidlist_append_lookup_file(ctx->append_ctx, file_seq); Index: dbox-sync-expunge.c =================================================================== RCS file: /var/lib/cvs/dovecot/src/lib-storage/index/dbox/dbox-sync-expunge.c,v retrieving revision 1.15.2.2 diff -u -r1.15.2.2 dbox-sync-expunge.c --- dbox-sync-expunge.c 23 Jul 2006 14:20:29 -0000 1.15.2.2 +++ dbox-sync-expunge.c 23 Jul 2006 16:49:29 -0000 @@ -14,6 +14,8 @@ #include +void i_debug(const char *format, ...) __attr_format__(1, 2); + static const struct dotlock_settings new_file_dotlock_set = { MEMBER(temp_prefix) NULL, MEMBER(lock_suffix) NULL, @@ -175,12 +177,16 @@ if (seq == 0) { mail_storage_set_critical(STORAGE(mbox->storage), "Expunged UID %u reappeared in file %s", - uid, path); + uid, mbox->file->path); + sleep(10000); + abort(); mail_index_mark_corrupted(mbox->ibox.index); ret = -1; break; } + i_debug("moved: seq=%u, uid=%u -> file=%u, offset=%llu", + seq, uid, file_seq, hdr_offset); mail_index_update_ext(ctx->trans, seq, mbox->dbox_file_ext_idx, &file_seq, NULL); mail_index_update_ext(ctx->trans, seq, @@ -297,6 +303,7 @@ entry = dbox_uidlist_entry_lookup(mbox->uidlist, sync_entry->file_seq); if (entry == NULL) { /* file is already unlinked. just remove from index. */ + i_debug("expunge: already unlinked"); return 0; } @@ -308,8 +315,11 @@ first_expunged_uid = exp_uid1; seen_expunges = FALSE; skipped_expunges = FALSE; uid = 0; range = array_get_modifyable(&entry->uid_list, &count); + i_debug(".. wanna expunge uid=%u..%u, first_expunged_uid=%u", + exp_uid1, exp_uid2, first_expunged_uid); for (i = 0; i < count; i++) { uid = range[i].seq1; + i_debug(".. range[%d] uid=%u..%u", i, range[i].seq1, range[i].seq2); if (!seen_expunges) { if (uid < first_expunged_uid) { @@ -346,6 +356,8 @@ /* end of sync records */ break; } + i_debug(".. expunge more, uid=%u..%u", + exp_uid1, exp_uid2); } if (uid <= range[i].seq2) { /* non-expunged mails exist in this file */ @@ -357,6 +369,7 @@ /* mails expunged from the middle. have to copy everything after the first expunged mail to new file. after copying we'll truncate/unlink the old file. */ + i_debug("expunge from middle uid=%u, offset=%llu", uid, offset); if (dbox_sync_expunge_copy(ctx, sync_entry, sync_idx, uid, entry, offset) < 0) return -1; @@ -365,6 +378,9 @@ if (!skipped_expunges) { /* all mails expunged from file, unlink it. */ + i_debug("expunged all mails, unlinking file=%u", + entry->file_seq); + path = t_strdup_printf("%s/"DBOX_MAILDIR_NAME"/" DBOX_MAIL_FILE_FORMAT, mbox->path, entry->file_seq); @@ -380,6 +396,8 @@ } /* mails expunged from the end of file, ftruncate() it */ + i_debug("expunging from end of file, file=%u, offset=%llu", + entry->file_seq, offset); ret = dbox_file_seek(mbox, entry->file_seq, offset, FALSE); if (ret <= 0) { if (ret < 0) @@ -388,6 +406,7 @@ /* unexpected EOF -> already truncated */ } else { /* file can no longer be appended to */ + i_debug(" - writing marker"); if (pwrite_full(mbox->file->fd, "00000000EFFFFFFF", 16, offsetof(struct dbox_file_header, append_offset_hex)) < 0) { @@ -479,6 +498,8 @@ const char *path; int ret; + i_debug("expunge: file=%u", sync_entry->file_seq); + if (ctx->dotlock_failed_file_seq != sync_entry->file_seq) { /* we need to have the file locked in case another process is appending there already. */ @@ -512,6 +533,7 @@ deadlock (appending process waits for uidlist lock which we have, we wait for file lock which append process has) */ sync_rec = array_idx(&sync_entry->sync_recs, sync_idx); + i_debug("expunge: locked, updating flags"); if (dbox_sync_update_flags(ctx, sync_rec) < 0) return -1; Index: dbox-sync-full.c =================================================================== RCS file: /var/lib/cvs/dovecot/src/lib-storage/index/dbox/dbox-sync-full.c,v retrieving revision 1.5.2.2 diff -u -r1.5.2.2 dbox-sync-full.c --- dbox-sync-full.c 12 Jun 2006 08:24:03 -0000 1.5.2.2 +++ dbox-sync-full.c 23 Jul 2006 16:49:29 -0000 @@ -206,6 +206,7 @@ /* go through msg.* files, sync them to index and based on it write dbox's index file */ path = t_strconcat(mbox->path, "/"DBOX_MAILDIR_NAME, NULL); + i_warning("dbox: Doing a full sync for %s", path); dirp = opendir(path); if (dirp == NULL) { mail_storage_set_critical(STORAGE(mbox->storage), Index: dbox-sync.c =================================================================== RCS file: /var/lib/cvs/dovecot/src/lib-storage/index/dbox/dbox-sync.c,v retrieving revision 1.16.2.3 diff -u -r1.16.2.3 dbox-sync.c --- dbox-sync.c 23 Jul 2006 15:37:55 -0000 1.16.2.3 +++ dbox-sync.c 23 Jul 2006 16:49:29 -0000 @@ -14,6 +14,8 @@ #include +void i_debug(const char *format, ...) __attr_format__(1, 2); + int dbox_sync_get_file_offset(struct dbox_sync_context *ctx, uint32_t seq, uint32_t *file_seq_r, uoff_t *offset_r) { @@ -68,6 +70,8 @@ struct dbox_sync_rec, 3); hash_insert(ctx->syncs, POINTER_CAST(file_seq), entry); } + i_debug(" - seq=%u..%u : file=%u (type %u)", seq, sync_rec->seq2, + entry->file_seq, sync_rec->type); new_sync_rec = *sync_rec; new_sync_rec.seq1 = seq; @@ -136,6 +140,8 @@ dbox_sync_rec.value.keyword_idx = sync_rec->keyword_idx; break; case MAIL_INDEX_SYNC_TYPE_EXPUNGE: + i_debug("EXPUNGE: seq=%u..%u, uid=%u..%u", + seq1, seq2, sync_rec->uid1, sync_rec->uid2); case MAIL_INDEX_SYNC_TYPE_APPEND: break; } @@ -174,6 +180,12 @@ return ret; while (mbox->file->seeked_uid <= uid2) { + if (first_flag_offset == offsetof(struct dbox_mail_header, expunged)) { + i_assert(array[0] == '1'); + i_debug(" - uid=%u: flagging expunged at %"PRIuUOFF_T, + mbox->file->seeked_uid, offset); + } + for (i = 0; i < flag_count; ) { if (!mask[i]) { i++; Index: dbox-uidlist.c =================================================================== RCS file: /var/lib/cvs/dovecot/src/lib-storage/index/dbox/dbox-uidlist.c,v retrieving revision 1.28.2.7 diff -u -r1.28.2.7 dbox-uidlist.c --- dbox-uidlist.c 23 Jul 2006 15:37:55 -0000 1.28.2.7 +++ dbox-uidlist.c 23 Jul 2006 16:49:29 -0000 @@ -863,6 +863,7 @@ files = array_get(&ctx->files, &count); for (i = 0; i < count; i++) file_dotlock_delete(&files[i]->dotlock); + i_debug("dotlocks: unlocked"); if (ctx->locked) dbox_uidlist_unlock(ctx->uidlist); @@ -1066,6 +1067,7 @@ } if (ret == 0) { i_assert(i < count || !*existing_r); + i_debug("dotlock: %s", str_c(path)); break; } @@ -1115,6 +1117,7 @@ return -1; *file_r = file = files[i]->file; + i_debug("append: selected already opened file"); o_stream_seek(file->output, file->append_offset); return 0; }