dovecot - May 2009 - [bug] dovecot 1.1.15: segfault after message move

Hello,

found the following in my error log:

May 20 13:27:48 ser dovecot: imap-login: Login: user=<juergen>,
method=PLAIN, rip=192.168.0.17, lip=192.168.0.90, TLS
May 20 13:28:10 ser dovecot: Panic: IMAP(juergen): file imap-sync.c: line 439
(cmd_sync_delayed): assertion failed: (client->mailbox != NULL)
May 20 13:28:10 ser dovecot: IMAP(juergen): Raw backtrace: imap [0x80cc01e]
-> imap [0x80cc08a] -> imap [0x80cba78] -> imap [0x806642f] -> imap
[0x80602c1]
May 20 13:28:10 ser dovecot: child 23536 (imap) killed with signal 6 (core dumps
disabled)

it's almost always reproducible using the Heirloom mailx [1] 
mail client, with mutt I get a 'connection closed' message but 
no segfault: 

- login to the dovecot server via imap/imaps
- move a message from INBOX to a another large mbox-file
- quit

Seems to be a new issue introduced with 1.1.15 because I don't
see that with 1.1.14 or older versions. 


Greetings
Juergen

[1] http://heirloom.sourceforge.net/mailx.html


#:> dovecot -n
# 1.1.15: /etc/dovecot.conf
# OS: Linux 2.6.27.23 i686  
base_dir: /var/run/dovecot/
protocols: imap imaps pop3 pop3s
ssl_cert_file: /etc/ssl/certs/dovecot.crt
ssl_key_file: /etc/ssl/keys/dovecot.key
disable_plaintext_auth: no
login_dir: /var/run/dovecot/login
login_executable(default): /usr/lib/dovecot/imap-login
login_executable(imap): /usr/lib/dovecot/imap-login
login_executable(pop3): /usr/lib/dovecot/pop3-login
login_process_per_connection: no
login_processes_count: 1
first_valid_gid: 100
mail_location: mbox:~/Mail:INBOX=/var/spool/mail/%u
mbox_min_index_size: 100
mbox_very_dirty_syncs: yes
mail_executable(default): /usr/lib/dovecot/imap
mail_executable(imap): /usr/lib/dovecot/imap
mail_executable(pop3): /usr/lib/dovecot/pop3
mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
auth default:
  passdb:
    driver: shadow
  userdb:
    driver: passwd


-- 
Juergen Daubert  |  mailto:jue at jue.li  
Korb, Germany    |  http://jue.li/crux

On Wed, May 20, 2009 at 01:47:42PM +0200, Juergen Daubert
wrote:
> Hello,
> 
> found the following in my error log:
> 
> May 20 13:27:48 ser dovecot: imap-login: Login: user=<juergen>,
method=PLAIN, rip=192.168.0.17, lip=192.168.0.90, TLS
> May 20 13:28:10 ser dovecot: Panic: IMAP(juergen): file imap-sync.c: line
439 (cmd_sync_delayed): assertion failed: (client->mailbox != NULL)
> May 20 13:28:10 ser dovecot: IMAP(juergen): Raw backtrace: imap [0x80cc01e]
-> imap [0x80cc08a] -> imap [0x80cba78] -> imap [0x806642f] -> imap
[0x80602c1]
> May 20 13:28:10 ser dovecot: child 23536 (imap) killed with signal 6 (core
dumps disabled)
> 
> it's almost always reproducible using the Heirloom mailx [1] 
> mail client, with mutt I get a 'connection closed' message but 
> no segfault: 
> 
> - login to the dovecot server via imap/imaps
> - move a message from INBOX to a another large mbox-file
> - quit
> 
> Seems to be a new issue introduced with 1.1.15 because I don't
> see that with 1.1.14 or older versions. 
I've done some more tests on that issue and found that I can fix it
if I revert commit http://hg.dovecot.org/dovecot-1.1/rev/78ab57f321c8.

At all it looks like a timing problem to me, because:
- it happens only if large mbox-files are involved
- the box dovecot is running on is very ancient, a 220MHz Cyrix i586

Below is a backtrace of the crash, hope this helps.


Regards
Juergen




#:> gdb /usr/lib/dovecot/imap 27893 

GNU gdb 6.8
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later
<http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show
copying"
and "show warranty" for details.
This GDB was configured as "i686-pc-linux-gnu"...
Attaching to program: /usr/lib/dovecot/imap, process 27893
ptrace: No such process.

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libdl.so.2...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/libnss_files.so.2...done.
Loaded symbols for /lib/libnss_files.so.2
Reading symbols from /usr/lib/libgcc_s.so.1...done.
Loaded symbols for /usr/lib/libgcc_s.so.1
Core was generated by `imap'.
Program terminated with signal 6, Aborted.
[New process 27893]
#0  0xb7e8d450 in raise () from /lib/libc.so.6
(gdb) bt full
#0  0xb7e8d450 in raise () from /lib/libc.so.6
No symbol table info available.
#1  0xb7e8ea2a in abort () from /lib/libc.so.6
No symbol table info available.
#2  0x080cc02e in default_fatal_finish ()
No locals.
#3  0x080cc08a in i_internal_fatal_handler ()
No locals.
#4  0x080cba78 in i_panic ()
No locals.
#5  0x0806642f in cmd_sync_delayed ()
No locals.
#6  0x080602c1 in client_handle_input ()
No locals.
#7  0x08060565 in client_input ()
No locals.
#8  0x080d370b in io_loop_handler_run ()
No locals.
#9  0x080d2c51 in io_loop_run ()
No locals.
#10 0x08067bf0 in main ()
No locals.
(gdb) 

-- 
Juergen Daubert  |  mailto:jue at jue.li  
Korb, Germany    |  http://jue.li/crux

On Wed, 2009-05-20 at 13:47 +0200, Juergen Daubert
wrote:
> May 20 13:28:10 ser dovecot: Panic: IMAP(juergen): file imap-sync.c: line
439 (cmd_sync_delayed): assertion failed: (client->mailbox != NULL)
Does this help? http://hg.dovecot.org/dovecot-1.1/rev/68a7068c7675

-------------- 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/20090524/559c22d8/attachment-0002.bin>

On Sun, May 24, 2009 at 06:10:50PM -0400, Timo Sirainen
wrote:
> On Wed, 2009-05-20 at 13:47 +0200, Juergen Daubert wrote:
> > May 20 13:28:10 ser dovecot: Panic: IMAP(juergen): file imap-sync.c:
line 439 (cmd_sync_delayed): assertion failed: (client->mailbox != NULL)
> 
> Does this help? http://hg.dovecot.org/dovecot-1.1/rev/68a7068c7675
Sorry, no. Now it hangs forever:

 #:>gdb -p 25509
 GNU gdb 6.8
 Copyright (C) 2008 Free Software Foundation, Inc.
 License GPLv3+: GNU GPL version 3 or later
 <http://gnu.org/licenses/gpl.html>
 This is free software: you are free to change and redistribute it.
 There is NO WARRANTY, to the extent permitted by law.  Type "show
 copying"
 and "show warranty" for details.
 This GDB was configured as "i686-pc-linux-gnu".
 Attaching to process 25509
 Reading symbols from /usr/lib/dovecot/imap...done.
 Reading symbols from /lib/libdl.so.2...done.
 Loaded symbols for /lib/libdl.so.2
 Reading symbols from /lib/libc.so.6...done.
 Loaded symbols for /lib/libc.so.6
 Reading symbols from /lib/ld-linux.so.2...done.
 Loaded symbols for /lib/ld-linux.so.2
 Reading symbols from /lib/libnss_files.so.2...done.
 Loaded symbols for /lib/libnss_files.so.2
 0xb7ff9be3 in epoll_wait () from /lib/libc.so.6
 (gdb) bt full
 #0  0xb7ff9be3 in epoll_wait () from /lib/libc.so.6
 No symbol table info available.
 #1  0x080d36a3 in io_loop_handler_run ()
 No locals.
 #2  0x080d2c61 in io_loop_run ()
 No locals.
 #3  0x08067c00 in main ()
 No locals.
 (gdb) 


-- 
Juergen Daubert  |  mailto:jue at jue.li  
Korb, Germany    |  http://jue.li/crux

On May 27, 2009, at 12:53 AM, Max Ivanov wrote:
>>
>> Once more, I changed the behavior so that I actually understand how  
>> it
>> works now :) http://hg.dovecot.org/dovecot-1.1/rev/c3612800cb90
>
> Does it affects 1.2 version?
Yes. It has the same fixes.