Signaled to death by 11

[Jeremy Rumpf]

On Wednesday 26 March 2003 05:35 am, Oliver Pitzeier wrote:
> Oliver Pitzeier wrote:
> > > Rob Siemborski wrote:
> > > > > Copying mails between two imap-servers is normally no
> > > > > problem and works with all my servers, except this one...
> > > > >
> > > > > Any ideas?
> > > >
> > > > Do you have a protocol trace of what outlook is feeding cyrus?
> > > > Alternatively, do you have a backtrace of the core dump?
>
> Here we go:
>
> DONE
> 001S OK Completed
> 001Y APPEND "INBOX" (\Seen) "26-Mar-2003 11:12:21 +0100" {8167}
>
> This seems right for me.
>
> Best regards,
>  Oliver

This has been on this list in the past, this post is on an older release, but 
is the problem is the same. The imap server dumps when a message from Outlook 
or Outlook Express is copied to it. Machine is an older alpha ev5.6. Here's a 
recap:


-------------------------------------------------------------------
From: Jeremy Rumpf <jrumpf at heavyload.net>
To: info-cyrus at lists.andrew.cmu.edu
Date: 08/19/02 15:05 pm

Recompiled cyrus with debug support, reproduced the segv, loaded the core file 
into gdb. Here's the goodies:


Copyright 2001 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "alpha-redhat-linux"...
(gdb) core-file core
Core was generated by `imapd -s'.
Program terminated with signal 11, Segmentation fault.
Reading symbols from /usr/lib/libsasl2.so.2...done.
Loaded symbols for /usr/lib/libsasl2.so.2
Reading symbols from /lib/libssl.so.2...done.
Loaded symbols for /lib/libssl.so.2
Reading symbols from /lib/libcrypto.so.2...done.
Loaded symbols for /lib/libcrypto.so.2
Reading symbols from /lib/libdb-3.2.so...done.
Loaded symbols for /lib/libdb-3.2.so
Reading symbols from /lib/libresolv.so.2.1...done.
Loaded symbols for /lib/libresolv.so.2.1
Reading symbols from /lib/libcom_err.so.2...done.
Loaded symbols for /lib/libcom_err.so.2
Reading symbols from /lib/libnsl.so.1.1...done.
Loaded symbols for /lib/libnsl.so.1.1
Reading symbols from /lib/libc.so.6.1...done.
Loaded symbols for /lib/libc.so.6.1
Reading symbols from /lib/libdl.so.2.1...done.
Loaded symbols for /lib/libdl.so.2.1
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /usr/lib/sasl2/libsasldb.so.2...done.
Loaded symbols for /usr/lib/sasl2/libsasldb.so.2
Reading symbols from /usr/lib/sasl2/libcrammd5.so.2...done.
Loaded symbols for /usr/lib/sasl2/libcrammd5.so.2
Reading symbols from /usr/lib/sasl2/libdigestmd5.so.2...done.
Loaded symbols for /usr/lib/sasl2/libdigestmd5.so.2
Reading symbols from /usr/lib/sasl2/libotp.so.2...done.
Loaded symbols for /usr/lib/sasl2/libotp.so.2
Reading symbols from /usr/lib/sasl2/libplain.so.2...done.
Loaded symbols for /usr/lib/sasl2/libplain.so.2
Reading symbols from /lib/libcrypt.so.1.1...done.
Loaded symbols for /lib/libcrypt.so.1.1
Reading symbols from /usr/lib/sasl2/libanonymous.so.2...done.
Loaded symbols for /usr/lib/sasl2/libanonymous.so.2
Reading symbols from /usr/lib/sasl2/liblogin.so.2...done.
Loaded symbols for /usr/lib/sasl2/liblogin.so.2
Reading symbols from /lib/libnss_files.so.2...done.
Loaded symbols for /lib/libnss_files.so.2
Reading symbols from /lib/libnss_ldap.so.2...done.
Loaded symbols for /lib/libnss_ldap.so.2
Reading symbols from /usr/lib/sasl/libanonymous.so...done.
Loaded symbols for /usr/lib/sasl/libanonymous.so
Reading symbols from /usr/lib/sasl/libcrammd5.so...done.
Loaded symbols for /usr/lib/sasl/libcrammd5.so
Reading symbols from /usr/lib/sasl/libdigestmd5.so...done.
Loaded symbols for /usr/lib/sasl/libdigestmd5.so
Reading symbols from /usr/lib/sasl/liblogin.so...done.
Loaded symbols for /usr/lib/sasl/liblogin.so
Reading symbols from /lib/libpam.so.0...done.
Loaded symbols for /lib/libpam.so.0
Reading symbols from /usr/lib/sasl/libplain.so...done.
Loaded symbols for /usr/lib/sasl/libplain.so
#0  0x12006cf0c in tmcomp (atmp=0x0, btmp=0x11fffddd0) at mkgmtime.c:102
102             if ((result = (atmp->tm_year - btmp->tm_year)) == 0 &&
(gdb)
(gdb)
(gdb)
(gdb) bt
#0  0x12006cf0c in tmcomp (atmp=0x0, btmp=0x11fffddd0) at mkgmtime.c:102
#1  0x12006d0e4 in mkgmtime (tmp=0x11fffde60) at mkgmtime.c:138
#2  0x120020c78 in getdatetime (date=0x11fffe0a0) at imapd.c:6870
#3  0x1200104d4 in cmd_append (tag=0x1201a24c0 "000E", name=0x1201a25a0 
"INBOX") at imapd.c:2382
#4  0x120009e20 in cmdloop () at imapd.c:876
#5  0x120009158 in service_main (argc=2, argv=0x11ffff908, envp=0x11ffff920) 
at imapd.c:665
#6  0x120006a4c in main (argc=2, argv=0x11ffff908, envp=0x11ffff920) at 
service.c:464
#7  0x200003a70ec in __libc_start_main (main=0x1200060a0 <main>, argc=2, 
ubp_av=0x11ffff908, init=0x120005890 <_init>, fini=0x2000002e788 
<_dl_debug_mask>, rtld_fini=0xa9,
    stack_end=0x11ffff8f0) at ../sysdeps/generic/libc-start.c:129
(gdb)

-------------------------------------------------------------------

From: Jeremy Rumpf <jrumpf at heavyload.net>
To: info-cyrus at lists.andrew.cmu.edu
Date: 08/19/02 13:49 pm

I've noticed a problem in imapd when interacting with Outlook/Outlook express 
clients via imap.

The outcome of the problem is imapd catching a sigsegv when copying 
(appending) messages to a folder. I originally uncovered the problem, after 
installing cyrus, by attempting to copy all my local messages to cyrus imapd 
by dragging them from the local inbox to the imap inbox on cyrus. In doing 
so, Outlook opens an error box stating, "You message could not be uploaded to 
the imap server. The server refused to accept it". This is consistent with 
both Outlook 2000 (9.0.0.2711) and Outlook Express 6 (6.00.2600). The master 
log simply states:

Aug 19 09:49:31  imapd[2419]: login: rayovac.foo.net[192.168.1.1] m1 
plaintext+TLS
Aug 19 09:49:31  master[991]: process 2419 exited, signaled to death by 11


Further more, the cyrus telemetry logs show the following:


---------- m1 Mon Aug 19 09:49:11 2002

>1029764951>0001 OK User logged in
<1029764951<0002 STATUS "INBOX" (MESSAGES UNSEEN)
>1029764951>* STATUS INBOX (MESSAGES 0 UNSEEN 0)
0002 OK Completed
<1029764951<0003 STATUS "INBOX/bar.us" (MESSAGES UNSEEN)
>1029764951>* STATUS INBOX/bar.us (MESSAGES 0 UNSEEN 0)
0003 OK Completed
<1029764951<0004 STATUS "INBOX/foo.net" (MESSAGES UNSEEN)
>1029764951>* STATUS INBOX/foo.net (MESSAGES 0 UNSEEN 0)
0004 OK Completed
<1029764951<0005 STATUS "INBOX/foo.net/cyrus-list" (MESSAGES UNSEEN)
>1029764951>* STATUS INBOX/foo.net/cyrus-list (MESSAGES 38 UNSEEN 14)
0005 OK Completed
<1029764951<0006 STATUS "INBOX/foo.net/xfree-list" (MESSAGES UNSEEN)
>1029764951>* STATUS INBOX/foo.net/xfree-list (MESSAGES 34 UNSEEN 27)
0006 OK Completed
<1029764951<0007 STATUS "INBOX/foo.com" (MESSAGES UNSEEN)
>1029764951>* STATUS INBOX/foo.com (MESSAGES 2 UNSEEN 0)
0007 OK Completed
<1029764951<ZZZZ LOGOUT
>1029764951>* BYE LOGOUT received
ZZZZ OK Completed
---------- m1 Mon Aug 19 09:49:31 2002

>1029764971>000D OK User logged in
<1029764971<000E APPEND "INBOX" (\Seen) " 9-Aug-2002 11:55:32 -0400" {10132}


In addition to the cyrus telemetry logs. I've also captured the following 
snipped from Outlook 6 by enabling imap logging:


Microsoft Internet Messaging API 6.00.2600.0000
IMAP Log started at 08/19/2002 09:49:58
IMAP: 09:49:58 [db] Connecting to 'foo.net' on port 993.
IMAP: 09:49:58 [db] OnNotify: asOld = 0, asNew = 4, ae = 0
IMAP: 09:49:58 [db] Negotiating secure connection with 'Microsoft Unified 
Security Protocol Provider'.
IMAP: 09:49:58 [db] OnNotify: asOld = 4, asNew = 6, ae = 2
IMAP: 09:49:58 [db] OnNotify: asOld = 6, asNew = 6, ae = 4
IMAP: 09:49:58 [db] OnNotify: asOld = 6, asNew = 5, ae = 2
IMAP: 09:49:58 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 09:49:58 [rx] * OK IMAP4 Ready rayovac.foo.net
IMAP: 09:49:58 [tx] 000C CAPABILITY
IMAP: 09:49:58 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 09:49:58 [rx] * CAPABILITY IMAP4 IMAP4REV1 LITERAL+
IMAP: 09:49:58 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 09:49:58 [rx] 000C OK CAPABILITY
IMAP: 09:49:58 [tx] LOGIN command sent
IMAP: 09:49:59 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 09:49:59 [rx] 000D OK User logged in
IMAP: 09:49:59 [tx] 000E APPEND "INBOX" (\Seen) " 9-Aug-2002 11:55:32 -0400" 
{10132}
IMAP: 09:49:59 [db] Connection to 'foo.net' closed.
IMAP: 09:49:59 [db] OnNotify: asOld = 5, asNew = 0, ae = 5
IMAP: 09:49:59 [db] ERROR: "Your server has unexpectedly terminated the 
connection. Possible causes for this include server problems, network 
problems, or a long period of inactivity.", hr=2148322319


So perhaps it's something with the way Outlook issues the APPEND statement? 
I've performed the same identical steps using Kmail as the client with 
complete success. Dragging and dropping a message in a local folder to a 
folder served by cyrus imapd using Kmail produces the following telemetry 
log:


>1029778580>2374 OK User logged in
<1029778580<2375 LIST "" "%"
>1029778580>* LIST (\HasChildren) "/" "INBOX"
2375 OK Completed (0.005 secs 7 calls)
<1029778580<2376 LIST "" "INBOX"
>1029778580>* LIST (\HasChildren) "/" "INBOX"
2376 OK Completed (0.003 secs 7 calls)
<1029778580<2377 LIST "" "INBOX/%"
>1029778580>* LIST (\HasNoChildren) "/" "INBOX/bar.us"
* LIST (\HasChildren) "/" "INBOX/foo.net"
* LIST (\HasNoChildren) "/" "INBOX/foo.com"
2377 OK Completed (0.002 secs 6 calls)
<1029778580<2378 LIST "" "INBOX/foo.net"
>1029778580>* LIST (\HasChildren) "/" "INBOX/foo.net"
2378 OK Completed (0.002 secs 4 calls)
<1029778580<2379 LIST "" "INBOX/foo.net/%"
>1029778580>* LIST (\HasNoChildren) "/" "INBOX/foo.net/cyrus-list"
* LIST (\HasNoChildren) "/" "INBOX/foo.net/xfree-list"
2379 OK Completed (0.001 secs 3 calls)
<1029778595<2380 NOOP
>1029778595>2380 OK Completed
<1029778603<2381 LIST "" "INBOX"
>1029778603>* LIST (\HasChildren) "/" "INBOX"
2381 OK Completed (0.002 secs 7 calls)
<1029778603<2382 APPEND "INBOX" (\SEEN) {3421}
>1029778603>+ go ahead

Perhaps something with the datastamp, in the append call?

Outlook: APPEND "INBOX" (\Seen) " 9-Aug-2002 11:55:32 -0400" {10132}
Kmail  : APPEND "INBOX" (\SEEN) {3421}


Details on the cyrus server are:

cyrus-imapd-2.1.5
cyrus-sasl-2.1.7

-------------------------------------------------------------------