On Wed 07 Mar 2007 at 02:28AM, Timo Sirainen wrote:
http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz.sig
Most importantly this should fix mbox problems in recent RCs.
(Sorry for the long mail)
I've got rc26 up and running on our production box, and we are now migrating users onto it. In a few days we'll see higher user load than we saw in our pilot deployment. So far things look mixed. Some observations:
I'm seeing a lot more imap-login's around than I am used to. Usually there have been just 3; maybe no big deal...? Maybe I made a settings mistake?
# pgrep -x imap-login | wc -l 27 # pgrep -x imap | wc -l 30
I'm seeing a new crash, over and over with one user (I have 580 core files), although gdb is having a tough time getting a backtrace beyond a few frames; I've yet to talk to the user to see what the experience looked like for him.
(gdb) bt full #0 0xfee505a7 in _lwp_kill () from /lib/libc.so.1 No symbol table info available. #1 0xfee4d71b in thr_kill () from /lib/libc.so.1 No symbol table info available. #2 0xfee06502 in raise () from /lib/libc.so.1 No symbol table info available. #3 0xfede4b8d in abort () from /lib/libc.so.1 No symbol table info available. #4 0x080b8ec8 in i_internal_panic_handler (fmt=0x0, args=0x8047024 "\217Â\f\b\230\001") at failures.c:406 backtrace = 0x80e9c68 "0x80b8a2f -> 0x8087b2f -> 0x80830f0 -> 0x80850f2 -> 0x8085560 -> 0x80ad0b0 -> 0x8071296 -> 0x806a1bf -> 0x806a334 -> 0x806ba6e -> 0x806ba02 -> 0x806bbbc -> 0x80be0d9 -> 0x80bdb11 -> 0x8072a08 -> 0x806"... #5 0x080b8a2f in i_panic ( format=0x80d23c0 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:195 No locals. #6 0x08087b2f in mbox_sync_rewrite (sync_ctx=0x8047800, mail_ctx=0x0, end_offset=138189881, move_diff=742, extra_space=The value of variable 'extra_space' is distributed across several locations, and GDB cannot access its value. ) at mbox-sync-rewrite.c:566 mails = (struct mbox_sync_mail *) 0x811dc48 offset = The value of variable 'offset' is distributed across several locations, and GDB cannot access its value. (gdb)
Here is a pstack:
# pstack core.imap.211539.117146 core 'core.imap.211539.117146' of 211539: imap fee505a7 _lwp_kill (1, 6) + 7 fee06502 raise (6) + 22 fede4b8d abort (80fe829, 80e9c68, 8047018, 80b8a2f, 80d23c0, 8047024) + cd 080b8ec8 i_internal_fatal_handler (80d23c0, 8047024, 8047028, 80b7cb6, 80f5568, 8047027) 080b8a2f ???????? (80d23c0, 80cc28f, 198, 80c71ae, 80d2528, a) 08087b2f mbox_sync_rewrite (8047800, 0, 83c9c39, 0, 2e6, 0) + 4f 080830f0 mbox_sync_do (feffcc70, 6799ca3, 98, 1, 29f0cad6, ffffffff) + a84 080850f2 mbox_sync (80fca90, 8, 0, 45f05a57, 80f68a0, 80f6b88) + 40e 08085560 mbox_storage_sync_init (80fca90, 1, 4d3db, 0) + 3c 080ad0b0 mailbox_sync_init (80fca90, 1, 0, 0, 0, 0) + 10 08071296 imap_sync_nonselected (80fca90, 1, 0, 0) + 12 0806a1bf _cmd_select_full (80f6bcc, 0, 22, 8, 806bf90, 22) + 9b 0806a334 cmd_select (80f6bcc, 80fafe0, 7, 80f6bcc) + 10 0806ba6e client_handle_input (80f6b88, 80f6bcc, 8047a48, 806bbab, 2, 80f6b88) + fa 0806ba02 client_handle_input (80bdfdd, 0, 9, 2, 80f5338, 1) + 8e 0806bbbc _client_input (80f6b88, 3, 8047a88, 80be0ce, 1, 1000000) + 74 080be0d9 io_loop_handler_run (80f4380, 0, 80f6b88, 8047c3a) + 131 080bdb11 io_loop_run (80f4380, 1, 80f6498, 32, fee47cd1, fedd63fc) + 21 08072a08 main (1, 8047b18, 8047b20) + 408 08067074 _start (1, 8047c20, 0, 8047c25, 8047c35, 8047c42) + 80
Dovecot is still *really* noisy on endianness switchover, and also I think it has been crashy, too:
Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.imap/INBOX/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/BUGS/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/KRNL/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/OSOL/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/CBLT/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SUST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/MISC/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/ESCS/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/NFST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/FSPT/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/ZFST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/JRSC/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SPAM/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/UFST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PCFS/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index.log: start_offset (6144) > file size (3400) Error: IMAP(foobar): broken sync positions Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index Error: IMAP(foobar): Fixed index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index: log file sync pos 0,0 -> 33554432, 6144 Error: IMAP(foobar): Unexpected transaction log desync with index /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PRTI/dovecot.index.log: start_offset (6144) > file size (2808) Error: IMAP(foobar): Unexpected transaction log desync with index /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PRTI/dovecot.index Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index.cache: indexid changed Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PRTI/dovecot.index.cache: indexid changed Info: imap-login: Disconnected: rip=XXX.9.61.63, lip=XXX.YYY.17.63 Info: imap-login: Disconnected: rip=XXX.9.61.63, lip=XXX.YYY.17.63 Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/.imap/Trash/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/OSOL/dovecot.index.log: unknown record type 0x10 Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/OSOL/dovecot.index Info: IMAP(foobar): Disconnected: Internal error occurred. Refer to server log for more information. [2007-03-07 06:59:21] Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices ... Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/.imap/Sent/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index.log: hdr.size too large (133076088) Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index Error: IMAP(foobar): Unexpected transaction log desync with index /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index Info: IMAP(foobar): Disconnected: Mailbox is in inconsistent state, please relogin. Error: IMAP(foobar): file client.c: line 412 (_client_input): assertion failed: (!client->handling_input) Error: IMAP(foobar): Raw backtrace: 0x80b8fd3 -> 0x806c1da -> 0x8068f2d -> 0x8069169 -> 0x8069222 -> 0x806935f -> 0x806bfd7 -> 0x806bf5e -> 0x806c140 -> 0x80be67d -> 0x80be0b5 -> 0x8072fac -> 0x806722c Error: child 170842 (imap) killed with signal 6 Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SUST/dovecot.index.log: unknown record type 0x0 Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SUST/dovecot.index Info: IMAP(foobar): Disconnected: Internal error occurred. Refer to server log for more information. [2007-03-07 07:02:32] Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar
And on and on. I can live with it, but it'd be nice to have it be detected and dealt with, with perhaps a less alarming message: "{big|little} endian {index|cache} file detected on {little|big} endian system; removing."
Thanks as always,
-dp
-- Daniel Price - Solaris Kernel Engineering - dp@eng.sun.com - blogs.sun.com/dp