dovecot - Sep 2008 - Panic: IMAP: Trying to allocate 2273345672 bytes

Hi, we're running dovecot 1.1.2 (centos5 32-bit rpm from atrpms) havn't
had any real issues with it, but today it looks like an index has become
badly corrupted. We're seeing this in the logs every time we log in to a
particular account:

2008-09-10T11:56:07+01:00 mail8 dovecot: Panic: IMAP(xxx): Trying to
allocate 2273345672 bytes
2008-09-10T11:56:07+01:00 mail8 dovecot: IMAP(xxx): Raw backtrace:
/usr/libexec/dovecot/imap [0x80d0310] -> /usr/libexec/dovecot/imap
[0x80d036a] -> /usr/libexec/dovecot/imap [0x80cfc2c] ->
/usr/libexec/dovecot/imap [0x80d966c] -> /usr/libexec/dovecot/imap
[0x80ce750] -> /usr/libexec/dovecot/imap(buffer_create_dynamic+0x30)
[0x80ce800] ->
/usr/libexec/dovecot/imap(mail_index_sync_ext_intro+0x4d5) [0x80c0145]
-> /usr/libexec/dovecot/imap(mail_index_sync_record+0x135) [0x80b11b5]
-> /usr/libexec/dovecot/imap(mail_index_sync_map+0x269) [0x80b1d79] ->
/usr/libexec/dovecot/imap(mail_index_map+0x38e) [0x80ab17e] ->
/usr/libexec/dovecot/imap [0x80a825c] ->
/usr/libexec/dovecot/imap(mail_index_open+0x1f4) [0x80a8554] ->
/usr/libexec/dovecot/imap(index_storage_mailbox_open+0x79) [0x809ca39]
-> /usr/libexec/dovecot/imap [0x806d339] -> /usr/libexec/dovecot/imap
[0x806e1fa] -> /usr/libexec/dovecot/imap(mailbox_open+0x49) [0x80a09e9]
-> /usr/libexec/dovecot/imap(cmd_select_full+0xa9) [0x805e459] ->
/usr/libexec/dovecot/imap(cmd_select+0x19) [0x805e629] ->
/usr/libexec/dovecot/imap [0x805fdec] -> /usr/libexec/dovecot/imap
[0x805fe95] -> /usr/libexec/dovecot/imap [0x8060655] ->
/usr/libexec/dovecot/imap(client_input+0x5e) [0x806086e] ->
/usr/libexec/dovecot/imap(io_loop_handler_run+0x100) [0x80d7c80] ->
/usr/libexec/dovecot/imap(io_loop_run+0x28) [0x80d6df8] ->
/usr/libexec/dovecot/imap(main+0x4ac) [0x80683ec] ->
/lib/libc.so.6(__libc_start_main+0xdc) [0x8c8dec] ->
/usr/libexec/dovecot/imap [0x805a171]

This account has about 12 mails in cur, nothing in new. Shortly before
this corruption started, I saw entries like:

2008-09-10T10:20:15+01:00 mail9 dovecot: IMAP(xxx):
/var/spool/mail/supplier_2/xxx/Maildir/dovecot-uidlist: Duplicate file
entry at line 2:
1217249435.M999046P25889.mail7.atlas.pipex.net,W=2673:2,S (uid 1 -> 14)
...

For all the mails in the cur directory.

About our setup: These are on an nfs-mounted file system. It's shared
between two computers and connections are randomly redirected to either
box; so potentially it could be an nfs type corruption issue. Timo, I'll
send you a tarball of the dovecot* files off-list

Thanks,

Mark

--
Mark Zealey -- Shared Hosting Team Leader
Product Development * Webfusion
123-reg.co.uk, webfusion.co.uk, donhost.co.uk, supanames.co.uk

This mail is subject to http://www.gxn.net/disclaimer

I've just found another user that has the exact same error message (same
number of bytes). However, this error only happened once, the user has
logged in successfully since then and there was not an error about the
uidlist having duplicate entries.

Thanks,

Mark

--
Mark Zealey -- Shared Hosting Team Leader
Product Development * Webfusion
123-reg.co.uk, webfusion.co.uk, donhost.co.uk, supanames.co.uk

This mail is subject to http://www.gxn.net/disclaimer 
> -----Original Message-----
> From: dovecot-bounces+mark.zealey=webfusion.com at dovecot.org 
> [mailto:dovecot-bounces+mark.zealey=webfusion.com at dovecot.org]
>  On Behalf Of Mark Zealey
> Sent: 10 September 2008 12:21
> To: dovecot at dovecot.org
> Subject: [Dovecot] Panic: IMAP: Trying to allocate 2273345672 bytes
> 
> Hi, we're running dovecot 1.1.2 (centos5 32-bit rpm from 
> atrpms) havn't
> had any real issues with it, but today it looks like an index 
> has become
> badly corrupted. We're seeing this in the logs every time we 
> log in to a
> particular account:
> 
> 2008-09-10T11:56:07+01:00 mail8 dovecot: Panic: IMAP(xxx): Trying to
> allocate 2273345672 bytes
> 2008-09-10T11:56:07+01:00 mail8 dovecot: IMAP(xxx): Raw backtrace:
> /usr/libexec/dovecot/imap [0x80d0310] -> /usr/libexec/dovecot/imap
> [0x80d036a] -> /usr/libexec/dovecot/imap [0x80cfc2c] ->
> /usr/libexec/dovecot/imap [0x80d966c] -> /usr/libexec/dovecot/imap
> [0x80ce750] -> /usr/libexec/dovecot/imap(buffer_create_dynamic+0x30)
> [0x80ce800] ->
> /usr/libexec/dovecot/imap(mail_index_sync_ext_intro+0x4d5) [0x80c0145]
> -> /usr/libexec/dovecot/imap(mail_index_sync_record+0x135) [0x80b11b5]
> -> /usr/libexec/dovecot/imap(mail_index_sync_map+0x269) [0x80b1d79]
->
> /usr/libexec/dovecot/imap(mail_index_map+0x38e) [0x80ab17e] ->
> /usr/libexec/dovecot/imap [0x80a825c] ->
> /usr/libexec/dovecot/imap(mail_index_open+0x1f4) [0x80a8554] ->
> /usr/libexec/dovecot/imap(index_storage_mailbox_open+0x79) [0x809ca39]
> -> /usr/libexec/dovecot/imap [0x806d339] -> /usr/libexec/dovecot/imap
> [0x806e1fa] -> /usr/libexec/dovecot/imap(mailbox_open+0x49) 
> [0x80a09e9]
> -> /usr/libexec/dovecot/imap(cmd_select_full+0xa9) [0x805e459] ->
> /usr/libexec/dovecot/imap(cmd_select+0x19) [0x805e629] ->
> /usr/libexec/dovecot/imap [0x805fdec] -> /usr/libexec/dovecot/imap
> [0x805fe95] -> /usr/libexec/dovecot/imap [0x8060655] ->
> /usr/libexec/dovecot/imap(client_input+0x5e) [0x806086e] ->
> /usr/libexec/dovecot/imap(io_loop_handler_run+0x100) [0x80d7c80] ->
> /usr/libexec/dovecot/imap(io_loop_run+0x28) [0x80d6df8] ->
> /usr/libexec/dovecot/imap(main+0x4ac) [0x80683ec] ->
> /lib/libc.so.6(__libc_start_main+0xdc) [0x8c8dec] ->
> /usr/libexec/dovecot/imap [0x805a171]
> 
> This account has about 12 mails in cur, nothing in new. Shortly before
> this corruption started, I saw entries like:
> 
> 2008-09-10T10:20:15+01:00 mail9 dovecot: IMAP(xxx):
> /var/spool/mail/supplier_2/xxx/Maildir/dovecot-uidlist: Duplicate file
> entry at line 2:
> 1217249435.M999046P25889.mail7.atlas.pipex.net,W=2673:2,S 
> (uid 1 -> 14)
> ...
> 
> For all the mails in the cur directory.
> 
> About our setup: These are on an nfs-mounted file system. It's shared
> between two computers and connections are randomly redirected 
> to either
> box; so potentially it could be an nfs type corruption issue. 
> Timo, I'll
> send you a tarball of the dovecot* files off-list
> 
> Thanks,
> 
> Mark
> 
> --
> Mark Zealey -- Shared Hosting Team Leader
> Product Development * Webfusion
> 123-reg.co.uk, webfusion.co.uk, donhost.co.uk, supanames.co.uk
> 
> This mail is subject to http://www.gxn.net/disclaimer
>

On 9/10/2008, Mark Zealey (Mark.Zealey at webfusion.com)
wrote:
> About our setup: These are on an nfs-mounted file system. It's shared
> between two computers and connections are randomly redirected to either
> box; so potentially it could be an nfs type corruption issue. Timo,
I'll
> send you a tarball of the dovecot* files off-list
Output of dovecot -n is generally needed when asking for help.

-- 

Best regards,

Charles

On Wed, 2008-09-10 at 12:20 +0100, Mark Zealey wrote:
> 2008-09-10T11:56:07+01:00 mail8 dovecot: Panic: IMAP(xxx): Trying to
> allocate 2273345672 bytes
> 2008-09-10T11:56:07+01:00 mail8 dovecot: IMAP(xxx): Raw backtrace:
> /usr/libexec/dovecot/imap [0x80d0310] -> /usr/libexec/dovecot/imap
> [0x80d036a] -> /usr/libexec/dovecot/imap [0x80cfc2c] ->
> /usr/libexec/dovecot/imap [0x80d966c] -> /usr/libexec/dovecot/imap
> [0x80ce750] -> /usr/libexec/dovecot/imap(buffer_create_dynamic+0x30)
> [0x80ce800] ->
> /usr/libexec/dovecot/imap(mail_index_sync_ext_intro+0x4d5) [0x80c0145]
This should help: http://hg.dovecot.org/dovecot-1.1/rev/aa01f9077178

But as for why the transaction log file contained such a broken record
in the first place:
> About our setup: These are on an nfs-mounted file system. It's shared
> between two computers and connections are randomly redirected to either
> box; so potentially it could be an nfs type corruption issue. Timo,
I'll
> send you a tarball of the dovecot* files off-list
Sounds like it could be because of NFS caching issues. You've set
mail_nfs_index=yes, right? What OS? Linux should be OK, but FreeBSD has
some issues.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 197 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20080910/77ace6de/attachment-0002.bin>

> > About our setup: These are on an nfs-mounted file system. 
> It's shared
> > between two computers and connections are randomly 
> redirected to either
> > box; so potentially it could be an nfs type corruption 
> issue. Timo, I'll
> > send you a tarball of the dovecot* files off-list
> 
> Sounds like it could be because of NFS caching issues. You've set
> mail_nfs_index=yes, right? What OS? Linux should be OK, but 
> FreeBSD has
> some issues.
Thanks for the patch; I've not seen any issues to do with nfs caching
before and we've had this live on very heavily loaded systems for
several months now. We use exim with deliver to deliver the messages
(maildir only). Relevant config:

mail_location: maildir:~/Maildir
mmap_disable: yes
mail_nfs_storage: yes
mail_nfs_index: yes
lock_method: dotlock
maildir_copy_preserve_filename: yes

Linux (centos5.2 w/updates). Mount options:
rw,noatime,nodiratime,hard,intr,rsize=32768,wsize=32768,tcp,nocto

Mark