0

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=<USER@SENDER.COM>, 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=<USER@RECIPIENT.COM>, 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=<relay@RECIPIENT.COM>
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=<relay@RECIPIENT.COM>, 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=<USER@RECIPIENT.COM>, 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=<relay@RECIPIENT.COM>, 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
assylias
  • 147
  • 9

2 Answers2

2

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=<USER@RECIPIENT.COM>, 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?

tater
  • 1,395
  • 2
  • 9
  • 12
  • I have DKIM and SPF properly configured I believe (not sure if that's enough). – assylias Nov 16 '20 at 23:01
  • Your server is acting as a relay and most likely the sender domain is not configured in SPF, but impossible to say with the information provided. Either fix that or create a mimecast ant-spoofing policy in their administration console, following the instructions at the link. – tater Nov 17 '20 at 00:44
  • Indeed my server is acting as a relay and the sender domain (in this case google.com) is configured in SPF. I can't change mimecast policy as this is another domain rejecting my emails. If I resend an email to the same recipient a few minutes later, it goes through without problem - that's why I thought it was a greylisting issue. – assylias Nov 17 '20 at 11:10
  • It is `je-smtp-inbound-1.mimecast-offshore.com` rejecting your mail in the log provided. If another server is also rejecting it, that is a separate matter but we can't comment on logs we don't see. And in this case, it is rejected because mimecast consider it to be spoofed. If you are trying to send an email from `google.com` to mimecast, it is **Google's** SPF that needs to include your IP (which is impossible), **not** your SPF including Google. Thus you either need to not send email pretending to be from `google.com`, or you need to allow your IP in mimecast admin panel. – tater Nov 17 '20 at 11:51
0

The messages were being rewritten and deleted from the queue by a custom script. Once that script was disabled postfix was able to resend messages after a few minutes and pass the greylisting checks as expected.

assylias
  • 147
  • 9