proxyd crashes while processing a APPEND command

[brong]

From: paul r turgyan
Bugzilla-Id: 2682
Version: 2.2.x
Owner: Ken Murchison

[brong]

From: paul r turgyan

proxyd is segfaulting while processing
an APPEND command.

We are running:
Cyrus IMAP4 Murder v2.2.12
Linux 2.4.31

Here is a backtrace from one of the proxyd core files

(gdb) bt
#0 prot_write (s=0x0,
buf=0xbfffb3a0
"msmx1RtCuWjZFMZPyr1rqdG1ZNURc/Kp5Hy1DTjGzRLlocneImm6kUmGY3PQ
9Oegqv4p+Gmn6zpc\r\njoiozjdxXUeM9NtprRsqu7HXpu9K87u/iQdEd7K4LM2PkI4DfXtWU6vLT2ug
jWdvd3MPw58Ov7Jv\r\nynm/Lngj357Vra34h/4QzTZLecq8LcDPXnmvOdV+K9zo"...,
len=2048)
at prot.c:835
#1 0x0804eaea in pipe_command (s=0x8152f30, optimistic_literal=16384)
at proxyd.c:632
#2 0x08054cf7 in cmd_append (tag=0x8167ce8 "3",
name=0x8167788 "Sent Messages") at proxyd.c:2889
#3 0x08050afd in cmdloop () at proxyd.c:1577
#4 0x080503df in service_main (argc=2, argv=0x813ce68, envp=0xbffff060)
at proxyd.c:1370
#5 0x0804cf5e in main (argc=2, argv=0x808e, envp=0xbffff060) at
service.c:530
#6 0x402658be in __libc_start_main (main=0x804c7c0 <main>, argc=2,
ubp_av=0x808e, init=0x809daf0 <__libc_csu_init>,
fini=0x809db20 <__libc_csu_fini>, rtld_fini=0x9, stack_end=0x8152f30)
at ../sysdeps/generic/libc-start.c:152
(gdb)

(gdb) up
#1 0x0804eaea in pipe_command (s=0x8152f30, optimistic_literal=16384)
at proxyd.c:632
632 proxyd.c: No such file or directory.
in proxyd.c
(gdb) p s
$1 = (struct backend *) 0x8152f30
(gdb) p *s
$2 = {hostname = "jackiebrown.mail.umich.edu", '\0' <repeats 37 times>,
addr = {ss_family = 2, __ss_align = 1896797069,
__ss_padding = '\0' <repeats 119 times>}, sock = -1, context = 0x0,
timeout = 0x0, saslconn = 0x0, tlsconn = 0x0, tlssess = 0x0,
capability = 31, last_result = '\0' <repeats 1023 times>, in = 0x0,
out = 0x0}

(gdb) p eol
$3 = "(\Seen) &quot;16-Jun-2005 08:30:25 -0700&quot; {13045655}\r\n\0?\004\0\0\0XK?lt\0
04\b\b9\025\b3?\0\004\0\0\b9\025\b8Y\026\b\0\0\0\0(3?\ra\a\b\bA\024\b\002\0\0\0
\b9\025\b@\0\0\0\004\0\0\0\001\0\0\0\211a\n\b\0\0\0"
(gdb)

This is how I reproduced it:

Use imtest to open a connection to a proxyd,
and issue an APPEND command w/ a BIG message
like:
110 append Sent (\Seen) {8000197+}
From: proxytest@whocares.com
Date: Tue, 14 Jun 2005 16:56:00 -0400 (EST)
Subject: Die you beast
To: xpaul@openbsd.staff.itd.umich.edu
Message-Id: <B27397-01000000@whocares.com>

1234567890123456789012345678901234567890123456789012345678901234567890123456789
1234567890123456789012345678901234567890123456789012345678901234567890123456789
1234567890123456789012345678901234567890123456789012345678901234567890123456789
1234567890123456789012345678901234567890123456789012345678901234567890123456789
1234567890123456789012345678901234567890123456789012345678901234567890123456789
1234567890123456789012345678901234567890123456789012345678901234567890123456789
1234567890123456789012345678901234567890123456789012345678901234567890123456789
1234567890123456789012345678901234567890123456789012345678901234567890123456789
45678901234567890123456

then wait about 6 minutes, and then enter somemore text.

Wait another 30 minutes or whatever your timeout value is in imapd.conf,
and look around on the frontend for your proxyd core file.

Here is what I think is happening.

proxyd opens a connection to the client.
proxyd opens a connection to the backend.

proxyd starts reading from client, writing to backend.
(this loop is in the function "pipe_command")

client sends some data

client stalls/stops sending data for a while.

5 minutes later proxyd detects no incoming data from the
client and the read operation timesout.

Timeout processing consists of: proxyd.c:892 function backend_timeout.

Proxyd sends "LOGOUT" to backend.
        and waits on reply from backend.

This is dumb,  because the backend is waiting to read the
rest of the "APPEND" command above.

Eventually (30 minutes later),  imapd on the backend gets tired
of waiting for proxyd,  and closes connection.

Proxyd wakes up from read above,  and proceeds to
close down the backend connection,  and all the data
structures associated w/ the backend (tls, sasl, ...).

NOTE:   All of this timeout processing is handled in a "callback"

Upon completion of the timeout processing, if the original
client had spit anything at proxyd during the 30 minute timeout,
the I/O funtions prot_fill and prot_read detect and return the
data to to the funtion pipe_command.

pipe_command tries to write the returned data to the backend,
and blows up because the connection has been closed down, and
the connection data is NULL.

Possible Fixes:
Initial idea is to store/note the "timeout" condition in the protstream
structure, or the "backend" structure and let upper level functions
decide how they want to process the condition. The pipe_command
function would check that the backend connection is still up before
writing to the socket, by checking that the protstream pointers are not
NULL in the backend structure.

Another idea is to close the client stream before/after closing the
backend stream. This could be done in proxyd, but it would affect
the prot routines. The prot_fill routine would have to check to see if
the fd had been closed before issuing the select on line prot.c:423 If
the fd was closed, then prot_fill would return EOF, and the upper
level routines could process the EOF however they like. This is a much
bigger change, because it affects all callers of the prot library.

[brong]

Attachment-Id: 366
From: paul r turgyan
Type: text/plain
File: proxyd.diff

Sets "backend_current" if none set

[brong]

From: Ken Murchison

Fixed in CVS. We no longer timeout "active" backends.