[Dovecot] Two different issues with dovecot 1.1.13
Hi Timo,
I'm using Debian backports.org dovecot-imapd, 1:1.1.13-2~bpo50+1. I've got two different issues, a reoccurring, seemingly harmless one about "Corrupted index cache file" (boring.txt) and one that went bonkers over the least few days (bt.txt) causing much spamming of the logs.
I've made bt.txt stop happening by just rm'ing dovecot.index* : find Maildir/ -type f -name 'dovecot.index*' -print0 | xargs -0r rm ... which I realise may not be the most helpful thing to have done from your point of view.
Anyway I just wanted to let you know about both of these. If one or both are already known about or already fixed by a later version of Dovecot, great and sorry for the noise! If not, and you want any more information etc., let me know.
Many thanks, Stu.
dovecot: 2009-07-28 10:23:16 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size dovecot: 2009-07-28 10:23:56 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size
dovecot: 2009-07-28 08:05:54 Panic: IMAP(strr): file index-mail-headers.c: line 77 (index_mail_parse_header_finish): assertion failed: ((match[match_idx] & HEADER_MAT CH_FLAG_FOUND) == 0) dovecot: 2009-07-28 08:05:54 Error: IMAP(strr): Raw backtrace: imap [0x48dbf2] -> imap [0x48dc73] -> imap [0x48d346] -> imap(index_mail_parse_header+0x617) [0x4545f7] -> imap [0x483284] -> imap [0x483478] -> imap(i_stream_read+0x2c) [0x491d7c] -> imap(i_stream_read_data+0x46) [0x491f16] -> imap(message_get_body_size+0x108) [0x4885 a8] -> imap [0x4226c3] -> imap(imap_fetch+0x162) [0x420852] -> imap(cmd_fetch+0x23c) [0x41a27c] -> imap [0x41e46c] -> imap [0x41e51d] -> imap [0x41eb25] -> imap(clien t_input+0x63) [0x41efd3] -> imap(io_loop_handler_run+0xcb) [0x49515b] -> imap(io_loop_run+0x18) [0x4945c8] -> imap(main+0x3da) [0x426bea] -> /lib/libc.so.6(__libc_sta rt_main+0xe6) [0x7f0e851941a6] -> imap [0x418859] dovecot: 2009-07-28 08:05:54 Error: child 20007 (imap) killed with signal 6 (core dumps disabled) dovecot: 2009-07-28 08:05:56 Panic: IMAP(strr): file index-mail-headers.c: line 77 (index_mail_parse_header_finish): assertion failed: ((match[match_idx] & HEADER_MAT CH_FLAG_FOUND) == 0) dovecot: 2009-07-28 08:05:56 Error: IMAP(strr): Raw backtrace: imap [0x48dbf2] -> imap [0x48dc73] -> imap [0x48d346] -> imap(index_mail_parse_header+0x617) [0x4545f7] -> imap [0x483284] -> imap [0x483478] -> imap(i_stream_read+0x2c) [0x491d7c] -> imap(i_stream_read_data+0x46) [0x491f16] -> imap(message_get_body_size+0x108) [0x4885 a8] -> imap [0x4226c3] -> imap(imap_fetch+0x162) [0x420852] -> imap(cmd_fetch+0x23c) [0x41a27c] -> imap [0x41e46c] -> imap [0x41e51d] -> imap [0x41eb25] -> imap(clien t_input+0x63) [0x41efd3] -> imap(io_loop_handler_run+0xcb) [0x49515b] -> imap(io_loop_run+0x18) [0x4945c8] -> imap(main+0x3da) [0x426bea] -> /lib/libc.so.6(__libc_sta rt_main+0xe6) [0x7f2edf08b1a6] -> imap [0x418859] dovecot: 2009-07-28 08:05:56 Error: child 20984 (imap) killed with signal 6 (core dumps disabled)
On Tue, 2009-07-28 at 19:17 +0100, Stuart Rowan wrote:
dovecot: 2009-07-28 10:23:16 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size dovecot: 2009-07-28 10:23:56 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size
These are kind of annoying. Apparently they still happens in some conditions, but I've really no idea how to reproduce/fix them. Anyway I'm going to simplify the code in a few months, maybe after that there will be no more cache corruption. :)
dovecot: 2009-07-28 08:05:54 Panic: IMAP(strr): file index-mail-headers.c: line 77 (index_mail_parse_header_finish): assertion failed: ((match[match_idx] & HEADER_MAT CH_FLAG_FOUND) == 0)
This was fixed in v1.1.16 with http://hg.dovecot.org/dovecot-1.1/rev/e596c98605dd
Timo Sirainen wrote, on 28/07/09 19:24:
On Tue, 2009-07-28 at 19:17 +0100, Stuart Rowan wrote:
dovecot: 2009-07-28 10:23:16 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size dovecot: 2009-07-28 10:23:56 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size
These are kind of annoying. Apparently they still happens in some conditions, but I've really no idea how to reproduce/fix them. Anyway I'm going to simplify the code in a few months, maybe after that there will be no more cache corruption. :)
Hi Timo,
Dovecot continues to serve us extremely well: I turned on squat based FTS last week and I am amazed how much snappier Thunderbird's Search is at finding messages now :)
The index corruption issues continues to dog us though. Attached text file shows this corruption (I've masked the differing user names and full paths) as listed by the log file produced since 06:00 this morning.
Cheers, Stu.
tigris:~# dovecot --version ; dovecot --build-options ; perl -pe '$u = 'user'; s/(?<=IMAP\()(\w+)\)/$u)/;s@(?<= /home/local/)(.*?)(?=/dove)@$u/ ... @' </var/log/dovecot/error.log 1.2.9 Build options: ioloop=epoll notify=inotify ipv6 openssl Mail storages: cydir dbox maildir mbox raw shared SQL drivers: mysql postgresql sqlite Passdb: checkpassword ldap pam passwd passwd-file shadow sql Userdb: nss ldap passwd passwd-file prefetch sql static
2010-01-11 08:23:26 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 08:31:51 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: record continues outside its allocated size 2010-01-11 09:13:49 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:15:08 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:17:01 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:17:58 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:49:05 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: record continues outside its allocated size 2010-01-11 09:50:21 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:50:22 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: record continues outside its allocated size 2010-01-11 09:51:01 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:51:10 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:57:20 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 09:58:00 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:02:14 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:04:20 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: record continues outside its allocated size 2010-01-11 10:05:38 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:06:23 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:06:33 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:06:34 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:08:46 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:10:16 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:15:07 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size 2010-01-11 10:18:34 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid field header size 2010-01-11 10:18:42 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: field header names corrupted 2010-01-11 10:21:40 IMAP(user): Error: Corrupted index cache file /home/local/user/ ... /dovecot.index.cache: invalid record size
On Mon, 2010-01-11 at 11:07 +0000, Stuart Rowan wrote:
Timo Sirainen wrote, on 28/07/09 19:24:
On Tue, 2009-07-28 at 19:17 +0100, Stuart Rowan wrote:
dovecot: 2009-07-28 10:23:16 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size dovecot: 2009-07-28 10:23:56 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size .. The index corruption issues continues to dog us though. Attached text file shows this corruption (I've masked the differing user names and full paths) as listed by the log file produced since 06:00 this morning.
What filesystem are you using? NFS or any other remote filesystem?
Timo Sirainen wrote, on 19/01/10 13:09:
On Mon, 2010-01-11 at 11:07 +0000, Stuart Rowan wrote:
Timo Sirainen wrote, on 28/07/09 19:24:
On Tue, 2009-07-28 at 19:17 +0100, Stuart Rowan wrote:
dovecot: 2009-07-28 10:23:16 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size dovecot: 2009-07-28 10:23:56 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size .. The index corruption issues continues to dog us though. Attached text file shows this corruption (I've masked the differing user names and full paths) as listed by the log file produced since 06:00 this morning.
What filesystem are you using? NFS or any other remote filesystem?
XFS as a local filesystem.
Cheers, Stu.
tigris:~# xfs_info /home meta-data=/dev/mapper/data-home--xfs isize=256 agcount=33, agsize=6553536 blks = sectsz=512 attr=0 data = bsize=1024 blocks=209715200, imaxpct=25 = sunit=64 swidth=128 blks naming =version 2 bsize=4096 log =internal bsize=1024 blocks=51200, version=2 = sectsz=512 sunit=64 blks, lazy-count=0 realtime =none extsz=65536 blocks=0, rtextents=0
tigris:~# mount | grep /home /dev/mapper/data-home--xfs on /home type xfs (rw,noatime,logbufs=8)
tigris:~# uname -a Linux tigris 2.6.26-2-amd64 #1 SMP Thu Nov 5 02:23:12 UTC 2009 x86_64 GNU/Linux
tigris:~# cat /etc/debian_version 5.0.3
On Wed, 2010-01-20 at 10:33 +0000, Stuart Rowan wrote:
dovecot: 2009-07-28 10:23:16 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size dovecot: 2009-07-28 10:23:56 Error: IMAP(strr): Corrupted index cache file /home/local/strr/Maildir/dovecot.index.cache: record continues outside its allocated size .. What filesystem are you using? NFS or any other remote filesystem? XFS as a local filesystem.
Weird. See what it logs with the attached patch?
participants (2)
-
Stuart Rowan
-
Timo Sirainen