Incoming emails from PayPal fail (STARTTLS)

newday · April 2, 2022, 8:11pm

Greetings,

No emails from PayPal seem to be landing into our inboxes. grepping the /var/log/mail.log for paypal produces the following on Mail-in-a-box v0.52

Any thoughts or direction to look for possible causes?
Much appreciated

Apr  2 10:52:44 mail postfix/smtpd[185443]: SSL_accept error from mx4.slc.paypal.com[173.0.84.229]: Connection timed out
Apr  2 10:52:44 mail postfix/smtpd[185443]: lost connection after STARTTLS from mx4.slc.paypal.com[173.0.84.229]
Apr  2 10:52:44 mail postfix/smtpd[185443]: disconnect from mx4.slc.paypal.com[173.0.84.229] ehlo=1 starttls=0/1 commands=1/2
Apr  2 10:55:24 mail postfix/smtpd[186264]: connect from mx4.phx.paypal.com[66.211.170.90]
Apr  2 11:00:24 mail postfix/smtpd[186264]: SSL_accept error from mx4.phx.paypal.com[66.211.170.90]: Connection timed out
Apr  2 11:00:24 mail postfix/smtpd[186264]: lost connection after STARTTLS from mx4.phx.paypal.com[66.211.170.90]
Apr  2 11:00:24 mail postfix/smtpd[186264]: disconnect from mx4.phx.paypal.com[66.211.170.90] ehlo=1 starttls=0/1 commands=1/2
Apr  2 11:06:47 mail postfix/smtpd[188656]: connect from mx1.phx.paypal.com[66.211.170.87]
Apr  2 11:11:47 mail postfix/smtpd[188656]: SSL_accept error from mx1.phx.paypal.com[66.211.170.87]: Connection timed out
Apr  2 11:11:47 mail postfix/smtpd[188656]: lost connection after STARTTLS from mx1.phx.paypal.com[66.211.170.87]
Apr  2 11:11:47 mail postfix/smtpd[188656]: disconnect from mx1.phx.paypal.com[66.211.170.87] ehlo=1 starttls=0/1 commands=1/2
Apr  2 11:13:53 mail postfix/smtpd[189519]: connect from mx3.slc.paypal.com[173.0.84.228]
Apr  2 11:18:53 mail postfix/smtpd[189519]: SSL_accept error from mx3.slc.paypal.com[173.0.84.228]: Connection timed out
Apr  2 11:18:53 mail postfix/smtpd[189519]: lost connection after STARTTLS from mx3.slc.paypal.com[173.0.84.228]
Apr  2 11:18:53 mail postfix/smtpd[189519]: disconnect from mx3.slc.paypal.com[173.0.84.228] ehlo=1 starttls=0/1 commands=1/2
Apr  2 12:09:18 mail postfix/smtpd[198529]: connect from mx4.phx.paypal.com[66.211.170.90]
Apr  2 12:14:18 mail postfix/smtpd[198529]: SSL_accept error from mx4.phx.paypal.com[66.211.170.90]: Connection timed out
Apr  2 12:14:18 mail postfix/smtpd[198529]: lost connection after STARTTLS from mx4.phx.paypal.com[66.211.170.90]
Apr  2 12:14:18 mail postfix/smtpd[198529]: disconnect from mx4.phx.paypal.com[66.211.170.90] ehlo=1 starttls=0/1 commands=1/2
Apr  2 12:17:01 mail postfix/smtpd[198529]: connect from mx3.slc.paypal.com[173.0.84.228]
Apr  2 12:22:01 mail postfix/smtpd[198529]: SSL_accept error from mx3.slc.paypal.com[173.0.84.228]: Connection timed out
Apr  2 12:22:01 mail postfix/smtpd[198529]: lost connection after STARTTLS from mx3.slc.paypal.com[173.0.84.228]
Apr  2 12:22:01 mail postfix/smtpd[198529]: disconnect from mx3.slc.paypal.com[173.0.84.228] ehlo=1 starttls=0/1 commands=1/2
Apr  2 12:41:50 mail postfix/smtpd[203403]: connect from mx0.slc.paypal.com[173.0.84.225]
Apr  2 12:46:51 mail postfix/smtpd[203403]: SSL_accept error from mx0.slc.paypal.com[173.0.84.225]: Connection timed out
Apr  2 12:46:51 mail postfix/smtpd[203403]: lost connection after STARTTLS from mx0.slc.paypal.com[173.0.84.225]
Apr  2 12:46:51 mail postfix/smtpd[203403]: disconnect from mx0.slc.paypal.com[173.0.84.225] ehlo=1 starttls=0/1 commands=1

openletter · April 2, 2022, 8:13pm

Does the MiaB dashboard report any errors, at all?

newday · April 2, 2022, 8:15pm

A new version of Mail-in-a-Box is available
System updates have been installed and a reboot of the machine is required.
Some DNS errors as expected since we’re using external DNS.

newday · April 2, 2022, 8:20pm

I’ll install the MiaB update and reboot, and see if that helps

newday · April 2, 2022, 8:46pm

After upgrading to latest version: v56 and rebooting, the issue remains: paypal emails are not being delivered:

Apr  2 13:37:37 mail postfix/smtpd[2865]: connect from mx1.phx.paypal.com[66.211.170.87]
Apr  2 13:42:37 mail postfix/smtpd[2865]: SSL_accept error from mx1.phx.paypal.com[66.211.170.87]: Connection timed out
Apr  2 13:42:37 mail postfix/smtpd[2865]: lost connection after STARTTLS from mx1.phx.paypal.com[66.211.170.87]
Apr  2 13:42:37 mail postfix/smtpd[2865]: disconnect from mx1.phx.paypal.com[66.211.170.87] ehlo=1 starttls=0/1 commands=1/2

openletter · April 2, 2022, 9:17pm

It looks like PayPal doesn’t want to establish a secure connection. My only guess at the moment is that there is something wrong with the certificate.

newday · April 3, 2022, 7:07am

Hmm, our cert receives an A+ rating on Qualys SSL Report and is not expired. Could it be to strict checking of paypals cert?

newday · April 4, 2022, 3:49pm

It seems like there is a 300 second (5 minute) delay between the connect and the SSL_accept error. This, to me, seems like something is timing out, could it be PayPal is not accepting the postfix connection?

openletter · April 4, 2022, 4:27pm

Have you changed anything on the server from how MiaB configures it? I have emails from PayPal and they go straight through, no problem.

SMTP/ESMTP is fairly worked out at this point and Postfix is a very mature project. These problems will be related to some configuration, networking, or DNS type problem, but not something related to general compatibility.

stylnchris · April 4, 2022, 6:01pm

Are you using your own certificate or LetsEncrypt? Seems like the cert your using might be on the webserver but on on the mail server (postfix).

openletter · April 4, 2022, 6:21pm

For the certificate, you should see something like:

$ grep -e smtpd_tls_cert -e smtpd_tls_key /etc/postfix/main.cf
#smtpd_tls_cert_file=/etc/ssl/certs/ssl-cert-snakeoil.pem
smtpd_tls_cert_file=/home/user-data/ssl/ssl_certificate.pem
#smtpd_tls_key_file=/etc/ssl/private/ssl-cert-snakeoil.key
smtpd_tls_key_file=/home/user-data/ssl/ssl_private_key.pem
$ ll /home/user-data/ssl/{ssl_certificate.pem,ssl_private_key.pem}
lrwxrwxrwx 1 root root   67 Feb 24 03:13 /home/user-data/ssl/ssl_certificate.pem -> /home/user-data/ssl/box.example.com-20220524-a08cbd44.pem
-rw------- 1 root root 1.7K Nov 23  2016 /home/user-data/ssl/ssl_private_key.pem

That is the LE cert (and private key).

newday · April 4, 2022, 7:20pm

I do, and I can see the website and postfix point to the same LetsEncrypt cert.

grep -e smtpd_tls_cert -e smtpd_tls_key /etc/postfix/main.cf

#smtpd_tls_cert_file=/etc/ssl/certs/ssl-cert-snakeoil.pem
smtpd_tls_cert_file=/home/user-data/ssl/ssl_certificate.pem
#smtpd_tls_key_file=/etc/ssl/private/ssl-cert-snakeoil.key
smtpd_tls_key_file=/home/user-data/ssl/ssl_private_key.pem

ll /home/user-data/ssl/{ssl_certificate.pem,ssl_private_key.pem}

lrwxrwxrwx 1 root root   58 Mar 26 03:08 /home/user-data/ssl/ssl_certificate.pem -> /home/user-data/ssl/mail.redacted.com-20220624-a88aa09b.pem
-rw------- 1 root root 1675 Dec 30  2020 /home/user-data/ssl/ssl_private_key.pem

stylnchris · April 4, 2022, 7:25pm

openssl s_client -showcerts -connect mail.example.com:993 -servername mail.example.com

where mail.example.com = your box

Are you getting the letsencrypt cert?

newday · April 4, 2022, 7:57pm

Yes, dovecot seems to be using the LE cert as well.

---
   i:C = US, O = Let's Encrypt, CN = R3
...
 1 s:C = US, O = Let's Encrypt, CN = R3
   i:C = US, O = Internet Security Research Group, CN = ISRG Root X1
...
issuer=C = US, O = Let's Encrypt, CN = R3

---
No client certificate CA names sent
Peer signing digest: SHA256
Peer signature type: RSA-PSS
Server Temp Key: ECDH, P-384, 384 bits
---
SSL handshake has read 4833 bytes and written 761 bytes
Verification: OK
---
New, TLSv1.3, Cipher is TLS_AES_256_GCM_SHA384
Server public key is 2048 bit
Secure Renegotiation IS NOT supported
Compression: NONE
Expansion: NONE
No ALPN negotiated
Early data was not sent
Verify return code: 0 (ok)
---
* OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE AUTH=PLAIN AUTH=LOGIN] Dovecot (Ubuntu) ready.

stylnchris · April 5, 2022, 1:37pm

@newday - Ok, I would have to assume that this isn’t an issue with the certificate.

Did you change anything in your /etc/postfix/main.cf file?

Only thing I can think of is that smtpd_tls_protocols = line was modified somehow being overly restrictive?

can you run this:

cat /etc/postfix/main.cf  | grep smtpd_tls

and compare with what is on my box?

#smtpd_tls_cert_file=/etc/ssl/certs/ssl-cert-snakeoil.pem
smtpd_tls_cert_file=/home/user-data/ssl/ssl_certificate.pem
#smtpd_tls_key_file=/etc/ssl/private/ssl-cert-snakeoil.key
smtpd_tls_key_file=/home/user-data/ssl/ssl_private_key.pem
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_tls_security_level=may
smtpd_tls_auth_only=yes
smtpd_tls_dh1024_param_file=/home/user-data/ssl/dh2048.pem
smtpd_tls_protocols=!SSLv2,!SSLv3
smtpd_tls_ciphers=medium
smtpd_tls_exclude_ciphers=aNULL,RC4
smtpd_tls_received_header=yes
smtpd_tls_mandatory_protocols=!SSLv2,!SSLv3,!TLSv1,!TLSv1.1
smtpd_tls_mandatory_ciphers=high
smtpd_tls_mandatory_exclude_ciphers=aNULL,DES,3DES,MD5,DES+MD5,RC4

stylnchris · April 5, 2022, 2:09pm

Also something you could do quick is scan the site with a SMTP TLS checker.

https://luxsci.com/smtp-tls-checker

newday · April 5, 2022, 3:57pm

Appreciate it. the configs seems to be the same. SMTP TLS checker reports LuxSci does NOT support forced TLS with this domain. so I ran https://github.com/drwetter/testssl.sh against the port 993 and results were acceptable and comparable to my other, non MiaB mailservers where PayPal emails arrive.

#smtpd_tls_cert_file=/etc/ssl/certs/ssl-cert-snakeoil.pem
smtpd_tls_cert_file=/home/user-data/ssl/ssl_certificate.pem
#smtpd_tls_key_file=/etc/ssl/private/ssl-cert-snakeoil.key
smtpd_tls_key_file=/home/user-data/ssl/ssl_private_key.pem
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_tls_security_level=may
smtpd_tls_auth_only=yes
smtpd_tls_dh1024_param_file=/home/user-data/ssl/dh2048.pem
smtpd_tls_protocols=!SSLv2,!SSLv3
smtpd_tls_ciphers=medium
smtpd_tls_exclude_ciphers=aNULL,RC4
smtpd_tls_mandatory_protocols=!SSLv2,!SSLv3,!TLSv1,!TLSv1.1
smtpd_tls_mandatory_ciphers=high
smtpd_tls_mandatory_exclude_ciphers=aNULL,DES,3DES,MD5,DES+MD5,RC4
smtpd_tls_received_header=yes

I wonder if the cert is not the issue, but some kind of IP block on PayPal side, no ip blocks appear in our iptables?

I’m going to enable more verbose logging on postfix by adding smtpd -vvvv to master.cf and see if that can offer more information.

newday · April 5, 2022, 4:31pm

After enabling more verbose logging, from what I can read, it looks like the PayPal mail server is ready to start the TLS, but then postfix doesn’t do anything?

mx1.slc.paypal.com[173.0.84.226]: 220 2.0.0 Ready to start TLS
… and then 5 minutes later
SSL_accept error from mx1.slc.paypal.com[173.0.84.226]: Connection timed out

[removed dict_* logs to fit in forum]
Apr  5 08:59:17 mail postfix/smtpd[682012]: process generation: 727 (727)
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? debug_peer_list
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? fast_flush_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? mynetworks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? permit_mx_backup_networks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? qmqpd_authorized_clients
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? relay_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? smtpd_access_maps
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: smtpd_client_event_limit_exceptions: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: mynetworks ~? debug_peer_list
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: mynetworks ~? fast_flush_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: mynetworks ~? mynetworks
Apr  5 08:59:17 mail postfix/smtpd[682012]: name_mask: host
Apr  5 08:59:17 mail postfix/smtpd[682012]: been_here: 127.0.0.1/32: 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: been_here: public.mail.ip.addr/32: 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: mynetworks_core: 127.0.0.1/32 public.mail.ip.addr/32
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: mynetworks ~? debug_peer_list
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: mynetworks ~? fast_flush_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: mynetworks ~? mynetworks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: relay_domains ~? debug_peer_list
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: relay_domains ~? fast_flush_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: relay_domains ~? mynetworks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: relay_domains ~? permit_mx_backup_networks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: relay_domains ~? qmqpd_authorized_clients
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: relay_domains ~? relay_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? debug_peer_list
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? fast_flush_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? mynetworks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? permit_mx_backup_networks
[removed more dict_* logs to fit in forum]
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_open: sqlite:/etc/postfix/virtual-alias-maps.cf
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_register: sqlite:/etc/postfix/virtual-alias-maps.cf(0,lock|fold_fix|utf8_request) 1
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_register: sqlite:/etc/postfix/virtual-mailbox-maps.cf(0,lock|fold_fix|utf8_request) 2
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? debug_peer_list
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? fast_flush_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? mynetworks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? permit_mx_backup_networks
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? qmqpd_authorized_clients
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? relay_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? smtpd_access_maps
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_register: /etc/postfix/sender-login-maps.cf 1
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 11 got 418
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_load_fp: dbpath = /home/user-data/mail/users.sqlite
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_load_fp: query = SELECT permitted_senders FROM (SELECT permitted_senders, 0 AS priority FROM aliases WHERE source='%s' AND permitted_senders IS NOT NULL UNION SELECT destination AS permitted_senders, 1 AS priority FROM aliases WHERE source='%s' AND permitted_senders IS NULL UNION SELECT email as permitted_senders, 2 AS priority FROM users WHERE email='%s') ORDER BY priority LIMIT 1;
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: dbpath = /home/user-data/mail/users.sqlite
Apr  5 08:59:17 mail postfix/smtpd[682012]: cfg_get_str: /etc/postfix/sender-login-maps.cf: dbpath = /home/user-data/mail/users.sqlite
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: query = SELECT permitted_senders FROM (SELECT permitted_senders, 0 AS priority FROM aliases WHERE source='%s' AND permitted_senders IS NOT NULL UNION SELECT destination AS permitted_senders, 1 AS priority FROM aliases WHERE source='%s' AND permitted_senders IS NULL UNION SELECT email as permitted_senders, 2 AS priority FROM users WHERE email='%s') ORDER BY priority LIMIT 1;
Apr  5 08:59:17 mail postfix/smtpd[682012]: cfg_get_str: /etc/postfix/sender-login-maps.cf: query = SELECT permitted_senders FROM (SELECT permitted_senders, 0 AS priority FROM aliases WHERE source='%s' AND permitted_senders IS NOT NULL UNION SELECT destination AS permitted_senders, 1 AS priority FROM aliases WHERE source='%s' AND permitted_senders IS NULL UNION SELECT email as permitted_senders, 2 AS priority FROM users WHERE email='%s') ORDER BY priority LIMIT 1;
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: result_format = (notfound)
Apr  5 08:59:17 mail postfix/smtpd[682012]: cfg_get_str: /etc/postfix/sender-login-maps.cf: result_format = %s
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: expansion_limit = (notfound)
Apr  5 08:59:17 mail postfix/smtpd[682012]: cfg_get_int: /etc/postfix/sender-login-maps.cf: expansion_limit = 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: domain = (notfound)
Apr  5 08:59:17 mail postfix/smtpd[682012]: cfg_get_str: /etc/postfix/sender-login-maps.cf: domain =
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_open: sqlite:/etc/postfix/sender-login-maps.cf
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_register: sqlite:/etc/postfix/sender-login-maps.cf(0,lock|fold_fix|utf8_request) 1
Apr  5 08:59:17 mail postfix/smtpd[682012]: policy_client_register: name="inet:127.0.0.1:10023" default_action="451 4.3.5 Server configuration problem" max_idle=300 max_ttl=1000 request_limit=0 retry_delay=1 timeout=100 try_limit=2 policy_context=""
Apr  5 08:59:17 mail postfix/smtpd[682012]: auto_clnt_create: transport=inet endpoint=127.0.0.1:10023
Apr  5 08:59:17 mail postfix/smtpd[682012]: attr_clnt_control: new request limit 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: attr_clnt_control: new retry limit 2
Apr  5 08:59:17 mail postfix/smtpd[682012]: attr_clnt_control: new retry delay 1
Apr  5 08:59:17 mail postfix/smtpd[682012]: unknown_helo_hostname_tempfail_action = defer_if_permit
Apr  5 08:59:17 mail postfix/smtpd[682012]: unknown_address_tempfail_action = defer_if_permit
Apr  5 08:59:17 mail postfix/smtpd[682012]: unverified_recipient_tempfail_action = defer_if_permit
Apr  5 08:59:17 mail postfix/smtpd[682012]: unverified_sender_tempfail_action = defer_if_permit
Apr  5 08:59:17 mail postfix/smtpd[682012]: name_mask: 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: tls_high_cipherlist = ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384
Apr  5 08:59:17 mail postfix/smtpd[682012]: mac_parse: ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_eval: const  ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: tls_medium_cipherlist = ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA
Apr  5 08:59:17 mail postfix/smtpd[682012]: mac_parse: ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_eval: const  ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA
[removed more dict_* logs to fit in forum]
Apr  5 08:59:17 mail postfix/smtpd[682012]: mac_parse: no
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_eval: const  no
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_lookup: tls_wildcard_matches_multiple_labels = (notfound)
Apr  5 08:59:17 mail postfix/smtpd[682012]: dict_update: tls_wildcard_matches_multiple_labels = yes
Apr  5 08:59:17 mail postfix/smtpd[682012]: auto_clnt_create: transport=local endpoint=private/tlsmgr
Apr  5 08:59:17 mail postfix/smtpd[682012]: auto_clnt_open: connected to private/tlsmgr
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_enable_read: fd 12
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_extend: fd 12
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_request_timer: set 0x7f0a427b3110 0x55fe6a675110 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_request_timer: set 0x7f0a427b3130 0x55fe6a675110 1000
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr request = seed
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr size = 32
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 12 flush 22
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 12 got 60
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: seed
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: seed
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: lygCDefA7MxGkgnL7C4Bs+7W/6oHjv9U1VdNVY7YJto=
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: (list terminator)
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: (end)
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_request_timer: reset 0x7f0a427b3110 0x55fe6a675110 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr request = policy
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr cache_type = smtpd
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 12 flush 33
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 12 got 34
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: cachable
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: cachable
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 1
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: timeout
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: timeout
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 3600
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: (list terminator)
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: (end)
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? debug_peer_list
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? fast_flush_domains
Apr  5 08:59:17 mail postfix/smtpd[682012]: chroot /var/spool/postfix user postfix
Apr  5 08:59:17 mail postfix/smtpd[682012]: auto_clnt_create: transport=local endpoint=private/anvil
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_request_timer: set 0x7f0a4304db80 0x0 100
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_enable_read: fd 6
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_enable_read: fd 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: watchdog_create: 0x55fe6a6a0d90 18000
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_enable_read: fd 16
Apr  5 08:59:17 mail postfix/smtpd[682012]: watchdog_stop: 0x55fe6a6a0d90
Apr  5 08:59:17 mail postfix/smtpd[682012]: watchdog_start: 0x55fe6a6a0d90
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_loop: time left   5 for 0x7f0a427b3110 0x55fe6a675110
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_loop: time left 100 for 0x7f0a4304db80 0x0
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_loop: time left 1000 for 0x7f0a427b3130 0x55fe6a675110
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_loop: select_delay 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_loop: read fd=6 act=0x7f0a4304daa0 0x6
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_cancel_timer: 0x7f0a4304db80 0x0 100
Apr  5 08:59:17 mail postfix/smtpd[682012]: connection established
Apr  5 08:59:17 mail postfix/smtpd[682012]: master_notify: status 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: name_mask: resource
Apr  5 08:59:17 mail postfix/smtpd[682012]: name_mask: software
Apr  5 08:59:17 mail postfix/smtpd[682012]: connect from mx1.slc.paypal.com[173.0.84.226]
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: mx1.slc.paypal.com: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: 173.0.84.226: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: mx1.slc.paypal.com: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: 173.0.84.226: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: smtp_stream_setup: maxtime=300 enable_deadline=0
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_hostname: smtpd_client_event_limit_exceptions: mx1.slc.paypal.com ~? 127.0.0.0/8
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_hostaddr: smtpd_client_event_limit_exceptions: 173.0.84.226 ~? 127.0.0.0/8
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_hostname: smtpd_client_event_limit_exceptions: mx1.slc.paypal.com ~? [::ffff:127.0.0.0]/104
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_hostaddr: smtpd_client_event_limit_exceptions: 173.0.84.226 ~? [::ffff:127.0.0.0]/104
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_hostname: smtpd_client_event_limit_exceptions: mx1.slc.paypal.com ~? [::1]/128
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_hostaddr: smtpd_client_event_limit_exceptions: 173.0.84.226 ~? [::1]/128
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: mx1.slc.paypal.com: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: 173.0.84.226: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: auto_clnt_open: connected to private/anvil
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_enable_read: fd 19
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr request = connect
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr ident = smtp:173.0.84.226
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 19 flush 41
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 19 got 25
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/anvil: wanted attribute: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/anvil: wanted attribute: count
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: count
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 1
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/anvil: wanted attribute: rate
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: rate
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 1
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/anvil: wanted attribute: (list terminator)
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: (end)
Apr  5 08:59:17 mail postfix/smtpd[682012]: report connect to all milters
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "j"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: result "mail.example.org"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "{daemon_name}"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: result "mail.example.org"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "{daemon_addr}"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: result "public.mail.ip.addr"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "v"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: result "Postfix 3.3.0"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: non-protocol events for protocol version 6:
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: transport=inet endpoint=127.0.0.1:8891
Apr  5 08:59:17 mail postfix/smtpd[682012]: trying... [127.0.0.1]
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_tweak_tcp: TCP_MAXSEG 32741
Apr  5 08:59:17 mail postfix/smtpd[682012]: fd=20: stream buffer size old=0 new=65482
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: my_version=0x6
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: my_actions=0x1ff SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: my_events=0x1fffff SMFIP_NOCONNECT SMFIP_NOHELO SMFIP_NOMAIL SMFIP_NORCPT SMFIP_NOBODY SMFIP_NOHDRS SMFIP_NOEOH SMFIP_NR_HDR SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_RCPT_REJ SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY SMFIP_HDR_LEADSPC
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 20 flush 17
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 20 got 17
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: milter inet:127.0.0.1:8891 version 6
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: events SMFIP_NOHELO SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_HDR_LEADSPC
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: requests SMFIF_ADDHDRS SMFIF_CHGHDRS SMFIF_SETSYMLIST
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_conn_event: milter inet:127.0.0.1:8891: connect mx1.slc.paypal.com/173.0.84.226
Apr  5 08:59:17 mail postfix/smtpd[682012]: event: SMFIC_CONNECT; macros: j=mail.example.org {daemon_name}=mail.example.org {daemon_addr}=public.mail.ip.addr v=Postfix 3.3.0
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 20 flush 138
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 20 got 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: reply: SMFIR_CONTINUE data 0 bytes
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: non-protocol events for protocol version 6:
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: transport=inet endpoint=127.0.0.1:8893
Apr  5 08:59:17 mail postfix/smtpd[682012]: trying... [127.0.0.1]
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_tweak_tcp: TCP_MAXSEG 32741
Apr  5 08:59:17 mail postfix/smtpd[682012]: fd=21: stream buffer size old=0 new=65482
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: my_version=0x6
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: my_actions=0x1ff SMFIF_ADDHDRS SMFIF_CHGBODY SMFIF_ADDRCPT SMFIF_DELRCPT SMFIF_CHGHDRS SMFIF_QUARANTINE SMFIF_CHGFROM SMFIF_ADDRCPT_PAR SMFIF_SETSYMLIST
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: my_events=0x1fffff SMFIP_NOCONNECT SMFIP_NOHELO SMFIP_NOMAIL SMFIP_NORCPT SMFIP_NOBODY SMFIP_NOHDRS SMFIP_NOEOH SMFIP_NR_HDR SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP SMFIP_RCPT_REJ SMFIP_NR_CONN SMFIP_NR_HELO SMFIP_NR_MAIL SMFIP_NR_RCPT SMFIP_NR_DATA SMFIP_NR_UNKN SMFIP_NR_EOH SMFIP_NR_BODY SMFIP_HDR_LEADSPC
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 21 flush 17
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 21 got 17
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: milter inet:127.0.0.1:8893 version 6
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: events SMFIP_NOBODY SMFIP_NOUNKNOWN SMFIP_NODATA SMFIP_SKIP
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_connect: requests SMFIF_ADDHDRS SMFIF_QUARANTINE
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_conn_event: milter inet:127.0.0.1:8893: connect mx1.slc.paypal.com/173.0.84.226
Apr  5 08:59:17 mail postfix/smtpd[682012]: event: SMFIC_CONNECT; macros: j=mail.example.org {daemon_name}=mail.example.org {daemon_addr}=public.mail.ip.addr v=Postfix 3.3.0
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 21 flush 138
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 21 got 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: reply: SMFIR_CONTINUE data 0 bytes
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 220 mail.example.org ESMTP Hi, I'm a Mail-in-a-Box (Ubuntu/Postfix; see https://mailinabox.email/)
Apr  5 08:59:17 mail postfix/smtpd[682012]: watchdog_pat: 0x55fe6a6a0d90
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 18 flush 100
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 18 got 25
Apr  5 08:59:17 mail postfix/smtpd[682012]: < mx1.slc.paypal.com[173.0.84.226]: EHLO mx1.slc.paypal.com
Apr  5 08:59:17 mail postfix/smtpd[682012]: report helo to all milters
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "{tls_version}"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "{cipher}"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "{cipher_bits}"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "{cert_subject}"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter_macro_lookup: "{cert_issuer}"
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_helo_event: milter inet:127.0.0.1:8891: helo mx1.slc.paypal.com
Apr  5 08:59:17 mail postfix/smtpd[682012]: event: SMFIC_HELO; macros: (none)
Apr  5 08:59:17 mail postfix/smtpd[682012]: skipping event SMFIC_HELO for milter inet:127.0.0.1:8891
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_helo_event: milter inet:127.0.0.1:8893: helo mx1.slc.paypal.com
Apr  5 08:59:17 mail postfix/smtpd[682012]: event: SMFIC_HELO; macros: (none)
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 21 flush 30
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 21 got 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: reply: SMFIR_CONTINUE data 0 bytes
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: mx1.slc.paypal.com: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: match_list_match: 173.0.84.226: no match
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-mail.example.org
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-PIPELINING
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-SIZE 134217728
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-VRFY
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-ETRN
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-STARTTLS
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-ENHANCEDSTATUSCODES
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250-8BITMIME
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 250 DSN
Apr  5 08:59:17 mail postfix/smtpd[682012]: watchdog_pat: 0x55fe6a6a0d90
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 18 flush 140
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 18 got 10
Apr  5 08:59:17 mail postfix/smtpd[682012]: < mx1.slc.paypal.com[173.0.84.226]: STARTTLS
Apr  5 08:59:17 mail postfix/smtpd[682012]: query milter states for other event
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_other_event: milter inet:127.0.0.1:8891
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_other_event: milter inet:127.0.0.1:8893
Apr  5 08:59:17 mail postfix/smtpd[682012]: > mx1.slc.paypal.com[173.0.84.226]: 220 2.0.0 Ready to start TLS
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 18 flush 30
Apr  5 08:59:17 mail postfix/smtpd[682012]: abort all milters
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_abort: abort milter inet:127.0.0.1:8891
Apr  5 08:59:17 mail postfix/smtpd[682012]: milter8_abort: abort milter inet:127.0.0.1:8893
Apr  5 08:59:17 mail postfix/smtpd[682012]: event_request_timer: reset 0x7f0a427b3110 0x55fe6a675110 5
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr request = seed
Apr  5 08:59:17 mail postfix/smtpd[682012]: send attr size = 32
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 12 flush 22
Apr  5 08:59:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 12 got 60
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: status
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: 0
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: seed
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: seed
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute value: KW//removedQWWremovedkZqbotKHkURPCoOremoved=
Apr  5 08:59:17 mail postfix/smtpd[682012]: private/tlsmgr: wanted attribute: (list terminator)
Apr  5 08:59:17 mail postfix/smtpd[682012]: input attribute name: (end)

— 5 min later —

Apr  5 09:04:17 mail postfix/smtpd[682012]: SSL_accept error from mx1.slc.paypal.com[173.0.84.226]: Connection timed out
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_hostname: smtpd_client_event_limit_exceptions: mx1.slc.paypal.com ~? 127.0.0.0/8
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_hostaddr: smtpd_client_event_limit_exceptions: 173.0.84.226 ~? 127.0.0.0/8
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_hostname: smtpd_client_event_limit_exceptions: mx1.slc.paypal.com ~? [::ffff:127.0.0.0]/104
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_hostaddr: smtpd_client_event_limit_exceptions: 173.0.84.226 ~? [::ffff:127.0.0.0]/104
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_hostname: smtpd_client_event_limit_exceptions: mx1.slc.paypal.com ~? [::1]/128
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_hostaddr: smtpd_client_event_limit_exceptions: 173.0.84.226 ~? [::1]/128
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_list_match: mx1.slc.paypal.com: no match
Apr  5 09:04:17 mail postfix/smtpd[682012]: match_list_match: 173.0.84.226: no match
Apr  5 09:04:17 mail postfix/smtpd[682012]: send attr request = disconnect
Apr  5 09:04:17 mail postfix/smtpd[682012]: send attr ident = smtp:173.0.84.226
Apr  5 09:04:17 mail postfix/smtpd[682012]: vstream_fflush_some: fd 19 flush 44
Apr  5 09:04:17 mail postfix/smtpd[682012]: vstream_buf_get_ready: fd 19 got 10
Apr  5 09:04:17 mail postfix/smtpd[682012]: private/anvil: wanted attribute: status
Apr  5 09:04:17 mail postfix/smtpd[682012]: input attribute name: status
Apr  5 09:04:17 mail postfix/smtpd[682012]: input attribute value: 0
Apr  5 09:04:17 mail postfix/smtpd[682012]: private/anvil: wanted attribute: (list terminator)
Apr  5 09:04:17 mail postfix/smtpd[682012]: input attribute name: (end)
Apr  5 09:04:17 mail postfix/smtpd[682012]: lost connection after STARTTLS from mx1.slc.paypal.com[173.0.84.226]
Apr  5 09:04:17 mail postfix/smtpd[682012]: disconnect event to all milters
Apr  5 09:04:17 mail postfix/smtpd[682012]: milter8_disc_event: quit milter inet:127.0.0.1:8891

newday · April 5, 2022, 4:50pm

Here’s the conf. I believe the only edit I made was to disable IPv6 since I unfortunately I can’t make a rDNS record. This box previously was accepting paypal emails until two weeks ago or so.

https://pastebin.com/mNuf76rF

stylnchris · April 6, 2022, 12:32pm

Here’s the file diff – not seeing anything obvious. Especially when it comes to TLS.

< myorigin = /etc/mailname
< #mydestination = $myhostname, mail.example.com, localhost.example.com, , localhost
---
> #mydestination = $myhostname, localdomain, localhost, localhost.localdomain, localhost
47c46
< mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
---
> mynetworks = 127.0.0.0/8 207.136.206.34 [::ffff:127.0.0.0]/104 [::1]/128
51,52c50,51
< inet_protocols = ipv4
< smtp_bind_address=my.public.ip.addr
---
> inet_protocols = all
> smtp_bind_address=my.public.ip.addr
62a62,63
> tls_preempt_cipherlist=no
> smtpd_tls_received_header=yes
67,68d67
< tls_preempt_cipherlist=no
< smtpd_tls_received_header=yes
81c80,81
< smtpd_recipient_restrictions=permit_sasl_authenticated,permit_mynetworks,reject_rbl_client zen.spamhaus.org,reject_unlisted_recipient,check_policy_service inet:127.0.0.1:10023
---
> #smtpd_recipient_restrictions=permit_sasl_authenticated,permit_mynetworks,reject_rbl_client zen.spamhaus.org,reject_unlisted_recipient,check_policy_service inet:127.0.0.1:10023
> smtpd_recipient_restrictions=permit_sasl_authenticated,permit_mynetworks,reject_rbl_client zen.spamhaus.org,reject_unlisted_recipient,check_policy_service inet:127.0.0.1:10023,check_policy_service inet:127.0.0.1:12340
86a87
> smtputf8_enable=no
94,95d94
< smtputf8_enable=no
<