Answer
The best answer was on the postfix-users mailing list and it is summarized here for the benefit of serverfault's users.
- I had forgotten
soft_bounce = yes
. Always switch it back tono
after validating the configuration - When asking for help about Postfix configuration, always include the complete output of
postconf -n
- Stop accepting mail AT ALL from IPs that have no PTR records. Add
reject_unknown_reverse_client_hostname
tosmtpd_recipient_restrictions
AFTERpermit_mynetworks
andpermit_sasl_authenticated
If the reply code is 4xx, it invites the other mail server to retry. The IP address seems to be used by a "snowshoe" spammer, making detection harder. Those IP addresses flicker in and out of the blacklist as blacklist operators (Spamhaus in this case) are working to counter the snowshoers' tactics. It is an ongoing, global arms race. Rejecting mail from IPs that have no PTR records reduces significantly the size of the local battlefield.
Original Question
This is logged on a low usage, personal Postfix server. I believe there should be two reasons to reject emails based on the headers below, but the outcome is a delivery to INBOX. Excerpts of the relevant Postfix configuration follows and my questions are at the end.
Log Exercerpt
Jun 5 09:58:37 x2 postfix/smtpd[8440]: connect from unknown[157.52.162.99]
Jun 5 09:58:37 x2 postfix/smtpd[8440]: NOQUEUE: reject: RCPT from unknown[157.52.162.99]: 454 4.7.1 Service unavailable; Client host [157.52.162.99] blocked using zen.spamhaus.org; from=<newsletter@vacque.com> to=<XXX@XXX> proto=ESMTP helo=<mr99.dgnmkt.com>
Jun 5 09:58:37 x2 postfix/smtpd[8440]: disconnect from unknown[157.52.162.99]
Jun 5 10:01:57 x2 postfix/anvil[8394]: statistics: max connection rate 1/60s for (smtp:198.2.130.200) at Jun 5 09:51:57
Jun 5 10:01:57 x2 postfix/anvil[8394]: statistics: max connection count 1 for (smtp:198.2.130.200) at Jun 5 09:51:57
Jun 5 10:01:57 x2 postfix/anvil[8394]: statistics: max cache size 2 at Jun 5 09:55:18
Jun 5 10:06:39 x2 postfix/smtpd[8507]: connect from unknown[157.52.162.99]
Jun 5 10:06:40 x2 policyd-spf[8513]: None; identity=helo; client-ip=157.52.162.99; helo=mr99.dgnmkt.com; envelope-from=newsletter@vacque.com; receiver=XXX@XXX
Jun 5 10:06:40 x2 policyd-spf[8513]: Pass; identity=mailfrom; client-ip=157.52.162.99; helo=mr99.dgnmkt.com; envelope-from=newsletter@vacque.com; receiver=XXX@XXX
Jun 5 10:06:40 x2 postfix/smtpd[8507]: 49D01C1EDE: client=unknown[157.52.162.99]
Jun 5 10:06:40 x2 postfix/cleanup[8514]: 49D01C1EDE: message-id=messageid-3-M3w1NDIzfDU4fDM3ODk3OTR8eWxlYmF5Y2EwNEBzZmluYS5jb218U2F0LCAwNCBKdW4gMjAxNiAwNToxNDowNyAtMDcwMA==
Jun 5 10:06:40 x2 opendkim[1220]: 49D01C1EDE: [157.52.162.99] [157.52.162.99] not internal
Jun 5 10:06:40 x2 opendkim[1220]: 49D01C1EDE: not authenticated
Jun 5 10:06:43 x2 opendkim[1220]: 49D01C1EDE: no signature data
Jun 5 10:06:43 x2 postfix/qmgr[1337]: 49D01C1EDE: from=<newsletter@vacque.com>, size=91945, nrcpt=1 (queue active)
Jun 5 10:06:43 x2 postfix/smtpd[8507]: disconnect from unknown[157.52.162.99]
Jun 5 10:06:43 x2 dovecot: lmtp(8516): Connect from local
Jun 5 10:06:43 x2 dovecot: lmtp(8516, YYY@XXX): nhVjEfMxVFdEIQAAzX/GXw: msgid=messageid-3-M3w1NDIzfDU4fDM3ODk3OTR8eWxlYmF5Y2EwNEBzZmluYS5jb218U2F0LCAwNCBKdW4gMjAxNiAwNToxNDowNyAtMDcwMA==: saved mail to INBOX
Jun 5 10:06:43 x2 postfix/lmtp[8515]: 49D01C1EDE: to=<YYY@XXX>, orig_to=<XXX@XXX>, relay=XXX[private/dovecot-lmtp], delay=3.6, delays=3.5/0.01/0.02/0.05, dsn=2.0.0, status=sent (250 2.0.0 <YYY@XXX> nhVjEfMxVFdEIQAAzX/GXw Saved)
Jun 5 10:06:43 x2 dovecot: lmtp(8516): Disconnect from local: Successful quit
Jun 5 10:06:43 x2 postfix/qmgr[1337]: 49D01C1EDE: removed
Notes About the Log
- @XXX is my domain
- XXX@XXX is an alias
- YYY@XXX is a mailbox
- My understanding is that the bad sender [157.52.162.99] has been blocked at 9:58:37 based on zen.spamhaus.org, but 8 minutes later it reconnected and delivered successfully what should have not passed through.
Headers of the Mail That Should Have Been Rejected
Return-Path: <newsletter@vacque.com>
Delivered-To: <YYY@XXX>
Received: from XXX
by XXX (Dovecot) with LMTP id nhVjEfMxVFdEIQAAzX/GXw
for <YYY@XXX>; Sun, 05 Jun 2016 10:06:43 -0400
Received-SPF: Pass (sender SPF authorized) identity=mailfrom; client-ip=157.52.162.99; helo=mr99.dgnmkt.com; envelope-from=newsletter@vacque.com; receiver=XXX@XXX
Received: from mr99.dgnmkt.com (unknown [157.52.162.99])
by XXX (Postfix) with ESMTP id 49D01C1EDE
for <XXX@XXX>; Sun, 5 Jun 2016 10:06:39 -0400 (EDT)
Received: from stormmta (unknown [157.52.162.99])
by mr99.dgnmkt.com (Postfix) with ESMTP id DD84AE61F8A
for <XXX@XXX>; Sun, 5 Jun 2016 08:16:33 -0700 (PDT)
From:=?UTF-8?B?VG1hcnQuY29t?=<newsletter@e.ailander.com>
To:XXX@XXX
Postfix Configuration
Relevant main.cf Options
smtpd_recipient_restrictions =
permit_mynetworks
permit_sasl_authenticated
reject_unauth_destination
reject_invalid_hostname
reject_non_fqdn_hostname
reject_non_fqdn_sender
reject_non_fqdn_recipient
reject_unknown_sender_domain
reject_unknown_recipient_domain
check_recipient_access hash:/etc/postfix/recipients
# used to have Postgrey here
# check_policy_service inet:127.0.0.1:10023
reject_rbl_client zen.spamhaus.org
check_policy_service unix:private/policy-spf
permit
smtpd_restriction_classes =
ebay
ebay =
check_reverse_client_hostname_mx_access pcre:/etc/postfix/ebay.pcre
/etc/postfix/recipients
XXX@XXX ebay
ebay.pcre
/.ebay.com$/ DUNNO
/(.*)/ REJECT Not allowed to relay from $1. Please use eBay's contact form if you have legit communication for this email address.
My Comments and Questions
I assign aliases to isolate sources of mail. One such alias is assigned to eBay. eBay leaks buyer's email address to merchants. Not all merchants respect buyers' communication preferences. My solution is to restrict the emails accepted on the eBay alias to emails from eBay and reject all noise.
First, I thought that this email should have been rejected by:
check_recipient_access hash:/etc/postfix/recipients
because following /etc/postfix/recipients
the ebay restriction apply and
ebay.pcre
would have caught it on the second line.
Second, I thought that this email should have been rejected by:
reject_rbl_client zen.spamhaus.org
like the attempt a few minutes earlier.
Obviously what I expected did not happen. Why? And how can I fix it?