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 at eng.sun.com - blogs.sun.com/dp