[Dovecot] "Broken mailbox list" with virtual plugin
Hi,
I'm using the virtual plugin for a virtual inbox (with dovecot 1.2, r8980), whose dovecot-virtual file looks as follows:
INBOX INBOX/Lists INBOX/Bulk INBOX/MaybeSpam Folders/TODO all
Everything seems to work fine, but I get the following error in my logfiles:
IMAP(matthijs): virtual /home/matthijs/Mail/virtual/INBOX: Broken mailbox list
Some investigation of the source code tells me that this error means that there was corrupt data in the index. In particular, the ext_data read from the index was not long enough to contain all mailbox names. Adding some debug code confirms this:
ext_size: 187 ext_data: \b0\5\0\0\5\0\0\0E\0\0\0\17\20w\9c\1\0\0\0\5\0\0\0\e9\af\e4I\92\1\0 \0\e7\2\0\0\0\0\0\0\7\0\0\0\b\0\0\0\e8\af\e4IO\3\0\0\5c\5\0\0\0\0\0 \0\8\0\0\0\a\0\0\0\ed\af\e4I\e6\0\0\0j\1\0\0\0\0\0\0\9\0\0\0\f\0\0 \0\3a\b0\e4I1\0\0\0e\0\0\0\0\0\0\0E\0\0\0\c\0\0\0\eb\af\e4I\c8\0\0 \0e\0\0\0\0\0\0\0INBOXINBOX/ListsINBOX/BulkINBOX/MaybeSpamFolders/TO ext_hdr: change_counter=1456 mailbox_count=5 highest_mailbox_id=69 search_args_crc32=2625052695 mailbox: id=1 name_len=5 uid_validity=1239724009 next_uid=402 higest_modseq=743 mailbox name: INBOX mailbox: id=7 name_len=11 uid_validity=1239724008 next_uid=847 higest_modseq=1372 mailbox name: INBOX/Lists mailbox: id=8 name_len=10 uid_validity=1239724013 next_uid=230 higest_modseq=362 mailbox name: INBOX/Bulk mailbox: id=9 name_len=15 uid_validity=1239724090 next_uid=49 higest_modseq=101 mailbox name: INBOX/MaybeSpam mailbox: id=69 name_len=12 uid_validity=1239724011 next_uid=200 higest_modseq=101 virtual /home/matthijs/Mail/virtual/INBOX: Broken mailbox list
As you can see in the ext_data dump, the last mailbox name (Folders/TODO) is cut short. I'm not so sure what caused this error.
I've just tried removing the index files, which seems to fix the error message. The index file gets recreated and my debug statements show proper output. Another solution is adding an extra file to the folder list, in which case the index will get fixed as well.
Perhaps it would be good to recreate the index file when this error is found, instead of complaining?
Also, from the code (virtual_sync_ext_header_read in src/virtual/virtual-sync.c) it seems that the last mailbox should be skipped because of this error, but the mailbox works fine. I'm probably not looking closely enough :-)
I haven't been able to reliably break the index file with some quick testing (reconnecting, restarting and modifying the mailbox list), but I did manage to break it once (by removing a mailbox from halfway the list, and then adding it again). I couldn't reproduce that, though, since removing a mailbox doesn't always seem to recreate the index for some reason...
I've also just upgraded to the latest version, so if this is a bug fixed between r8980 and r9018, then you'll probably not hear from me again :-)
I hope all this info helps a bit, I'm available for further debugging and testing (also on IRC, nick is blathijs).
Gr.
Matthijs
Hi,
I just noticed another error in the log, something somewhat more serious:
Panic: file virtual-sync.c: line 524: unreached Raw backtrace: imap [0x80efa61] -> imap [0x80efae2] -> imap [0x80ef469] -> /usr/lib/dovecot/modules/imap/lib20_virtual_plugin.so [0xb7e5f762] -> /usr/lib/dovecot/modules/imap/lib20_virtual_plugin.so(virtual_storage_sync_init+0x122d) [0xb7e60cbd] -> imap(mailbox_sync+0x32) [0x80b4ad2] -> imap(cmd_close+0x9a) [0x8060b7a] -> imap [0x806717c] -> imap [0x8067219] -> imap(client_handle_input+0x1d) [0x806785d] -> imap(client_input+0x63) [0x8067d13] -> imap(io_loop_handler_run+0xe0) [0x80f8660] -> imap(io_loop_run+0x20) [0x80f7af0] -> imap(main+0x5e5) [0x8070635] -> /lib/libc.so.6(__libc_start_main+0xe5) [0xb7e7b455] -> imap [0x805fc61] child 17088 (imap) killed with signal 6 (core dumps disabled)
I'm not quite sure what I was doing when this error occured, I don't think I did anything in particular. I did remove a mailbox from the virtual list (that I put there for debugging), but that was some time before this error ocurred IIRC.
Gr.
Matthijs
On Wed, 2009-05-06 at 11:06 +0200, Matthijs Kooijman wrote:
virtual /home/matthijs/Mail/virtual/INBOX: Broken mailbox list .. I've just tried removing the index files, which seems to fix the error message. The index file gets recreated and my debug statements show proper output. Another solution is adding an extra file to the folder list, in which case the index will get fixed as well.
Perhaps it would be good to recreate the index file when this error is found, instead of complaining?
That's what it should have done. I just tested and it did successfully update the index file without complaining about anything again. Anyway I added some more checks to the code now.
Also, from the code (virtual_sync_ext_header_read in src/virtual/virtual-sync.c) it seems that the last mailbox should be skipped because of this error, but the mailbox works fine. I'm probably not looking closely enough :-)
It then handles it the same way as newly seen mailboxes. Gives a new mailbox ID and syncs it from the beginning.
I haven't been able to reliably break the index file with some quick testing (reconnecting, restarting and modifying the mailbox list), but I did manage to break it once (by removing a mailbox from halfway the list, and then adding it again). I couldn't reproduce that, though, since removing a mailbox doesn't always seem to recreate the index for some reason...
I tried stress testing by having it open "*" mailboxes and then randomly creating and deleting them. Didn't seem to cause broken virtual index file.
participants (2)
-
Matthijs Kooijman
-
Timo Sirainen