Hello,
I'm running a virus/spam checker mail server: clients point their MX records
towards my server, my server checks the mail via content_filter script, and
sends good mail towards the real mailserver by way of transport table
lookup.
My server is a CentOS 7.2 x64 server with the distro-supplied version of
Postfix 2.10.1
The server has reject_unverified_recipient in its
smtpd_recipient_restrictions,
so my server doesn't need to know about all the possible recipient
addresses in advance.
This works just fine for the vast amount of messages, but sometimes
fails: the
double-bounce probe gets rejected with a permanent 5xx error, but postfix
nevertheless accepts and queues the mail, sends it to the content_filter
script, which reinserts it into the queue, and the SMTP client, inevitably,
gets the same 5xx error and we've got a bounce.
I've attached a log snippet (anonymized to protect the innocent, not
otherwise
altered/abridged) showing the complete timeline of such an occurrence.
3tbPxJ5Khxz35r2bf mailhost.sender.example attempts to deliver a mail from
person@sender.domain to firstname@recipient.example to my mailserver
mailsrv.relayhost.domain, and indeed succeeds for reasons unknown (to me)
3tbPxJ5KWLz35r2b5 Recipient Validation message - gets 550 permanent error
from nexthop.destinationdom and returns "status=undeliverable"
3tbPxK57lxz35r0NV Mail re-inserted into MTA after content_filter
"spamfilter"
check passed -> nexthop still says 550, mail inevitably bounces
3tbPxK6KNlz35r0P5 Bounce notification to sender
Dec 10 11:10:27 mailsrv postfix/postscreen[1186]: PASS OLD [10.1.2.3]:61197
Dec 10 11:10:27 mailsrv postfix/smtpd[5973]: connect from
mailhost.sender.example[10.1.2.3]
Dec 10 11:10:28 mailsrv postfix/smtpd[5973]: Anonymous TLS connection
established from mailhost.sender.example[10.1.2.3]: TLSv1.2 with cipher
ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Dec 10 11:10:28 mailsrv postfix/smtpd[5973]: 3tbPxJ5Khxz35r2bf:
client=mailhost.sender.example[10.1.2.3]
Dec 10 11:10:28 mailsrv postfix/cleanup[17092]: 3tbPxJ5KWLz35r2b5:
message-id=<3tbPxJ5KWLz35r2b5@mailsrv.relayhost.domain>
Dec 10 11:10:28 mailsrv postfix/qmgr[1174]: 3tbPxJ5KWLz35r2b5:
from=<double-bounce@relayhost.domain>, size=222, nrcpt=1 (queue active)
Dec 10 11:10:28 mailsrv postfix/smtp[21674]: Trusted TLS connection
established to nexthop.destinationdom[192.168.3.229]:25: TLSv1.2 with
cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Dec 10 11:10:28 mailsrv postfix/smtp[21674]: 3tbPxJ5KWLz35r2b5:
to=<firstname@recipient.example>,
relay=nexthop.destinationdom[192.168.3.229]:25, delay=0.05,
delays=0/0/0.04/0, dsn=5.1.1, status=undeliverable (host
nexthop.destinationdom[192.168.3.229] said: 550 5.1.1
<firstname@recipient.example>: Recipient address rejected: User unknown
(in reply to RCPT TO command))
Dec 10 11:10:28 mailsrv postfix/qmgr[1174]: 3tbPxJ5KWLz35r2b5: removed
Dec 10 11:10:29 mailsrv postfix/cleanup[16248]: 3tbPxJ5Khxz35r2bf:
message-id=<9ef34851-0b3bdcd0-1481364620-7198099403@mail.sender.example>
Dec 10 11:10:29 mailsrv opendkim[7846]: 3tbPxJ5Khxz35r2bf:
mailhost.sender.example [10.1.2.3] not internal
Dec 10 11:10:29 mailsrv opendkim[7846]: 3tbPxJ5Khxz35r2bf: not authenticated
Dec 10 11:10:29 mailsrv opendkim[7846]: 3tbPxJ5Khxz35r2bf: message has
signatures from sender.domain
Dec 10 11:10:29 mailsrv opendkim[7846]: 3tbPxJ5Khxz35r2bf: DKIM
verification successful
Dec 10 11:10:29 mailsrv opendmarc[1510]: 3tbPxJ5Khxz35r2bf: SPF
(mailfrom): person@sender.domain pass
Dec 10 11:10:29 mailsrv opendmarc[1510]: 3tbPxJ5Khxz35r2bf:
sender.domain pass
Dec 10 11:10:29 mailsrv postfix/qmgr[1174]: 3tbPxJ5Khxz35r2bf:
from=<person@sender.domain>, size=28091, nrcpt=1 (queue active)
Dec 10 11:10:29 mailsrv postfix/pickup[3197]: 3tbPxK57lxz35r0NV: uid=992
from=<person@sender.domain>
Dec 10 11:10:29 mailsrv postfix/cleanup[14395]: 3tbPxK57lxz35r0NV:
message-id=<9ef34851-0b3bdcd0-1481364620-7198099403@mail.sender.example>
Dec 10 11:10:29 mailsrv postfix/qmgr[1174]: 3tbPxK57lxz35r0NV:
from=<person@sender.domain>, size=28702, nrcpt=1 (queue active)
Dec 10 11:10:29 mailsrv postfix/smtp[17189]: Trusted TLS connection
established to nexthop.destinationdom[192.168.3.229]:25: TLSv1.2 with
cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Dec 10 11:10:29 mailsrv postfix/pipe[9337]: 3tbPxJ5Khxz35r2bf:
to=<firstname@recipient.example>, relay=spamfilter, delay=1.2,
delays=0.94/0/0/0.3, dsn=2.0.0, status=sent (delivered via spamfilter
service)
Dec 10 11:10:29 mailsrv postfix/qmgr[1174]: 3tbPxJ5Khxz35r2bf: removed
Dec 10 11:10:29 mailsrv postfix/smtp[17189]: 3tbPxK57lxz35r0NV:
to=<firstname@recipient.example>,
relay=nexthop.destinationdom[192.168.3.229]:25, delay=0.17,
delays=0/0/0.04/0.12, dsn=5.1.1, status=bounced (host
nexthop.destinationdom[192.168.3.229] said: 550 5.1.1
<firstname@recipient.example>: Recipient address rejected: User unknown
(in reply to RCPT TO command))
Dec 10 11:10:29 mailsrv postfix/cleanup[17092]: 3tbPxK6KNlz35r0P5:
message-id=<3tbPxK6KNlz35r0P5@mailsrv.relayhost.domain>
Dec 10 11:10:29 mailsrv postfix/bounce[19422]: 3tbPxK57lxz35r0NV: sender
non-delivery notification: 3tbPxK6KNlz35r0P5
Dec 10 11:10:29 mailsrv postfix/qmgr[1174]: 3tbPxK6KNlz35r0P5: from=<>,
size=5507, nrcpt=1 (queue active)
Dec 10 11:10:29 mailsrv postfix/qmgr[1174]: 3tbPxK57lxz35r0NV: removed
Dec 10 11:10:31 mailsrv postfix/smtp[21677]: 3tbPxK6KNlz35r0P5:
to=<person@sender.domain>, relay=inbound.sender.domain[10.2.3.4]:25,
delay=1.2, delays=0/0/0.51/0.72, dsn=2.0.0, status=sent (250 2.0.0 OK
Mail accepted 694DB485)
Dec 10 11:10:31 mailsrv postfix/qmgr[1174]: 3tbPxK6KNlz35r0P5: removed
address_verify_negative_expire_time = 2h
address_verify_negative_refresh_time = 30m
alias_maps = hash:/etc/aliases
bounce_size_limit = 5000
config_directory = /etc/postfix
default_destination_recipient_limit = 1
disable_vrfy_command = yes
dkim_milter = inet:localhost:8892
dmarc_milter = inet:localhost:8893
enable_long_queue_ids = yes
header_checks = regexp:$maps_directory/header_checks
mailbox_size_limit = 151200000
maps_directory = $config_directory/maps
masquerade_domains = !external.$mydomain $mydomain
masquerade_exceptions = root
message_size_limit = 36000000
milter_connect_macros = j {daemon_name} v {if_name} _
milter_default_action = accept
mime_header_checks =
mydestination = $myhostname, localhost.$mydomain
mydomain = relayhost.domain
mynetworks = 192.168.3.0/24
nested_header_checks =
parent_domain_matches_subdomains = mynetworks,smtpd_access_maps
postscreen_blacklist_action = enforce
postscreen_dnsbl_action = enforce
postscreen_dnsbl_reply_map = static:DNSBLs
postscreen_dnsbl_sites = zen.spamhaus.org*4 bb.barracudacentral.org*3
postscreen_dnsbl_threshold = 4
postscreen_greet_action = enforce
recipient_bcc_maps = hash:$maps_directory/recipient_bcc_maps
recipient_canonical_maps = hash:$maps_directory/recipient_canonical
relay_domains = $mydestination,hash:$maps_directory/relay_domains
relay_recipient_maps = hash:$maps_directory/relay_recipients
show_user_unknown_table_name = no
smtp_tls_CAfile = $ssl_directory/ca-certificates.crt
smtp_tls_ciphers = high
smtp_tls_exclude_ciphers = aNULL, DES, RC4, MD5
smtp_tls_fingerprint_digest = sha1
smtp_tls_loglevel = 1
smtp_tls_mandatory_ciphers = high
smtp_tls_mandatory_exclude_ciphers = aNULL, DES, RC4, MD5
smtp_tls_mandatory_protocols = !SSLv2, !SSLv3
smtp_tls_note_starttls_offer = yes
smtp_tls_protocols = !SSLv2, !SSLv3
smtp_tls_security_level = may
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtpd_banner = $myhostname ESMTP Filter
smtpd_data_restrictions = reject_multi_recipient_bounce,
reject_unauth_pipelining
smtpd_helo_required = yes
smtpd_milters = ${dkim_milter}, ${dmarc_milter}
smtpd_recipient_restrictions = check_recipient_access
hash:$maps_directory/access_recipient, check_client_access
cidr:$maps_directory/access_client, check_helo_access
regexp:$maps_directory/access_helo, check_sender_access
hash:$maps_directory/access_sender, reject_invalid_helo_hostname,
reject_non_fqdn_helo_hostname, reject_non_fqdn_sender,
reject_non_fqdn_recipient, reject_unknown_sender_domain,
reject_unknown_recipient_domain, reject_unlisted_sender,
permit_mynetworks,
reject_unauth_destination, reject_unverified_recipient,
check_recipient_access pcre:$maps_directory/x-add-envelope-to.pcre,
permit
smtpd_relay_restrictions =
smtpd_tls_CApath = $config_directory/sslca
smtpd_tls_cert_file = $ssl_directory/intermediate-20161006.pem
smtpd_tls_ciphers = high
smtpd_tls_dh1024_param_file = /etc/pki/tls/private/dh_2048.pem
smtpd_tls_dh512_param_file = /etc/pki/tls/private/dh_512.pem
smtpd_tls_exclude_ciphers = aNULL, DES, RC4, MD5
smtpd_tls_fingerprint_digest = sha1
smtpd_tls_key_file = $ssl_directory/key-20161006.pem
smtpd_tls_loglevel = 1
smtpd_tls_mandatory_ciphers = high
smtpd_tls_mandatory_exclude_ciphers = aNULL, DES, RC4, MD5
smtpd_tls_mandatory_protocols = !SSLv2, !SSLv3
smtpd_tls_protocols = !SSLv2, !SSLv3
smtpd_tls_received_header = yes
smtpd_tls_security_level = may
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
ssl_directory = $config_directory/ssl
tls_preempt_cipherlist = yes
transport_maps = hash:$maps_directory/transport
unverified_recipient_defer_code = 250
unverified_recipient_reject_code = 550
unverified_recipient_reject_reason = Recipient address lookup failed
virtual_alias_domains = hash:$maps_directory/virtual_domains
virtual_alias_maps = pcre:$maps_directory/virtual_aliases
smtp inet n - - - 1 postscreen
smtpd pass - - - - 50 smtpd
-o recipient_bcc_maps= -o content_filter=spamfilter
dnsblog unix - - - - 0 dnsblog
tlsproxy unix - - - - 0 tlsproxy
pickup fifo n - n 60 1 pickup
-o receive_override_options=no_address_mappings
cleanup unix n - n - 0 cleanup
qmgr fifo n - n 300 1 qmgr
tlsmgr unix - - n 1000? 1 tlsmgr
rewrite unix - - n - - trivial-rewrite
bounce unix - - n - 0 bounce
defer unix - - n - 0 bounce
trace unix - - n - 0 bounce
verify unix - - n - 1 verify
flush unix n - n 1000? 0 flush
proxymap unix - - n - - proxymap
smtp unix - - n - - smtp
relay unix - - n - - smtp
-o fallback_relay=
showq unix n - n - - showq
error unix - - n - - error
discard unix - - n - - discard
local unix - n n - - local
virtual unix - n n - - virtual
lmtp unix - - n - - lmtp
anvil unix - - n - 1 anvil
scache unix - - n - 1 scache
maildrop unix - n n - - pipe
flags=DRhu user=vmail argv=/usr/local/bin/maildrop -d ${recipient}
cyrus unix - n n - - pipe
user=cyrus argv=/usr/lib/cyrus/bin/deliver -e -r ${sender} -m
${extension}
${user}
uucp unix - n n - - pipe
flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail
($recipient)
ifmail unix - n n - - pipe
flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp unix - n n - - pipe
flags=Fq. user=foo argv=/usr/local/sbin/bsmtp -f $sender $nexthop
$recipient
procmail unix - n n - - pipe
flags=R user=nobody argv=/usr/bin/procmail -t -m /etc/procmailrc
${sender}
${recipient}
retry unix - - n - - error
proxywrite unix - - n - 1 proxymap
spamfilter unix - n n - 100 pipe
flags=Rq user=vscan null_sender= argv=/opt/spam/bin/spamfilter -f
${sender} -- ${recipient} ${size} ${client_address} ${client_hostname}
${client_helo}