ippaso wrote:
>SP ha scritto:
>
>> Ok, thanks: I will patch mailman immediately and post here the 'error'
>> log as soon as the error appears again.
>
>Here the relevant part of mailman 'error' log (the time of the last sent
>message is 22.29 and the time of the first message which gets stuck in
>qfiles/out is 22.30):
<snip>
The following are the connect to start sending the last message
successfully sent.
>Feb 03 22:32:14 2008 qrunner(20175): connect: ('localhost', 25)
>Feb 03 22:32:14 2008 qrunner(20175): connect: ('localhost', 25)
Qmail is busy here too. Reply to connect takes 41 seconds.
>Feb 03 22:32:55 2008 qrunner(20175): reply: '220 MYDOMAIN ESMTP\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: retcode (220); Msg: MYDOMAIN
>ESMTP
And the connect succeeded and we begin to send.
>Feb 03 22:32:55 2008 qrunner(20175): connect: MYDOMAIN ESMTP
>Feb 03 22:32:55 2008 qrunner(20175): send: 'ehlo www.MYDOMAIN\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250-MYDOMAIN\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250-AUTH LOGIN CRAM-MD5
>PLAIN\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250-AUTH=LOGIN CRAM-MD5
>PLAIN\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250-STARTTLS\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250-PIPELINING\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250 8BITMIME\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: retcode (250); Msg: MYDOMAIN
>AUTH LOGIN CRAM-MD5 PLAIN
>AUTH=LOGIN CRAM-MD5 PLAIN
>STARTTLS
>PIPELINING
>8BITMIME
>Feb 03 22:32:55 2008 qrunner(20175): send: 'mail
>FROM:<[EMAIL PROTECTED]>\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250 ok\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: retcode (250); Msg: ok
>Feb 03 22:32:55 2008 qrunner(20175): send: 'rcpt
>TO:<[EMAIL PROTECTED]>\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '250 ok\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: retcode (250); Msg: ok
>Feb 03 22:32:55 2008 qrunner(20175): send: 'data\r\n'
>Feb 03 22:32:55 2008 qrunner(20175): reply: '354 go ahead\r\n'
>Feb 03 22:32:56 2008 qrunner(20175): reply: retcode (354); Msg: go ahead
>Feb 03 22:32:56 2008 qrunner(20175): data: (354, 'go ahead')
>Feb 03 22:32:56 2008 qrunner(20175): send: 'Return-Path:
><[EMAIL PROTECTED]>\r\nDelivered-To: [EMAIL PROTECTED]:
>(qmail 4288 invoked by uid 511); 3 Feb 2008 22:29:12 +0100\r\nDate: 3
>Feb 2008 22:29:12 +0100\r\nMessage-ID:
><[EMAIL PROTECTED]>\r\nFrom: [EMAIL PROTECTED]:
>[EMAIL PROTECTED]: [Test] Test Sun Feb 3 22:29:12 CET
>2008\r\nX-BeenThere: [EMAIL PROTECTED]:
>2.1.9\r\nPrecedence: list\r\nList-Id:
><test.MYDOMAIN>\r\nList-Unsubscribe:
><http://MYDOMAIN/mailman/listinfo/test>,\r\n\t<mailto:[EMAIL
>PROTECTED]>\r\nList-Archive:
>
><http://MYDOMAIN/pipermail/test>\r\nList-Post:
><mailto:[EMAIL PROTECTED]>\r\nList-Help:
><mailto:[EMAIL PROTECTED]>\r\nList-Subscribe:
><http://MYDOMAIN/mailman/listinfo/test>,\r\n\t<mailto:[EMAIL
>PROTECTED]>\r\nMIME-Version:
>
>1.0\r\nContent-Type: text/plain;
>charset="iso-8859-1"\r\nContent-Transfer-Encoding:
>quoted-printable\r\nSender: [EMAIL PROTECTED]:
>[EMAIL PROTECTED] Feb 3 22:29:12 CET
>2008\r\n_______________________________________________\r\nTest mailing
>[EMAIL PROTECTED]://MYDOMAIN/mailman/listinfo/test\r\n.\r\n'
Above, we send the message at 22:32:56. We do not receive the reply
below until 22:33:23. Presumably, Qmail spent most of the 27 seconds
doing the spam scanning.
>Feb 03 22:33:23 2008 qrunner(20175): reply: '250 ok 1202074403 qp
>5450\r\n'
>Feb 03 22:33:23 2008 qrunner(20175): reply: retcode (250); Msg: ok
>1202074403 qp 5450
>Feb 03 22:33:23 2008 qrunner(20175): data: (250, 'ok 1202074403 qp 5450')
>Feb 03 22:33:23 2008 qrunner(20175): send: 'quit\r\n'
>Feb 03 22:33:23 2008 qrunner(20175): reply: '221 MYDOMAIN\r\n'
>Feb 03 22:33:23 2008 qrunner(20175): reply: retcode (221); Msg: MYDOMAIN
Now, the message is sent and accepted and we try to connect again to
send the next message.
>Feb 03 22:33:23 2008 qrunner(20175): connect: ('localhost', 25)
>Feb 03 22:33:23 2008 qrunner(20175): connect: ('localhost', 25)
But we receive no reply to our connect and no timeout either, so we are
still waiting.
I'm not sure where the problem is, but it is outside Mailman. The
underlying Python smtplib has issued a tcp/ip connect request to
localhost, port 25 and is waiting for some kind of response, i.e., a
response from the process listening on localhost:25, a tcp/ip refusal
or a tcp/ip timeout. None of these things occur, so we just wait.
I have no idea whether this is an OS issue, a networking issue or a
Qmail issue, but there should eventually be a reply or a timeout.
>Again at the moment of the failure the system load was high since there
>were about 20 simultaneous connections to the smtp server, and
>consequently many spamassassins processes, and from the mailman 'smtp'
>log again it took many time to deliver the last few messages:
>
>
>Feb 03 22:25:10 2008 (20175) <[EMAIL PROTECTED]> smtp
>to test for 1 recips, completed in 3.815 seconds
>Feb 03 22:26:06 2008 (20175) <[EMAIL PROTECTED]> smtp
>to test for 1 recips, completed in 3.451 seconds
>Feb 03 22:31:22 2008 (20175) <[EMAIL PROTECTED]> smtp
>to test for 1 recips, completed in 102.005 seconds
>Feb 03 22:32:14 2008 (20175) <[EMAIL PROTECTED]> smtp
>to test for 1 recips, completed in 52.107 seconds
>Feb 03 22:33:23 2008 (20175) <[EMAIL PROTECTED]> smtp
>to test for 1 recips, completed in 69.000 seconds
68+ of those 69 seconds are in waiting for the initial response to
connect and waiting for reply after sending the message text.
--
Mark Sapiro <[EMAIL PROTECTED]> The highway is for gamblers,
San Francisco Bay Area, California better use your sense - B. Dylan
------------------------------------------------------
Mailman-Users mailing list
[email protected]
http://mail.python.org/mailman/listinfo/mailman-users
Mailman FAQ: http://www.python.org/cgi-bin/faqw-mm.py
Searchable Archives: http://www.mail-archive.com/mailman-users%40python.org/
Unsubscribe:
http://mail.python.org/mailman/options/mailman-users/archive%40jab.org
Security Policy:
http://www.python.org/cgi-bin/faqw-mm.py?req=show&file=faq01.027.htp
