Hello,
I'm currently using Simon's rpms on a Centos 4 murder setup. For awhile
now, I've been getting (occasionally) 15-20 minutes worth of "Deferred"
messages from sendmail. I never believed it was sendmail, but I've been
having issues proving that. We managed to get the debug_command going in
Cyrus, and have now found that it's lmtpd that's seg faulting, but I'm
still confused as to why.
This happens, like I said, randomly for 15-20 minutes at a time. It will
eventually start delivering fine on it's own. As a matter of fact, any
attempt at restarting services (cyrus, sendmail, etc) or rebooting the
server has NO effect (it will just keep Deferring until it starts
randomly delivering again).
At any rate, I so far have telemetry and strace logs and will paste an
example here. I hope to recompile with debugging and have a gdb
backtrace soon as well, but was wondering if anyone had ideas.
This has been happening for awhile now. It even happened occasionally in
2.2.x tho nowhere near as bad as 2.3.x has been. This also seems to
happen after the "Rcpt to:", either before or during the DATA section.
Example telemetry log:
1154532184>220 XXXXXXXXX.net LMTP Cyrus v2.3.7-Invoca-RPM-2.3.7-2.LN1
ready
<1154532184<LHLO XXXXXXXXXXX.net
1154532184>250-cXXXXXXXXX.net
250-8BITMIME
250-ENHANCEDSTATUSCODES
250-PIPELINING
250-SIZE
250-AUTH EXTERNAL
250 IGNOREQUOTA
<1154532184<MAIL From:<alerts@xxxxxxxxxxxxxx> SIZE=2109
1154532184>250 2.1.0 ok
<1154532184<RCPT To:<stckayak@xxxxxxxxxxxxxxx>
RCPT To:<jrforbes@xxxxxxxxxxxx>
DATA
(and that's the last thing in the telemetry log).
Excerpt from strace:
11:23:04.144071 send(5, "<23>Aug 2 11:23:04 lmtpunix[100"..., 73,
MSG_NOSIGNAL) = 73
11:23:04.144318 open("/var/lib/imap/log/postman/10002",
O_WRONLY|O_APPEND|O_CREAT, 0644) = 8
11:23:04.144569 time(NULL) = 1154532184
11:23:04.144788 write(8, "---------- postman Wed Aug 2 11"..., 45) = 45
11:23:04.145044 select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
11:23:04.145206 time([1154532184]) = 1154532184
11:23:04.145351 write(8, ">1154532184>", 12) = 12
11:23:04.145508 write(8, "220 XXXXXXXXXXX.net LMTP Cyr"..., 72) = 72
11:23:04.145704 write(1, "220 XXXXXXXXXXX.net LMTP Cyr"..., 72) = 72
11:23:04.146082 time(NULL) = 1154532184
11:23:04.146225 select(1, [0], NULL, NULL, {360, 0}) = 1 (in [0], left
{360, 0})
11:23:04.146408 time(NULL) = 1154532184
11:23:04.146532 time(NULL) = 1154532184
11:23:04.146684 read(0, "LHLO XXXXXXXXXXX.net\r\n", 4096) = 26
11:23:04.146856 time([1154532184]) = 1154532184
11:23:04.147030 write(8, "<1154532184<", 12) = 12
11:23:04.147187 write(8, "LHLO XXXXXXXXXX.net\r\n", 26) = 26
11:23:04.147430 select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
11:23:04.147592 time([1154532184]) = 1154532184
11:23:04.147763 write(8, ">1154532184>", 12) = 12
11:23:04.147914 write(8, "250-XXXXXXXXXXX.net\r\n250-8BI"..., 126) = 126
11:23:04.148065 write(1, "250-XXXXXXXXXXX.net\r\n250-8BI"..., 126) = 126
11:23:04.149743 time(NULL) = 1154532184
11:23:04.149893 select(1, [0], NULL, NULL, {360, 0}) = 1 (in [0], left
{360, 0})
11:23:04.150075 time(NULL) = 1154532184
11:23:04.150198 time(NULL) = 1154532184
11:23:04.150317 read(0, "MAIL From:<alerts@XXXXXXXX."..., 4096) = 48
11:23:04.150484 time([1154532184]) = 1154532184
11:23:04.150658 write(8, "<1154532184<", 12) = 12
11:23:04.150822 write(8, "MAIL From:<alerts@XXXXXXX."..., 48) = 48
11:23:04.151030 open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT
(No such file or directory)
11:23:04.151314 select(1, [0], NULL, NULL, {0, 0}) = 0 (Timeout)
11:23:04.151477 time([1154532184]) = 1154532184
11:23:04.151619 write(8, ">1154532184>", 12) = 12
11:23:04.151811 write(8, "250 2.1.0 ok\r\n", 14) = 14
11:23:04.151961 write(1, "250 2.1.0 ok\r\n", 14) = 14
11:23:04.153298 time(NULL) = 1154532184
11:23:04.153442 select(1, [0], NULL, NULL, {360, 0}) = 1 (in [0], left
{360, 0})
11:23:04.153619 time(NULL) = 1154532184
11:23:04.153779 time(NULL) = 1154532184
11:23:04.153902 read(0, "RCPT To:<stckayak@xxxxxxxxxxx>\r\n"..., 4096) = 70
11:23:04.154068 time([1154532184]) = 1154532184
11:23:04.154215 write(8, "<1154532184<", 12) = 12
11:23:04.154364 write(8, "RCPT To:<stckayak@xxxxxxxxxxx>\r\n"..., 70) = 70
11:23:04.154539 open("/var/lib/imap/msg/shutdown", O_RDONLY) = -1 ENOENT
(No such file or directory)
11:23:04.154809 select(7, [6], NULL, NULL, {0, 0}) = 0 (Timeout)
11:23:04.155000 write(6,
"\0\0\0:\305\"K\341U\326w:u4\273hx\263\274\363\374\246\24"..., 62) = 62
11:23:04.155671 time(NULL) = 1154532184
11:23:04.155818 read(6,
"\0\0\0\246\205\3669\356\212\360\351S\260t\305\233\274@"..., 4096) = 170
11:23:04.156045 --- SIGSEGV (Segmentation fault) @ 0 (0) ---
I'll try to post a backtrace of a crashing lmtpd process as soon as I
can, but does anyone have any ideas as to where I can start looking?
Thanks.
Lenny
--"Wisdom is to a man an infinite Treasure" - Anonymous
----
Cyrus Home Page: http://asg.web.cmu.edu/cyrus
Cyrus Wiki/FAQ: http://cyruswiki.andrew.cmu.edu
List Archives/Info: http://asg.web.cmu.edu/cyrus/mailing-list.html
