[MM3-users] Re: Huge performance issue: Mailman doesn't (seem to) receive any mails.

20 Sep 2019

      Mark Sapiro wrote:
...
This seems to say that the Postfix container can connect to
172.19.199.2:8024 and receive the greeting from Mailman's lmtp runner.
So, why can't Postfix send to 172.19.199.2:8024?
That is why I figured that the problem could be Mailman bloking for more mails, somhow.
...
The only log entry you
postes just says "Sep 18 10:07:47 postfix postfix/qmgr[98]: warning:
mail for [172.19.199.2]:8024 is using up 7844 of 7844 active queue entries".
What other log entries relate to attempts to send to 172.19.199.2:8024?
You may have to go back to when this first started to see them.
Docker deleted it's log when restaring, as the container is deleted and removed, but the starte of the current log says:
Sep 18 13:28:57 postfix rsyslogd: [origin software="rsyslogd" swVersion="7.4.7" x-pid="20" x-info="http://www.rsyslog.com"] start
Sep 18 13:29:00 postfix postfix/postfix-script[94]: starting the Postfix mail system
Sep 18 13:29:00 postfix postfix/master[96]: daemon started -- version 2.10.1, configuration /etc/postfix
Sep 18 13:29:02 postfix postfix/smtpd[102]: connect from incoming.gateway.example.com[192.168.111.222]
Sep 18 13:29:04 postfix postfix/smtpd[102]: EFF017E9D65AE: client=incoming.gateway.example.com[192.168.111.222]
Sep 18 13:29:04 postfix postfix/cleanup[106]: EFF017E9D65AE: message-id=&lt;2E40950170CA0A4A8D0F0C0CF1C0630601B8B9F412@P1KITMBX03WC02.unicph.domain>
Sep 18 13:29:04 postfix opendkim[19]: EFF017E9D65AE: incoming.gateway.example.com [192.168.111.222] not internal
Sep 18 13:29:04 postfix opendkim[19]: EFF017E9D65AE: not authenticated
Sep 18 13:29:04 postfix postfix/smtpd[102]: disconnect from incoming.gateway.example.com[192.168.111.222]
Sep 18 13:29:18 postfix postfix/qmgr[98]: 0E53F7E9D7D8D: from=&lt;>, size=212010, nrcpt=1 (queue active)
Sep 18 13:29:18 postfix postfix/qmgr[98]: C51DE7E9920B8: from=&lt;>, size=212004, nrcpt=1 (queue active)
Sep 18 13:29:18 postfix postfix/qmgr[98]: 2923A7E99B41F: from=&lt;>, size=212040, nrcpt=1 (queue active)
Sep 18 13:29:18 postfix postfix/qmgr[98]: D0A1E7E981E26: from=&lt;quarantine@messaging.microsoft.com>, size=14542, nrcpt=1 (queue active)
Sep 18 13:29:18 postfix postfix/qmgr[98]: 95FA77E9815A5: from=&lt;>, size=211977, nrcpt=1 (queue active)
Sep 18 13:29:18 postfix postfix/qmgr[98]: 208777E993635: from=&lt;sender@example.com>, size=9826184, nrcpt=1 (queue active)
Sep 18 13:29:18 postfix postfix/qmgr[98]: 757C27E9BD45C: from=&lt;>, size=211997, nrcpt=1 (queue active)
Sep 18 13:29:18 postfix postfix/qmgr[98]: 738C87E9B94BE: from=&lt;>, size=212141, nrcpt=1 (queue active)
[SLIP]
Sep 18 13:32:24 postfix postfix/anvil[103]: statistics: max cache size 1 at Sep 18 13:29:02
Sep 18 13:43:48 postfix postfix/smtpd[992]: connect from gateway[172.19.199.1]
Sep 18 13:43:48 postfix postfix/smtpd[992]: 9E0D37E9D65AF: client=gateway[172.19.199.1]
Sep 18 13:43:48 postfix postfix/cleanup[996]: 9E0D37E9D65AF: message-id=&lt;3e08121bcdf5b0ebeb779a26ab2fe6ef@mailing.einnews.com>
Sep 18 13:43:48 postfix opendkim[19]: 9E0D37E9D65AF: DKIM-Signature field added (s=default, d=sendergateway.example.com)
Sep 18 13:43:48 postfix postfix/smtpd[992]: disconnect from gateway[172.19.199.1]
Sep 18 13:43:48 postfix postfix/qmgr[98]: 9E0D37E9D65AF: from=&lt;sender@example.com>, size=59393, nrcpt=1 (queue active)
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: mail for [172.19.199.2]:8024 is using up 7863 of 7863 active queue entries
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: you may need to reduce lmtp connect and helo timeouts
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: so that Postfix quickly skips unavailable hosts
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: you may need to increase the main.cf minimal_backoff_time and maximal_backoff_time
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: so that Postfix wastes less time on undeliverable mail
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: you may need to increase the master.cf lmtp process limit
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: please avoid flushing the whole queue when you have
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: lots of deferred mail, that is bad for performance
Sep 18 13:43:48 postfix postfix/qmgr[98]: warning: to turn off these warnings specify: qmgr_clog_warn_time = 0

We see the queueing in Postfix as Mailman is not receiving and that this is why Postfix is using up all it's active queue entries.
However, suddenly this morning, everything came alive all by itself. The question left is: What held the flow. If we don't know what held it, it may happen again, so I would really like some help to understand the problem.
Sep 20 07:05:23 postfix opendkim[19]: 23AED7E98F748: incoming.gateway.example.com [192.168.111.222] not internal
Sep 20 07:05:23 postfix opendkim[19]: 23AED7E98F748: not authenticated
Sep 20 07:05:23 postfix postfix/smtpd[20713]: disconnect from incoming.gateway.example.com[192.168.111.222]
Sep 20 07:05:23 postfix postfix/qmgr[16738]: 23AED7E98F748: from=&lt;someone@foo.bar>, size=4379, nrcpt=1 (queue active)
Sep 20 07:05:23 postfix postfix/qmgr[16738]: warning: mail for [172.19.199.2]:8024 is using up 5363 of 5364 active queue entries
Sep 20 07:05:23 postfix postfix/qmgr[16738]: warning: you may need to increase the main.cf lmtp_destination_concurrency_limit from 20
Sep 20 07:05:23 postfix postfix/qmgr[16738]: warning: please avoid flushing the whole queue when you have
Sep 20 07:05:23 postfix postfix/qmgr[16738]: warning: lots of deferred mail, that is bad for performance
Sep 20 07:05:23 postfix postfix/qmgr[16738]: warning: to turn off these warnings specify: qmgr_clog_warn_time = 0
Sep 20 07:05:23 postfix postfix/lmtp[20393]: B64F97E9D0BF4: to=&lt;LISTNAME-bounces@lists.example.com>, relay=172.19.199.2[172.19.199.2]:8024, conn_use=4, delay=663077, delays=659443/3624/1/8.1, dsn=2.0.0, status=sent (250 Ok)
Sep 20 07:05:23 postfix postfix/qmgr[16738]: B64F97E9D0BF4: removed

/ Henrik Rasmussen