On 2/12/23 7:11 PM, Viktor Dukhovni wrote:
On Sun, Feb 12, 2023 at 06:49:12PM -0800, David Newman wrote:
Postfix 3.5.17 on Debian 11
Greetings. I could use some help understanding why postfix takes around
60 seconds to accept and forward messages received using submission.
Feb 12 18:02:23 mail10 postfix/submission/smtpd[593931]:
connect from cpe-2.2.2.2.my.wonderful.isp.com[2.2.2.2]
Feb 12 18:02:23 mail10 postfix/submission/smtpd[593931]: <
cpe-2.2.2.2.my.wonderful.isp.com[2.2.2.2]: AUTH PLAIN <sensitive data>
This was just base64 encoded, not encrypted. Posting verbose logging
leaked the password of the user in question, change it promptly. DO NOT
post encoded "AUTH" command content.
No worries. I didn't mention it, but I'd also obfuscated the string
following AUTH PLAIN.
Feb 12 18:02:23 mail10 postfix/submission/smtpd[593931]: send attr
client_name = cpe-2.2.2.2.my.wonderful.isp.com
Feb 12 18:02:23 mail10 postfix/submission/smtpd[593931]: send attr
reverse_client_name = cpe-2.2.2.2.my.wonderful.isp.com
Feb 12 18:02:53 mail10 postfix/submission/smtpd[593931]:
permit_mynetworks: cpe-2.2.2.2.my.wonderful.isp.com 2.2.2.2
The 30s delay suggets a slow "cleanup" or a slow policy service.
Feb 12 18:02:53 mail10 postfix/submission/smtpd[593931]: send attr
client_address = 2.2.2.2
Feb 12 18:02:53 mail10 postfix/submission/smtpd[593931]: send attr
client_name = cpe-2.2.2.2.my.wonderful.isp.com
Feb 12 18:02:53 mail10 postfix/submission/smtpd[593931]: send attr
reverse_client_name = cpe-2.2.2.2.my.wonderful.isp.com
Feb 12 18:03:23 mail10 postfix/submission/smtpd[593931]: >
cpe-2.2.2.2.my.wonderful.isp.com[2.2.2.2]: 250 2.0.0 Ok: queued as >
4PFSKT5m0kzHTbm
Another 30s delay. Your restrictions include:
smtpd_recipient_restrictions =
reject_non_fqdn_recipient
reject_unlisted_recipient
check_policy_service inet:127.0.0.1:7777
permit_mynetworks permit_sasl_authenticated
reject_unauth_destination
check_policy_service inet:127.0.0.1:12340
smtpd_end_of_data_restrictions =
check_policy_service inet:127.0.0.1:7777
The "7777" service is a strong suspect.
Bingo. That service was timing out due to an incorrect database password
in its config file. All good now after entering the correct password and
restarting postfix. Thanks for the pointer!
dn