[Dovecot] [dovecot] Dovecot Migration so far

[Mark Moseley]

We've been doing our own beta testing of Dovecot 2.0-beta4 IMAP (both
direct IMAP and webmail-fronted), and we've had nothing but glowing
compliments from our beta users/victims. I've also been running a lone
box with the latest mercurial build and that's been running just fine
too. All mail data is on NFS, but I've put indexes on the local disk,
which has worked just dandy so far.

Everything's been great and all I've seen amiss are a few random
problems -- all of which are are barely impacting us and I mention
only for the sake of feedback. All boxes are Debian Lenny i386,
running 2.6.33.1.


One oddity is that I see lots of messages like this (I've obfuscated
paths/IPs/usernames, so assume paths are all actually correct) for a
variety of different mailboxes prior to their indexes directory
getting initially created:

Apr 02 13:25:24 imap(mail at box): Error:
creat(/var/tmp/Indexes/14/75/mail at box/dovecot.mailbox.log) failed: No
such file or directory

Judging by the mtimes of the containing directories, the directory was
created a couple of seconds after the error gets logged, so I'm
guessing mailbox_log_alloc is just getting called too early. It
obviously just happens that first time. Doesn't seem to actually be
hurting anything, that I can tell.


One other kind of weird thing I saw was that originally I had my
indexes on a dedicated partition with ext4 (Debian Lenny, i386,
2.6.33.1), I was seeing scattered messages like this:

Mar 29 18:02:38 imap(mail at box): Error: FETCH [] for mailbox INBOX UID
3244 got too little data: 1116 vs 1087383
Mar 29 18:02:38 imap(mail at box): Error: Corrupted index cache file
/var/tmp/Indexes/12/dc/mail at box/.INBOX/dovecot.index.cache: Broken
virtual size for mail UID 3244

The message corresponding with UID 3244 was around 1116 bytes (+32
bytes, IIRC), so no clue where the 1087383. In all the cases of that
error I saw, the lefthand number of bytes was very closer to correct
and the righthand was way way off, and the S= flag in the filename was
correct too. I'm guessing that the random righthand number was just
due to corrupted cache. When I reformatted that partition as ext3, the
error went almost completely away (just a few total over the past few
days, as opposed to a few per hour when it was on ext4). I don't even
have an educated guess as to why that'd happen. A wild guess would be
that ext4's delayed allocation was causing problems.

Even under ext4, it was still pretty rare and only, say, 1 out of 100
imap logins. And ext3 performance on the indexes partition so far has
been just fine, so I don't plan on switching back to ext4 -- though if
anyone has any experience with putting indexes on reiserfs and/or xfs
versus ext3, I'd love to hear your thoughts.


I've also seen a couple of these in the past few days (on beta4, not
repo version -- haven't been running repo version long enough to say
if it'd do the same):

Mar 31 21:52:54 imap(mail at box): Error:
fdatasync(/mail/username/mail at box/Maildir/dovecot-uidlist) failed:
Input/output error
Mar 31 21:52:54 imap(mail at box): Error: Raw backtrace:
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot.so.0 [0xb77c0b71] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot.so.0 [0xb77c0bef] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot.so.0(i_error+0)
[0xb77c0ea8] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(mail_index_sync_begin_to+0x9a9)
[0xb7837ca9] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(mail_index_sync_begin+0x56)
[0xb7837d56] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(maildir_sync_index_begin+0x51)
[0xb78734d1] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0
[0xb78716eb] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(maildir_storage_sync_force+0x4d)
[0xb78719bd] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(maildir_uidlist_lookup+0x96)
[0xb7877646] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0
[0xb787215a] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(maildir_sync_index+0x7f0)
[0xb78729d0] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0
[0xb78715b6] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(maildir_storage_sync_init+0x162)
[0xb7871b92] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot-storage.so.0(mailbox_sync_init+0x39)
[0xb7815759] -> dovecot/imap [mail at box 215.108.28.102
UID](imap_sync_init+0x54) [0x805efa4] -> dovecot/imap [mail at box
215.108.28.102 UID](cmd_sync_delayed+0x223) [0x805f2a3] ->
dovecot/imap [mail at box 215.108.28.102 UID](client_output+0xb6)
[0x8056de6] -> /opt/dovecot-2.0.beta4/lib/dovecot/libdovecot.so.0
[0xb77d5d4a] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0xf5)
[0xb77cd1d5] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot.so.0(io_loop_run+0x30)
[0xb77cc220] ->
/opt/dovecot-2.0.beta4/lib/dovecot/libdovecot.so.0(master_service_run+0x2a)
[0xb77b9e1a] -> dovecot/imap [mail at box 215.108.28.102 UID](main+0x1c5)
[0x805f8e5] -> /lib/libc.so.6(__libc_start_main+0xe5) [0xb764d455] ->
dovecot/imap [mail at box 215.108.28.102 UID] [0x804e621]
Mar 31 21:52:54 master: Error: service(imap): child 4500 killed with
signal 6 (core dumps disabled)

In 4 days of beta testing with a fair number of users, I've seen maybe
4 of these backtraces total, so not exactly a big issue.


These are all super minor things. Everything's been fantastic so far.