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.

To a small degree because you have unnecessary verbose logging slowing
it down. :-(

> 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.

> 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.

-- 
    Viktor.

Reply via email to