Postfix does not retry after 451 error / greylisting
I have a forwarding server using postfix/dovecot that receives emails from a third party mail client (say gmail) and forwards the emails to the final recipient.
I have noticed that when the recipient email server uses greylisting, postfix does not attempt to resend the email a few minutes later as I would expect. All my backoff settings are using default values and I have bounce_queue_lifetime = 0 although I don't think it is related.
Below is a log extract for such a greylisting response. There seems to be a few things that go wrong: the retry is almost immediate, then the server sends a message to itself which gets bounced etc... There is no further log entry related to this message.
Any ideas how to sort this out and get postfix/dovecot to just retry after a few minutes?
Nov 16 15:55:46 mail2 postfix/submission/smtpd[24769]: connect from mail-yb1-f174.google.com[209.85.219.174]
Nov 16 15:55:46 mail2 postfix/submission/smtpd[24769]: Anonymous TLS connection established from mail-yb1-f174.google.com[209.85.219.174]: TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits)
Nov 16 15:55:47 mail2 postfix/submission/smtpd[24769]: 50DB53E8EE: client=mail-yb1-f174.google.com[209.85.219.174], sasl_method=PLAIN, sasl_username=xxxx
Nov 16 15:55:47 mail2 postfix/cleanup[24775]: 50DB53E8EE: message-id=<CAOPu7Eg7445dbRTT+_EV7s8=0de0=ce0cJmqOO_49-gXokdXLg@mail.gmail.com>
Nov 16 15:55:47 mail2 opendkim[1011]: 50DB53E8EE: DKIM-Signature field added
Nov 16 15:55:47 mail2 postfix/qmgr[24745]: 50DB53E8EE: from=<[email protected]>, size=2483, nrcpt=1 (queue active)
Nov 16 15:55:47 mail2 postfix/submission/smtpd[24769]: disconnect from mail-yb1-f174.google.com[209.85.219.174] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=8
Nov 16 15:55:48 mail2 postfix/smtp[24776]: 50DB53E8EE: host je-smtp-inbound-1.mimecast-offshore.com[213.167.75.36] said: 451 Internal resource temporarily unavailable - https://community.mimecast.com/docs/DOC-1369#451 [FrAlAYP7MGavfrTQVnqFbQ.jer5] (in reply to RCPT TO command)
Nov 16 15:55:49 mail2 postfix/smtp[24776]: 50DB53E8EE: to=<[email protected]>, relay=je-smtp-inbound-1.mimecast-offshore.com[213.167.81.36]:25, delay=1.7, delays=0.26/0.02/1.3/0.19, dsn=4.0.0, status=deferred (host je-smtp-inbound-1.mimecast-offshore.com[213.167.81.36] said: 451 Internal resource temporarily unavailable - https://community.mimecast.com/docs/DOC-1369#451 [CrknqwFZOxmiUomNi_j5xw.jer4] (in reply to RCPT TO command))
Nov 16 15:56:01 mail2 postfix/pickup[24746]: 404853F264: uid=0 from=<[email protected]>
Nov 16 15:56:01 mail2 postfix/cleanup[24775]: 404853F264: message-id=<CAOPu7Eg7445dbRTT+_EV7s8=0de0=ce0cJmqOO_49-gXokdXLg@mail.gmail.com>
Nov 16 15:56:01 mail2 opendkim[1011]: 404853F264: DKIM-Signature field added
Nov 16 15:56:01 mail2 postfix/postsuper[24805]: 50DB53E8EE: removed
Nov 16 15:56:01 mail2 postfix/postsuper[24805]: Deleted: 1 message
Nov 16 15:56:01 mail2 postfix/qmgr[24745]: 404853F264: from=<[email protected]>, size=2955, nrcpt=1 (queue active)
Nov 16 15:56:01 mail2 postfix/pickup[24746]: 6189F3E8EE: uid=0 from=<root>
Nov 16 15:56:01 mail2 postfix/cleanup[24775]: 6189F3E8EE: message-id=<20201116155601.6189F3E8EE@POSTFIX_SERVER>
Nov 16 15:56:01 mail2 opendkim[1011]: 6189F3E8EE: no signing table match for 'root@POSTFIX_SERVER'
Nov 16 15:56:01 mail2 opendkim[1011]: 6189F3E8EE: no signature data
Nov 16 15:56:01 mail2 postfix/qmgr[24745]: 6189F3E8EE: from=<root@POSTFIX_SERVER>, size=787, nrcpt=1 (queue active)
Nov 16 15:56:01 mail2 postfix/postscreen[24810]: CONNECT from [POSTFIX_SERVER]:50962 to [POSTFIX_SERVER]:25
Nov 16 15:56:01 mail2 postfix/smtp[24776]: 404853F264: to=<[email protected]>, relay=je-smtp-inbound-1.mimecast-offshore.com[213.167.81.36]:25, delay=0.63, delays=0.08/0/0.45/0.1, dsn=5.0.0, status=bounced (host je-smtp-inbound-1.mimecast-offshore.com[213.167.81.36] said: 550 Anti-Spoofing policy - Inbound not allowed - https://community.mimecast.com/docs/DOC-1369#550 [22wPIJELPUOp5GuDx4lfGw.jer2] (in reply to RCPT TO command))
Nov 16 15:56:01 mail2 postfix/cleanup[24775]: ED7723F26B: message-id=<20201116155601.ED7723F26B@POSTFIX_SERVER>
Nov 16 15:56:01 mail2 postfix/bounce[24818]: 404853F264: sender non-delivery notification: ED7723F26B
Nov 16 15:56:01 mail2 postfix/qmgr[24745]: ED7723F26B: from=<>, size=5588, nrcpt=1 (queue active)
Nov 16 15:56:01 mail2 postfix/qmgr[24745]: 404853F264: removed
Nov 16 15:56:02 mail2 postfix/postscreen[24810]: PASS OLD [POSTFIX_SERVER]:50962
Nov 16 15:56:02 mail2 postfix/smtpd[24819]: connect from POSTFIX_SERVER
Nov 16 15:56:02 mail2 dovecot: auth: Debug: auth client connected (pid=0)
Nov 16 15:56:02 mail2 postfix/smtp[24809]: warning: host POSTFIX_SERVER:25 greeted me with my own hostname POSTFIX_SERVER
Nov 16 15:56:02 mail2 postfix/smtp[24809]: warning: host POSTFIX_SERVER:25 replied to HELO/EHLO with my own hostname POSTFIX_SERVER
Nov 16 15:56:02 mail2 postfix/smtp[24809]: 6189F3E8EE: to=<root@POSTFIX_SERVER>, orig_to=<root>, relay=POSTFIX_SERVER:25, delay=0.72, delays=0.04/0.09/0.59/0, dsn=5.4.6, status=bounced (mail for POSTFIX_SERVER loops back to myself)
Nov 16 15:56:02 mail2 postfix/smtpd[24819]: disconnect from POSTFIX_SERVER ehlo=1 quit=1 commands=2
Nov 16 15:56:02 mail2 postfix/cleanup[24775]: 1D6A53F264: message-id=<20201116155602.1D6A53F264@POSTFIX_SERVER>
Nov 16 15:56:02 mail2 postfix/qmgr[24745]: 1D6A53F264: from=<>, size=2779, nrcpt=1 (queue active)
Nov 16 15:56:02 mail2 postfix/bounce[24818]: 6189F3E8EE: sender non-delivery notification: 1D6A53F264
Nov 16 15:56:02 mail2 postfix/qmgr[24745]: 6189F3E8EE: removed
Nov 16 15:56:02 mail2 postfix/postscreen[24810]: CONNECT from [POSTFIX_SERVER]:50968 to [POSTFIX_SERVER]:25
Nov 16 15:56:02 mail2 postfix/postscreen[24810]: PASS OLD [POSTFIX_SERVER]:50968
Nov 16 15:56:02 mail2 postfix/smtpd[24819]: connect from POSTFIX_SERVER
Nov 16 15:56:02 mail2 postfix/smtp[24809]: warning: host POSTFIX_SERVER:25 greeted me with my own hostname POSTFIX_SERVER
Nov 16 15:56:02 mail2 postfix/smtp[24809]: warning: host POSTFIX_SERVER:25 replied to HELO/EHLO with my own hostname POSTFIX_SERVER
Nov 16 15:56:02 mail2 postfix/smtp[24809]: 1D6A53F264: to=<root@POSTFIX_SERVER>, relay=POSTFIX_SERVER:25, delay=0.01, delays=0/0/0/0, dsn=5.4.6, status=bounced (mail for POSTFIX_SERVER loops back to myself)
Nov 16 15:56:02 mail2 postfix/smtpd[24819]: disconnect from POSTFIX_SERVER ehlo=1 quit=1 commands=2
Nov 16 15:56:02 mail2 postfix/qmgr[24745]: 1D6A53F264: removed
Nov 16 15:56:02 mail2 postfix/smtp[24776]: ED7723F26B: to=<[email protected]>, relay=je-smtp-inbound-2.mimecast-offshore.com[213.167.81.36]:25, delay=0.62, delays=0/0/0.42/0.19, dsn=5.0.0, status=bounced (host je-smtp-inbound-2.mimecast-offshore.com[213.167.81.36] said: 550 Invalid Recipient - https://community.mimecast.com/docs/DOC-1369#550 [wEA4IvMnPkWfW2uIBVHiIg.jer2] (in reply to RCPT TO command))
Nov 16 15:56:02 mail2 postfix/qmgr[24745]: ED7723F26B: removed
Solution 1:
This appears to have nothing to do with greylisting and is because of a 550 code by mimecast.
Nov 16 15:56:01 mail2 postfix/smtp[24776]: 404853F264: to=<[email protected]>, relay=je-smtp-inbound-1.mimecast-offshore.com[213.167.81.36]:25, delay=0.63, delays=0.08/0/0.45/0.1, dsn=5.0.0, status=bounced (host je-smtp-inbound-1.mimecast-offshore.com[213.167.81.36] said: 550 Anti-Spoofing policy - Inbound not allowed - https://community.mimecast.com/docs/DOC-1369#550 [22wPIJELPUOp5GuDx4lfGw.jer2] (in reply to RCPT TO command))
Look at the link provided in the log and it will tell you the resolution is to create an anti-spoofing policy:
550 Anti-Spoofing policy - Inbound not allowed The message has triggered an Anti-Spoofing policy. Create an Anti-Spoofing policy to take no action for the sender's address or IP address.
Did you do that?