Mailman3 stopped sending out mail
Hello.
Recently my mailman3 instance stopped distributing mail. But mailman's own mail (notification, digest etc) and archiving are working OK. I couldn't figure what is going wrong
From mail.log
Dec 31 10:03:20 lists postfix/smtpd[10900]: Anonymous TLS connection established from mail.xxxx.xx[5.79.72.163]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Dec 31 10:03:20 lists postfix/smtpd[10900]: Anonymous TLS connection established from mail.xxxx.xx[5.79.72.163]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Dec 31 10:03:20 lists policyd-spf[10907]: prepend Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=5.79.72.163; helo=mail.xxxx.xx; envelope-from=abhijith@xxxx.xx; receiver=<UNKNOWN> Dec 31 10:03:20 lists policyd-spf[10907]: prepend Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=5.79.72.163; helo=mail.xxxx.xx; envelope-from=abhijith@xxxx.xx; receiver=<UNKNOWN> Dec 31 10:03:21 lists postfix/smtpd[10900]: 04C2412038F: client=mail.xxxx.xx[5.79.72.163] Dec 31 10:03:21 lists postfix/smtpd[10900]: 04C2412038F: client=mail.xxxx.xx[5.79.72.163] Dec 31 10:03:21 lists postfix/cleanup[10912]: 04C2412038F: message-id=f875c144-a23c-baa2-7de2-1b102d3e7494@xxxx.xx Dec 31 10:03:21 lists postfix/cleanup[10912]: 04C2412038F: message-id=f875c144-a23c-baa2-7de2-1b102d3e7494@xxxx.xx Dec 31 10:03:21 lists opendkim[450]: 04C2412038F: s=_teknikKey d=xxxx.xx SSL Dec 31 10:03:21 lists opendkim[450]: 04C2412038F: s=_teknikKey d=xxxx.xx SSL Dec 31 10:03:21 lists postfix/smtpd[10900]: disconnect from mail.xxxx.xx[5.79.72.163] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7 Dec 31 10:03:21 lists postfix/smtpd[10900]: disconnect from mail.xxxx.xx[5.79.72.163] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7 Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: from=abhijith@xxxx.xx, size=1699, nrcpt=1 (queue active) Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: from=abhijith@xxxx.xx, size=1699, nrcpt=1 (queue active) Dec 31 10:03:21 lists postfix/lmtp[10915]: 04C2412038F: to=test3@lists.yyyy.yy, relay=127.0.0.1[127.0.0.1]:8024, delay=0.87, delays=0.62/0.02/0.04/0.2, dsn=2.0.0, status=sent (250 Ok) Dec 31 10:03:21 lists postfix/lmtp[10915]: 04C2412038F: to=test3@lists.yyyy.yy, relay=127.0.0.1[127.0.0.1]:8024, delay=0.87, delays=0.62/0.02/0.04/0.2, dsn=2.0.0, status=sent (250 Ok) Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: removed Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: removed
I am not sure why 'postfix/qmgr[13211]: 04C2412038F: removed' is happening.
from /var/log/mailman3/smtp.log:
Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) handling connection Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'LHLO lists.xxxx.xx' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'MAIL FROM:abhijith@xxxx.xx' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) sender: abhijith@xxxx.xx Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'RCPT TO:test3@xxxx.xx' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) recip: test3@xxxx.xx Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'DATA' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'QUIT' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) connection lost Dec 31 10:03:21 2018 (6323) Connection lost during _handle_client()
Here again I am doubtful about 'Connection lost during _handle_client()'.
Please help.
Abhijith PA
On 12/31/18 2:14 AM, Abhijith PA via Mailman-users wrote:
Recently my mailman3 instance stopped distributing mail. But mailman's own mail (notification, digest etc) and archiving are working OK. I couldn't figure what is going wrong
From mail.log
Dec 31 10:03:20 lists postfix/smtpd[10900]: Anonymous TLS connection established from mail.xxxx.xx[5.79.72.163]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Dec 31 10:03:20 lists postfix/smtpd[10900]: Anonymous TLS connection established from mail.xxxx.xx[5.79.72.163]: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits) Dec 31 10:03:20 lists policyd-spf[10907]: prepend Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=5.79.72.163; helo=mail.xxxx.xx; envelope-from=abhijith@xxxx.xx; receiver=<UNKNOWN> Dec 31 10:03:20 lists policyd-spf[10907]: prepend Received-SPF: Pass (mailfrom) identity=mailfrom; client-ip=5.79.72.163; helo=mail.xxxx.xx; envelope-from=abhijith@xxxx.xx; receiver=<UNKNOWN> Dec 31 10:03:21 lists postfix/smtpd[10900]: 04C2412038F: client=mail.xxxx.xx[5.79.72.163] Dec 31 10:03:21 lists postfix/smtpd[10900]: 04C2412038F: client=mail.xxxx.xx[5.79.72.163] Dec 31 10:03:21 lists postfix/cleanup[10912]: 04C2412038F: message-id=f875c144-a23c-baa2-7de2-1b102d3e7494@xxxx.xx Dec 31 10:03:21 lists postfix/cleanup[10912]: 04C2412038F: message-id=f875c144-a23c-baa2-7de2-1b102d3e7494@xxxx.xx Dec 31 10:03:21 lists opendkim[450]: 04C2412038F: s=_teknikKey d=xxxx.xx SSL Dec 31 10:03:21 lists opendkim[450]: 04C2412038F: s=_teknikKey d=xxxx.xx SSL Dec 31 10:03:21 lists postfix/smtpd[10900]: disconnect from mail.xxxx.xx[5.79.72.163] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7 Dec 31 10:03:21 lists postfix/smtpd[10900]: disconnect from mail.xxxx.xx[5.79.72.163] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7 Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: from=abhijith@xxxx.xx, size=1699, nrcpt=1 (queue active) Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: from=abhijith@xxxx.xx, size=1699, nrcpt=1 (queue active) Dec 31 10:03:21 lists postfix/lmtp[10915]: 04C2412038F: to=test3@lists.yyyy.yy, relay=127.0.0.1[127.0.0.1]:8024, delay=0.87, delays=0.62/0.02/0.04/0.2, dsn=2.0.0, status=sent (250 Ok) Dec 31 10:03:21 lists postfix/lmtp[10915]: 04C2412038F: to=test3@lists.yyyy.yy, relay=127.0.0.1[127.0.0.1]:8024, delay=0.87, delays=0.62/0.02/0.04/0.2, dsn=2.0.0, status=sent (250 Ok) Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: removed Dec 31 10:03:21 lists postfix/qmgr[13211]: 04C2412038F: removed
Aside from the fact that every log message seems to appear twice, this is a normal interaction for an incoming message to test3@lists.yyyy.yy and delivered via lmtp to Mailman.
Is there anything later in the Postfix log for an outgoing message?
I am not sure why 'postfix/qmgr[13211]: 04C2412038F: removed' is happening.
Because Postfix has finished processing the message, has delivered it and has now removed it from the Postfix queue.
from /var/log/mailman3/smtp.log:
Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) handling connection Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'LHLO lists.xxxx.xx' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'MAIL FROM:abhijith@xxxx.xx' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) sender: abhijith@xxxx.xx Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'RCPT TO:test3@xxxx.xx' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) recip: test3@xxxx.xx Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'DATA' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) Data: b'QUIT' Dec 31 10:03:21 2018 (6323) ('127.0.0.1', 48720) connection lost Dec 31 10:03:21 2018 (6323) Connection lost during _handle_client()
This again looks normal other than the fact that the recipient in the Postfix log is test3@lists.yyyy.yy and the recipient here is test3@xxxx.xx. Presumably this is just because you chose to mung the address differently in the two cases.
Here again I am doubtful about 'Connection lost during _handle_client()'.
That's a red herring. Postfix has sent QUIT and one side or the other has disconnected before the response to QUIT was delivered. That's not a problem. This 'Connection lost during _handle_client()' message is a normal occurrence.
It appears that Mailman has received the post. You say above "...archiving are working OK". Does this mean the received post was archived? If so, and it wasn't delivered, either there were no eligible recipients or something went wrong in the pipeline between to-archive and to-outgoing.
Are there messages like
Dec 31 10:03:xx 2018 (6323) <message-id> smtp to test3@xxxx.xx for n recips, completed in n.nn seconds Dec 31 10:03:xx 2018 (6323) <message-id> post to test3@xxxx.xx from test3-bounces@xxxx.xx, nnn bytes
in /var/log/mailman3/smtp.log
What's in /var/log/mailman3/mailman.log?
-- Mark Sapiro mark@msapiro.net The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Hello, I experienced the same after managing this issue: "Re-enable member after bouce processed disable" https://lists.mailman3.org/archives/list/mailman-users@mailman3.org/thread/X... after upgrading frm mailman to mailman3 going from bionic to focal.
I also thought that "Connection lost during _handle_client()" was a problem. Anyway sporadically mails sent to a list seem just to disappear. They just appear in smtp.log. Postfix logs show incoming, but no outgoing mails resulting from it. Maybe lost information on tcp socket?
Think I have to enable debug logs to see whats going on. In the meanwhile I instruct mailing list members to ackknowledge own posts to avoid communicaiton failure. Because there are possible problems with hyperkitty setup I have to cross check this issues too.
On 11/21/23 04:28, webmaster@orcas.de wrote:
Anyway sporadically mails sent to a list seem just to disappear. They just appear in smtp.log. Postfix logs show incoming, but no outgoing mails resulting from it. Maybe lost information on tcp socket?
Is there anything in Mailman's shunt queue? Are there exceptions logged in Mailman's mailman.log?
-- Mark Sapiro mark@msapiro.net The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
as of now I think the same as here: https://lists.mailman3.org/archives/list/mailman-users@mailman3.org/thread/U... Just got it in the logs: "Uncaught runner exception: module 'time' has no attribute 'clock'".
So I have to take a look at python dependencies after checking whole configuration twice again and a few other django exceptions.
On the one hand things would have been clear enough if acknowledgment of own postings was configured. But because the upgrade process unset a lot of defaults there were no missing acknowledgements. Should we add another try catch because of circumstances like this?
On 11/22/23 6:39 AM, webmaster@orcas.de wrote:
as of now I think the same as here: https://lists.mailman3.org/archives/list/mailman-users@mailman3.org/thread/U... Just got it in the logs: "Uncaught runner exception: module 'time' has no attribute 'clock'".
That specific issue is from using Mailman Core < 3.3.0 with Python >= 3.8. Note the current release of Mailman Core is 3.3.9. Releases less than 3.3.0 are over 4 years old.
Should we add another try catch because of circumstances like this?
This is Python, not Perl or PHP. And we do catch exception and log them as we did in this case.
-- Mark Sapiro mark@msapiro.net The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
participants (3)
-
Abhijith PA -
Mark Sapiro -
webmaster＠orcas.de