On Fri, May 07, 2021 at 09:17:26AM +0200, Florian Lohoff wrote:
So i am pretty shure nothing else is accessing this mailbox - This morning i opened the screen session and i am here:
Okay - ran doveadm force-resync and it finished without further notices.
I changed password back and immediatly the web frontend started to try to fetch mails. (No deliveries enabled).
First accesses took ages - it seems the imapd tried to rebuild cache files or the like - nothing in the log.
After ~10 Minutes this happened and now the mailbox is broken again:
May 07 16:07:44 imap(inbox@wasteland)<26758><5rud0r3BwL0qAQT4AgGS8wAAAAAAAA8Q>: Warning: Transaction log file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index.log was locked for 554 seconds (rotating while syncing) May 07 16:07:44 imap(inbox@wasteland)<30094><eM6p6r3BqsEqAQT4AgGS8wAAAAAAAA8Q>: Warning: Locking transaction log file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index.log took 151 seconds (syncing) May 07 16:07:44 imap(inbox@wasteland)<26758><5rud0r3BwL0qAQT4AgGS8wAAAAAAAA8Q>: Info: Connection closed (UID FETCH finished 0.000 secs ago) in=101 out=973 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 May 07 16:07:47 imap(inbox@wasteland)<26219><OcR9zr3BMr0qAQT4AgGS8wAAAAAAAA8Q>: Error: Corrupted transaction log file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index.log seq 3: indexid changed: 1620395840 -> 1620395910 (sync_offset=0) May 07 16:07:47 imap(inbox@wasteland)<26219><OcR9zr3BMr0qAQT4AgGS8wAAAAAAAA8Q>: Warning: Transaction log file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index.log was locked for 627 seconds (rotating while syncing) May 07 16:07:47 imap(inbox@wasteland)<26219><OcR9zr3BMr0qAQT4AgGS8wAAAAAAAA8Q>: Panic: file mail-index-write.c: line 137 (mail_index_write): assertion failed: (file->hdr.prev_file_seq == hdr->log_file_seq) May 07 16:07:47 imap(inbox@wasteland)<26219><OcR9zr3BMr0qAQT4AgGS8wAAAAAAAA8Q>: Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0xd2621) [0x7f01a4917621] -> /usr/lib/dovecot/libdovecot.so.0(+0xd26c1) [0x7f01a49176c1] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f01a487f093] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_index_write+0x52f) [0x7f01a4cc053f] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_index_sync_commit+0x200) [0x7f01a4cb4590] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync_end+0x2e9) [0x7f01a4c7b139] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_sync+0x5b) [0x7f01a4c7b1eb] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_list_index_refresh_force+0x143) [0x7f01a4c7d4c3] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0xb36e0) [0x7f01a4c7d6e0] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0xb3891) [0x7f01a4c7d891] -> /usr/lib/dovecot/modules/lib20_zlib_plugin.so(+0x3043) [0x7f01a088e043] -> /usr/lib/dovecot/libdovecot-storage.so.0(+0x4a8ec) [0x7f01a4c148ec] -> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_open+0x72) [0x7f01a4c14b02] -> dovecot/imap(cmd_select_full+0x160) [0x5620d32c64c0] -> dovecot/imap(command_exec+0x7c) [0x5620d32ce32c] -> dovecot/imap(+0x1b642) [0x5620d32cc642] -> dovecot/imap(+0x1b6d4) [0x5620d32cc6d4] -> dovecot/imap(client_handle_input+0x1a5) [0x5620d32ccaf5] -> dovecot/imap(client_input+0x82) [0x5620d32cd192] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x75) [0x7f01a4930615] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x109) [0x7f01a4932019] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x56) [0x7f01a4930726] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f01a4930938] -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13) [0x7f01a48a4d43] -> dovecot/imap(main+0x330) [0x5620d32be840] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1) [0x7f01a44c62e1] -> dovecot/imap(_start+0x2a) [0x5620d32bea2a] May 07 16:07:47 imap(inbox@wasteland)<26219><OcR9zr3BMr0qAQT4AgGS8wAAAAAAAA8Q>: Fatal: master: service(imap): child 26219 killed with signal 6 (core dumped) May 07 16:07:57 imap-login: Info: Login: user=inbox@wasteland, method=PLAIN, rip=2a01:4f8:201:92f3::f10, lip=2a01:4f8:201:92f3::f10, mpid=31042, TLS, session=<nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q> May 07 16:07:57 imap(inbox@wasteland)<31042><nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q>: Error: Index file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index: indexid changed: 1620395840 -> 1620395910 May 07 16:07:57 imap(inbox@wasteland)<31042><nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q>: Error: Corrupted transaction log file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index.log seq 3: indexid changed: 1620395840 -> 1620395910 (sync_offset=40) May 07 16:07:57 imap(inbox@wasteland)<31042><nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q>: Error: Transaction log file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index.log: marked corrupted May 07 16:07:57 imap(inbox@wasteland)<31042><nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q>: Error: Index /var/vmail/wasteland/inbox/mdbox/dovecot.list.index: Lost log for seq=3 offset=40: Missing middle file seq=3 (between 3..4294967295, we have seqs 2): Requested newer log than exists: Log inode is unchanged (initial_mapped=0, reason=Index mapped) May 07 16:07:57 imap(inbox@wasteland)<31042><nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q>: Warning: fscking index file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index May 07 16:07:57 imap(inbox@wasteland)<31042><nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q>: Error: Fixed index file /var/vmail/wasteland/inbox/mdbox/dovecot.list.index: log_file_seq 3 -> 2 May 07 16:07:58 imap-login: Info: Login: user=inbox@wasteland, method=PLAIN, rip=2a01:4f8:201:92f3::f10, lip=2a01:4f8:201:92f3::f10, mpid=31044, TLS, session=<M3x49L3BEsMqAQT4AgGS8wAAAAAAAA8Q> May 07 16:07:58 imap(inbox@wasteland)<31042><nMx19L3BEMMqAQT4AgGS8wAAAAAAAA8Q>: Error: Mailbox list index was marked as fsck'd /var/vmail/wasteland/inbox/mdbox/dovecot.list.index May 07 16:07:58 imap(inbox@wasteland)<31044><M3x49L3BEsMqAQT4AgGS8wAAAAAAAA8Q>: Error: Mailbox list index was marked as fsck'd /var/vmail/wasteland/inbox/mdbox/dovecot.list.index
My feeling tells me that mdbox is not very stable. If you hammer hard enough, or your access times are slow enough, or your mailbox is large enough it will eat its own mailbox for breakfast.
Flo
Florian Lohoff f@zz.de Any sufficiently advanced technology is indistinguishable from magic.