Bug with sieve and sendmail not properly configured (and possible
fix)
Jesús Roncero
jesus at mxtelecom.com
Mon Feb 5 05:19:15 EST 2007
Hi list,
I have come across a bug that brings down an entire cyrus system when =
using sieve and the sendmail path is misconfigured and pointing to a =
non-existant sendmail executable file. I have set up a testing =
environment where I have been able to reproduce the bug and identify =
part of the "offending" code. I'd like to write what my findings are and =
ask the cyrus developers and community for some insight :-)
Scenario is this:
- Cyrus 2.3.7 configured against sasl and brekeley db 4.2. Using =
berkeley database for delivery.db as well as tls_connections.db. =
singleinstancestore enabled to save disk space. sendmail path configured =
to the default path, and no sendmail executable file on such location.
- A sieve script set up for one user where mail is rejected when coming =
from a specific email address. A simple filter like this:
require ["reject"];
if header :contains ["From"] ["jron at gmail.com"] {
reject "Rejecting your mail";
}
- When a message is dispatched to the cyrus mail system, and the filter =
triggers the rejection, it works for a few times and then, repeating the =
event makes the lmtp process and its child (the one that should run =
sendmail) end up in a frozen state where they no longer accept any =
connections and they are waiting for something to happen with the =
berkeley db.
- The problem gets worse as all available preforked lmtp daemons reach =
the same state while others processes try to access the berkeley db and =
they cannot do it because the lmtpd process have blocked the access to =
the database or something. Restarting cyrus may end up with a corrupted =
database and multiples instances of cyrusdb_ctl running trying to =
recover the database. Imap servers end up not responding as well.
- At this point, all messages are queued at the MTA, trying to deliver =
them all to cyrus through lmtp, including the one to be filtered by sieve.
As I said before I've been able to reproduce the bug in a controlled =
environment and have done some analysis of the source code and might =
have got to the point where this is happening. I also have some gdb =
backtraces, which are attached to this message, so you can see exactly =
where it is happening.
The problem, I think, lies on the file imap/lmtp_sieve.c when the =
function open_sendmail is called, for example on the function =
send_rejection:
sm_pid =3D open_sendmail(smbuf, &sm);
if (sm =3D=3D NULL) {
return -1;
}
returning -1 should be happening when sendmail could not be executed, as =
it can be seen on the function that calls send_rejection. The thing is =
that sm never gets NULL when sendmail has not been executed, in fact, it =
always gets a valid file descriptor. The code for open_sendmail is:
pid_t open_sendmail(const char *argv[], FILE **sm)
{
int fds[2];
FILE *ret;
pid_t p;
pipe(fds);
if ((p =3D fork()) =3D=3D 0) {
/* i'm the child! run sendmail! */
close(fds[1]);
/* make the pipe be stdin */
dup2(fds[0], 0);
execv(config_getstring(IMAPOPT_SENDMAIL), (char **) argv);
/* if we're here we suck */
printf("451 lmtpd: didn't exec() sendmail?!?\r\n");
fatal("couldn't exec() sendmail", EC_OSERR);
}
if (p < 0) {
/* failure */
*sm =3D NULL;
return p;
}
/* parent */
close(fds[0]);
ret =3D fdopen(fds[1], "w");
*sm =3D ret;
return p;
}
in the case of the parent, the call to fdopen to the pipe opened below =
will _always_ return a valid file descriptor, thus, never returning =
NULL. On the other hand, the child calls the function fatal when it =
cannot "execv" the sendmail executable. I guess that the function fatal =
should gracefully kill the running process without doing anything extra, =
but it turns out that fatal does a number of function calls that end up =
trying to close the berkeley db that was opened. This, and the fact that =
the parent also tries to do some stuff with the berkeley db, results in =
both processes blocked while accessing the database and the possibility =
of corrupting the db, as can be seen on the backtraces.
What I've done to fix this is to insert a call to exit just before the =
call to fatal (so this one is never executed):
exit(EXIT_FAILURE);
In any case, I think, it shouldn't matter that anything else is not =
executed on the child process as, on success, the call to execv would =
replace the running process and nothing would be executed that is =
executed on the call to fatal (regarding the database).
I haven't gone that far away into checking all the source code involved =
in this calls, but it would be great if any cyrus developer with more =
expertise on the matter could just have a look at this and check it and, =
if possible, find a more elegant way of dealing with this issue :-).
In my case, calling exit causes cyrus to behave correctly, by printing =
an error message and inserting the message in the INBOX folder, which, I =
guess, is the right thing to do when the rejection sieve filter fails, =
so the mail is not lost, and also, the mail system does not fail because =
of a misconfiguration.
Thanks for reading that far away.
-- =
Jes=FAs Roncero <jesus at mxtelecom.com>
System Developer
Tel: +44 (0) 845 666 7778
http://www.mxtelecom.com
-------------- next part --------------
#0 0x4020163c in __db_shalloc_free () from /lib/libdb-4.2.so
#1 0x402040c2 in __dbreg_teardown () from /lib/libdb-4.2.so
#2 0x401e4493 in __db_refresh () from /lib/libdb-4.2.so
#3 0x401e41c6 in __db_close () from /lib/libdb-4.2.so
#4 0x401f2ed5 in __db_close_pp () from /lib/libdb-4.2.so
#5 0x0809db87 in myclose (db=3D0x815b508) at cyrusdb_berkeley.c:435
#6 0x080725b5 in duplicate_done () at duplicate.c:407
#7 0x0804eab2 in shut_down (code=3D75) at lmtpd.c:913
#8 0x0804e9ec in fatal (s=3D0x80a9507 "couldn't exec() sendmail", code=3D7=
5) at lmtpd.c:883
#9 0x080565e8 in open_sendmail (argv=3D0xbfff90c0, sm=3D0xbfff90fc) at smt=
pclient.c:78
#10 0x08054a9f in send_rejection (origid=3D0x816cec8 "<cmu-lmtpd-3654-11703=
40563-1 at puma>", rejto=3D0x816fdb8 "jron at gmail.com", origreceip=3D0x0,
mailreceip=3D0xbfffa460 "jesus at domain.com", reason=3D0x4166106c "Reject=
ing your mail", file=3D0x816cfb8) at lmtp_sieve.c:234
#11 0x08055351 in sieve_reject (ac=3D0x81679d0, ic=3D0x0, sc=3D0xbfffa650, =
mc=3D0xbfffbcd0, errmsg=3D0xbfff91e0) at lmtp_sieve.c:444
#12 0x0807e1fe in do_action_list (interp=3D0x815b488, body_cache=3D0xbfff92=
00, script_context=3D0xbfffa650, message_context=3D0xbfffbcd0, imapflags=3D=
0xbfff9210,
actions=3D0x8167970, notify_list=3D0x816f040, actions_string=3D0xbfff92=
20 "Action(s) taken:\n", errmsg=3D0x0) at script.c:714
#13 0x0807e881 in sieve_execute_bytecode (exe=3D0x816f010, interp=3D0x815b4=
88, script_context=3D0xbfffa650, message_context=3D0xbfffbcd0) at script.c:=
926
#14 0x0805641f in run_sieve (user=3D0x815c0a8 "jesus", domain=3D0x815c0ae "=
domain.com", mailbox=3D0x0, interp=3D0x815b488, msgdata=3D0xbfffbcd0)
at lmtp_sieve.c:911
#15 0x0804e6d8 in deliver (msgdata=3D0x815b928, authuser=3D0x0, authstate=
=3D0x0) at lmtpd.c:781
#16 0x08052238 in lmtpmode (func=3D0x8132b60, pin=3D0x816d920, pout=3D0x816=
d990, fd=3D0) at lmtpengine.c:1300
#17 0x0804d387 in service_main (argc=3D1, argv=3D0x8158c98, envp=3D0xbffff6=
0c) at lmtpd.c:285
#18 0x0804cff6 in main (argc=3D1, argv=3D0xbffff604, envp=3D0xbffff60c) at =
service.c:532
-------------- next part --------------
(gdb) bt
#0 0x40332812 in select () from /lib/libc.so.6
#1 0x40246448 in ?? () from /lib/libdb-4.2.so
#2 0x00000000 in ?? ()
#3 0x40017f48 in ?? ()
#4 0x4022a115 in __os_sleep () from /lib/libdb-4.2.so
#5 0x4022a23f in __os_yield () from /lib/libdb-4.2.so
#6 0x4018bb60 in __db_tas_mutex_lock () from /lib/libdb-4.2.so
#7 0x4021e89d in __log_txn_lsn () from /lib/libdb-4.2.so
#8 0x4022cb5c in __txn_compensate_begin () from /lib/libdb-4.2.so
#9 0x4022c825 in __txn_begin () from /lib/libdb-4.2.so
#10 0x40206492 in __dbreg_lazy_id () from /lib/libdb-4.2.so
#11 0x401e62f6 in __db_addrem_log () from /lib/libdb-4.2.so
#12 0x401f15c6 in __db_pitem () from /lib/libdb-4.2.so
#13 0x4019561a in __bam_iitem () from /lib/libdb-4.2.so
#14 0x40190a62 in __bam_bulk_duplicates () from /lib/libdb-4.2.so
#15 0x401ec84c in __db_c_put () from /lib/libdb-4.2.so
#16 0x401e51f4 in __db_put () from /lib/libdb-4.2.so
#17 0x401f4ab7 in __db_put_pp () from /lib/libdb-4.2.so
#18 0x0809e5ed in mystore (mydb=3D0x815b508, key=3D0xbfff6c20 "<cmu-sieve-3=
654-1170340563-1 at puma>", keylen=3D63, data=3D0xbfff6bb0 "=EF=BF=BD=EF=BF=BD=
", datalen=3D8, mytid=3D0x0,
putflags=3D0, txnflags=3D256) at cyrusdb_berkeley.c:746
#19 0x0809e7bd in store_nosync (db=3D0x815b508, key=3D0xbfff6c20 "<cmu-siev=
e-3654-1170340563-1 at puma>", keylen=3D63, data=3D0xbfff6bb0 "=EF=BF=BD=EF=BF=
=BD", datalen=3D8, tid=3D0x0)
at cyrusdb_berkeley.c:820
#20 0x08072090 in duplicate_mark (id=3D0xbfff70c0 "<cmu-sieve-3654-11703405=
63-1 at puma>", idlen=3D34, to=3D0x813b2a0 ".jesus at domain.com.sieve.", tolen=
=3D27,
mark=3D1170340563, uid=3D0) at duplicate.c:198
#21 0x08054b6b in send_rejection (origid=3D0x816cec8 "<cmu-lmtpd-3654-11703=
40563-1 at puma>", rejto=3D0x816fdb8 "jron at gmail.com", origreceip=3D0x0,
mailreceip=3D0xbfffa460 "jesus at domain.com", reason=3D0x4166106c "Reject=
ing your mail", file=3D0x816cfb8) at lmtp_sieve.c:245
#22 0x08055351 in sieve_reject (ac=3D0x81679d0, ic=3D0x0, sc=3D0xbfffa650, =
mc=3D0xbfffbcd0, errmsg=3D0xbfff91e0) at lmtp_sieve.c:444
#23 0x0807e1fe in do_action_list (interp=3D0x815b488, body_cache=3D0xbfff92=
00, script_context=3D0xbfffa650, message_context=3D0xbfffbcd0, imapflags=3D=
0xbfff9210,
actions=3D0x8167970, notify_list=3D0x816f040, actions_string=3D0xbfff92=
20 "Action(s) taken:\n", errmsg=3D0x0) at script.c:714
#24 0x0807e881 in sieve_execute_bytecode (exe=3D0x816f010, interp=3D0x815b4=
88, script_context=3D0xbfffa650, message_context=3D0xbfffbcd0) at script.c:=
926
#25 0x0805641f in run_sieve (user=3D0x815c0a8 "jesus", domain=3D0x815c0ae "=
domain.com", mailbox=3D0x0, interp=3D0x815b488, msgdata=3D0xbfffbcd0)
at lmtp_sieve.c:911
#26 0x0804e6d8 in deliver (msgdata=3D0x815b928, authuser=3D0x0, authstate=
=3D0x0) at lmtpd.c:781
#27 0x08052238 in lmtpmode (func=3D0x8132b60, pin=3D0x816d920, pout=3D0x816=
d990, fd=3D0) at lmtpengine.c:1300
#28 0x0804d387 in service_main (argc=3D1, argv=3D0x8158c98, envp=3D0xbffff6=
0c) at lmtpd.c:285
#29 0x0804cff6 in main (argc=3D1, argv=3D0xbffff604, envp=3D0xbffff60c) at =
service.c:532
More information about the Info-cyrus
mailing list