1 Topic by rob.ired

  • rob.ired
  • Member
  • Offline
  • Registered: 2017-05-09
  • Posts: 36

Topic: Grey Listing appears to not work for some emails

==== REQUIRED BASIC INFO OF YOUR IREDMAIL SERVER ====
- iRedMail version (check /etc/iredmail-release): 1.6.0 MARIADB edition.
- Deployed with iRedMail Easy or the downloadable installer? N
- Linux/BSD distribution name and version: CentOS Linux release 7.9.2009 (Core)
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MySQL
- Web server (Apache or Nginx): Apache
- Manage mail accounts with iRedAdmin-Pro? N
- [IMPORTANT] Related original log or error message is required if you're experiencing an issue.
====

I have an email coming via salesforce.com (so the original from address is mangled), that is not passing the Grey Listing from iRedAPD.

Below is 5 occurrences (3 lines each) from the log file that are essentially the same, the source IP is the same.
It should pass Grey Listing, but it's not.

The date/times are:
Jun 29 15:08:19
Jun 29 15:18:21
Jun 29 15:38:26
Jun 29 16:18:36
Jun 29 17:38:53

So well within the 5 minutes defined in the config

GREYLISTING_BLOCK_EXPIRE = 5

/var/log/iredapd/iredapd.log

Jun 29 15:08:19 nebula journal: iredapd [13.238.11.116] Client has not been seen before, greylisted (ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com).
Jun 29 15:08:19 nebula journal: iredapd [13.238.11.116] RCPT, camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> camp@todomain.org.au, 451 4.7.1 Intentional policy rejection, please try again later [sasl_username=, sender=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com, client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, reverse_client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, helo=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=, process_time=0.1058s]
Jun 29 15:08:24 nebula journal: iredapd [srs][sender]  rewrote: camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> SRS0=8Q/+=XE=ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@mydomain.com.au

Jun 29 15:18:21 nebula journal: iredapd [13.238.11.116] Client has not been seen before, greylisted (ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com).
Jun 29 15:18:21 nebula journal: iredapd [13.238.11.116] RCPT, camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> camp@todomain.org.au, 451 4.7.1 Intentional policy rejection, please try again later [sasl_username=, sender=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com, client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, reverse_client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, helo=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=, process_time=0.1216s]
Jun 29 15:18:26 nebula journal: iredapd [srs][sender]  rewrote: camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> SRS0=8Q/+=XE=ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@mydomain.com.au

Jun 29 15:38:26 nebula journal: iredapd [13.238.11.116] Client has not been seen before, greylisted (ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com).
Jun 29 15:38:26 nebula journal: iredapd [13.238.11.116] RCPT, camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> camp@todomain.org.au, 451 4.7.1 Intentional policy rejection, please try again later [sasl_username=, sender=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com, client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, reverse_client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, helo=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=, process_time=0.1082s]
Jun 29 15:38:31 nebula journal: iredapd [srs][sender]  rewrote: camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> SRS0=8Q/+=XE=ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@mydomain.com.au

Jun 29 16:18:36 nebula journal: iredapd [13.238.11.116] Client has not been seen before, greylisted (ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com).
Jun 29 16:18:36 nebula journal: iredapd [13.238.11.116] RCPT, camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> camp@todomain.org.au, 451 4.7.1 Intentional policy rejection, please try again later [sasl_username=, sender=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com, client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, reverse_client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, helo=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=, process_time=0.1036s]
Jun 29 16:18:41 nebula journal: iredapd [srs][sender]  rewrote: camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> SRS0=8Q/+=XE=ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@mydomain.com.au

Jun 29 17:38:53 nebula journal: iredapd [13.238.11.116] Client has not been seen before, greylisted (ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com).
Jun 29 17:38:53 nebula journal: iredapd [13.238.11.116] RCPT, camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> camp@todomain.org.au, 451 4.7.1 Intentional policy rejection, please try again later [sasl_username=, sender=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com, client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, reverse_client_name=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, helo=smtp-0fed340ad1cf7c796.core1.sfdc-vwfla6.mta.salesforce.com, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=, process_time=0.1122s]
Jun 29 17:38:58 nebula journal: iredapd [srs][sender]  rewrote: camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com -> SRS0=8Q/+=XE=ykfd48fzszkzwdvb.5num7zm.28-1deyqeai.aus25.bnc.salesforce.com=camping=fromdomain.asn.au__0-3w7nw7sjuglkyw.66zbr51vqp349v0a@mydomain.com.au

I have turned on iRedAPD debug mode and will check tomorrow when the next email comes.

I can't use spf_to_whitelist_domains.py because salesforce.com uses 

_spf.salesforce.com.  TXT   "v=spf1 exists:%{i}._spf.mta.salesforce.com -all"

Any ideas?

Thanks, Rob

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,082

Re: Grey Listing appears to not work for some emails

Any update here?
Seems it didn't insert / get required record from SQL table "iredapd.greylisting_tracking".

3 Reply by rob.ired

  • rob.ired
  • Member
  • Offline
  • Registered: 2017-05-09
  • Posts: 36

Re: Grey Listing appears to not work for some emails

Hello Zhang,

My apologies for taking so long to update this ticket.

I turned on the iRedAPD debug, and waited for the next email relevant to this issue.
As of today (19th) I have reviewed the logs and the last occurrence was 13th. 

I have reviewed the SQL table "iredapd.greylisting_tracking" and of course there is no matching record because of the 6 days delay. (Next automated email will be tomorrow, so I can check again then).

I have noticed in the log....

Sep 13 15:02:36 nebula journal: iredapd [54.79.205.229] Client has not been seen before, greylisted (nr6foye6cyt5r5df.vg5u.28-1deyqeai.aus25.bnc.salesforce.com).
Sep 13 15:02:36 nebula journal: iredapd [SQL] New tracking: #012INSERT INTO greylisting_tracking  <snip>
...
Sep 13 15:02:36 nebula journal: iredapd [SQL] Insert into smtp_sessions: #012        INSERT INTO smtp_sessions <snip>

I found the record in "iredapd.smtp_sessions".

There are current records in "iredapd.greylisting_tracking" (for other emails), so I can assume iRedAPD can write to the table.  So I took the above "New tracking:" log record and substituted "#012" for "\n", which gave valid SQL.
I then ran it via PMA, and the record was inserted - so the syntax is ok.

I have located the MTA resend @15:07:45 and @15:17:47, and they also have the same entries "iredapd [SQL] New tracking: #012INSERT" and "iredapd [SQL] Insert into smtp_sessions:" with updated timestamps.

I will check the SQL table tomorrow evening to see if the record is added via iRedAPD.

Is there anything else I should check or look for tomorrow evening, given the above information?

Thanks for your time.

Rob.

4 Reply by rob.ired

  • rob.ired
  • Member
  • Offline
  • Registered: 2017-05-09
  • Posts: 36

Re: Grey Listing appears to not work for some emails

Hello Zhang,

There was an attempted email @ 15:02 today.
I checked the SQL tables....
"iredapd.greylisting_tracking" - there is no matching record.
"iredapd.smtp_sessions" - there is a matching record.

Below is the information collected:

maillog

Sep 22 15:02:25 nebula postfix/postscreen[23034]: CONNECT from [52.64.221.35]:20559 to [45.124.53.126]:25
Sep 22 15:02:25 nebula postfix/dnsblog[23037]: addr 52.64.221.35 listed by domain dnsbl.spfbl.net as 127.0.0.4
Sep 22 15:02:26 nebula postfix/dnsblog[23041]: addr 52.64.221.35 listed by domain score.senderscore.com as 127.0.4.84
Sep 22 15:02:31 nebula postfix/postscreen[23034]: PASS OLD [52.64.221.35]:20559
Sep 22 15:02:31 nebula postfix/smtpd[23064]: connect from smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com[52.64.221.35]
Sep 22 15:02:31 nebula postfix/smtpd[23064]: Anonymous TLS connection established from smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com[52.64.221.35]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Sep 22 15:02:32 nebula postfix/smtpd[23064]: 8974A20D4: client=smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com[52.64.221.35]
Sep 22 15:02:32 nebula postfix/smtpd[23064]: 8974A20D4: warn: RCPT from smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com[52.64.221.35]: ; from=<camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com> to=<camp@todomain.org.au> proto=ESMTP helo=<smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com>
Sep 22 15:02:32 nebula postfix/smtpd[23064]: 8974A20D4: reject: RCPT from smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com[52.64.221.35]: 451 4.7.1 <camp@todomain.org.au>: Recipient address rejected: Sorry, I'm a bit tired, sleeping for a while, please try again later; from=<camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com> to=<camp@todomain.org.au> proto=ESMTP helo=<smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com>
Sep 22 15:02:37 nebula postfix/smtpd[23064]: disconnect from smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com[52.64.221.35]

iredapd.log

Sep 22 15:02:32 nebula journal: iredapd [srs][recipient]  input: get camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com
Sep 22 15:02:32 nebula journal: iredapd [srs][recipient]  500 Not a valid SRS address, bypassed.
Sep 22 15:02:32 nebula journal: iredapd [srs][recipient]  input: get camp@todomain.org.au
Sep 22 15:02:32 nebula journal: iredapd [srs][recipient]  500 Not a valid SRS address, bypassed.
Sep 22 15:02:32 nebula journal: iredapd [policy] request=smtpd_access_policy
Sep 22 15:02:32 nebula journal: iredapd [policy] protocol_state=RCPT
Sep 22 15:02:32 nebula journal: iredapd [policy] protocol_name=ESMTP
Sep 22 15:02:32 nebula journal: iredapd [policy] client_address=52.64.221.35
Sep 22 15:02:32 nebula journal: iredapd [policy] client_name=smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com
Sep 22 15:02:32 nebula journal: iredapd [policy] reverse_client_name=smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com
Sep 22 15:02:32 nebula journal: iredapd [policy] helo_name=smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com
Sep 22 15:02:32 nebula journal: iredapd [policy] sender=camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com
Sep 22 15:02:32 nebula journal: iredapd [policy] recipient=camp@todomain.org.au
Sep 22 15:02:32 nebula journal: iredapd [policy] recipient_count=0
Sep 22 15:02:32 nebula journal: iredapd [policy] queue_id=8974A20D4
Sep 22 15:02:32 nebula journal: iredapd [policy] instance=5a18.632bec68.340.0
Sep 22 15:02:32 nebula journal: iredapd [policy] size=0
Sep 22 15:02:32 nebula journal: iredapd [policy] etrn_domain=
Sep 22 15:02:32 nebula journal: iredapd [policy] stress=
Sep 22 15:02:32 nebula journal: iredapd [policy] sasl_method=
Sep 22 15:02:32 nebula journal: iredapd [policy] sasl_username=
Sep 22 15:02:32 nebula journal: iredapd [policy] sasl_sender=
Sep 22 15:02:32 nebula journal: iredapd [policy] ccert_subject=
Sep 22 15:02:32 nebula journal: iredapd [policy] ccert_issuer=
Sep 22 15:02:32 nebula journal: iredapd [policy] ccert_fingerprint=
Sep 22 15:02:32 nebula journal: iredapd [policy] ccert_pubkey_fingerprint=
Sep 22 15:02:32 nebula journal: iredapd [policy] encryption_protocol=TLSv1.2
Sep 22 15:02:32 nebula journal: iredapd [policy] encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384
Sep 22 15:02:32 nebula journal: iredapd [policy] encryption_keysize=256
Sep 22 15:02:32 nebula journal: iredapd --> Apply plugin: reject_null_sender
Sep 22 15:02:32 nebula journal: iredapd <-- Result: DUNNO
Sep 22 15:02:32 nebula journal: iredapd --> Apply plugin: wblist_rdns
Sep 22 15:02:32 nebula journal: iredapd All policy rDNS names: ['smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', '.smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', '.core1.sfdc-vwfla6.mta.salesforce.com', '.sfdc-vwfla6.mta.salesforce.com', '.mta.salesforce.com', '.salesforce.com', '.com']
Sep 22 15:02:32 nebula journal: iredapd [SQL] Query whitelisted rDNS names: #012SELECT rdns#012               FROM wblist_rdns#012              WHERE rdns IN ('smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', '.smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', '.core1.sfdc-vwfla6.mta.salesforce.com', '.sfdc-vwfla6.mta.salesforce.com', '.mta.salesforce.com', '.salesforce.com', '.com') AND wb='W'#012              LIMIT 1
Sep 22 15:02:32 nebula journal: iredapd [SQL] Query blacklisted rDNS names: #012SELECT rdns#012               FROM wblist_rdns#012              WHERE rdns IN ('smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', '.smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', '.core1.sfdc-vwfla6.mta.salesforce.com', '.sfdc-vwfla6.mta.salesforce.com', '.mta.salesforce.com', '.salesforce.com', '.com') AND wb='B'#012              LIMIT 1
Sep 22 15:02:32 nebula journal: iredapd <-- Result: DUNNO
Sep 22 15:02:32 nebula journal: iredapd --> Apply plugin: reject_sender_login_mismatch
Sep 22 15:02:32 nebula journal: iredapd Not an authenticated sender (no sasl_username).
Sep 22 15:02:32 nebula journal: iredapd [SQL] query local domain (sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com): #012SELECT domain#012                   FROM domain#012                  WHERE domain='sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com' AND active=1 AND backupmx=0#012                  LIMIT 1
Sep 22 15:02:32 nebula journal: iredapd SQL query result: None
Sep 22 15:02:32 nebula journal: iredapd [SQL] query alias domain (sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com): #012"SELECT alias_domain.alias_domain\n                       FROM alias_domain, domain\n                      WHERE domain.active=1\n                            AND domain.domain=alias_domain.target_domain\n                            AND alias_domain.alias_domain='sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com'\n                      LIMIT 1"
Sep 22 15:02:32 nebula journal: iredapd [SQL] query result: None
Sep 22 15:02:32 nebula journal: iredapd Sender domain is NOT hosted locally.
Sep 22 15:02:32 nebula journal: iredapd <-- Result: DUNNO
Sep 22 15:02:32 nebula journal: iredapd --> Apply plugin: greylisting
Sep 22 15:02:32 nebula journal: iredapd [SQL] query target domain of given alias domain (todomain.org.au): #012"SELECT alias_domain.target_domain\n               FROM alias_domain, domain\n              WHERE domain.active=1\n                    AND domain.domain=alias_domain.target_domain\n                    AND alias_domain.alias_domain='todomain.org.au'\n              LIMIT 1"
Sep 22 15:02:32 nebula journal: iredapd [SQL] query result: None
Sep 22 15:02:32 nebula journal: iredapd [SQL] Query greylisting whitelists from `greylisting_whitelist_domain_spf`: #012SELECT LOWER(sender)#012                   FROM greylisting_whitelist_domain_spf#012                  WHERE account IN ('camp@todomain.org.au', '@todomain.org.au', '@.', '@.todomain.org.au', '@.org.au', '@.au')
Sep 22 15:02:32 nebula journal: iredapd [SQL] Query greylisting whitelists from `greylisting_whitelists`: #012SELECT LOWER(sender)#012                   FROM greylisting_whitelists#012                  WHERE account IN ('camp@todomain.org.au', '@todomain.org.au', '@.', '@.todomain.org.au', '@.org.au', '@.au')
Sep 22 15:02:32 nebula journal: iredapd [52.64.221.35] Client is not explictly whitelisted.
Sep 22 15:02:32 nebula journal: iredapd No whitelist found.
Sep 22 15:02:32 nebula journal: iredapd [SQL] query greylisting settings: #012SELECT id, account, sender, sender_priority, active#012               FROM greylisting#012              WHERE account IN ('camp@todomain.org.au', '@todomain.org.au', '@.', '@.todomain.org.au', '@.org.au', '@.au')#012              ORDER BY priority DESC, sender_priority DESC
Sep 22 15:02:32 nebula journal: iredapd [SQL] query result: [(2, '@.', '101.53.164.213', 80, 0), (3, '@.', '101.53.164.214', 80, 0), (4, '@.', '101.53.164.221', 80, 0), (5, '@.', '101.53.164.222', 80, 0), (22, '@.', '@.', 0, 1)]
Sep 22 15:02:32 nebula journal: iredapd Greylisting should be applied according to SQL record: (id=22, account='@.', sender='@.')
Sep 22 15:02:32 nebula journal: iredapd [SPF][sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com] 'spf:' tag: _spf.salesforce.com
Sep 22 15:02:32 nebula journal: iredapd [SPF][include _spf.salesforce.com] v=spf1 exists:%{i}._spf.mta.salesforce.com -all
Sep 22 15:02:32 nebula journal: iredapd [SPF][_spf.salesforce.com] No valid IP addresses/networks.
Sep 22 15:02:32 nebula journal: iredapd [SPF][sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com] No valid IP addresses/networks.
Sep 22 15:02:32 nebula journal: iredapd [SPF] IP 52.64.221.35 is NOT listed in SPF DNS record of domain sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com.
Sep 22 15:02:32 nebula journal: iredapd [SQL] check whether client address (52.64.221.35) passed greylisting: #012SELECT id#012               FROM greylisting_tracking#012              WHERE client_address='52.64.221.35' AND passed=1#012              LIMIT 1
Sep 22 15:02:32 nebula journal: iredapd Client address (52.64.221.35) didn't pass greylisting.
Sep 22 15:02:32 nebula journal: iredapd [SQL] query greylisting tracking: #012SELECT init_time, blocked_count, block_expired, record_expired#012               FROM greylisting_tracking#012              WHERE sender='camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com'#012                    AND recipient='camp@todomain.org.au'#012                    AND client_address='52.64.221.35'#012              LIMIT 1
Sep 22 15:02:32 nebula journal: iredapd [52.64.221.35] Client has not been seen before, greylisted (sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com).
Sep 22 15:02:32 nebula journal: iredapd [SQL] New tracking: #012INSERT INTO greylisting_tracking (sender, sender_domain,#012                                                   recipient, rcpt_domain,#012                                                   client_address,#012                                                   init_time,#012                                                   block_expired, record_expired,#012                                                   blocked_count)#012                      VALUES ('camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', 'sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', 'camp@todomain.org.au', 'todomain.org.au', '52.64.221.35', 1663822952, 1663823252, 1663909352, 1)
Sep 22 15:02:32 nebula journal: iredapd <-- Result: 451 4.7.1 Sorry, I'm a bit tired, sleeping for a while, please try again later
Sep 22 15:02:32 nebula journal: iredapd Session ended.
Sep 22 15:02:32 nebula journal: iredapd [52.64.221.35] RCPT, camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com -> camp@todomain.org.au, 451 4.7.1 Sorry, I'm a bit tired, sleeping for a while, please try again later [sasl_username=, sender=camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com, client_name=smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com, reverse_client_name=smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com, helo=smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=, process_time=0.1298s]
Sep 22 15:02:32 nebula journal: iredapd [SQL] Insert into smtp_sessions: #012        INSERT INTO smtp_sessions (#012            time, time_num,#012            action, reason, instance,#012            client_address, client_name, reverse_client_name, helo_name,#012            encryption_protocol, encryption_cipher,#012            server_address, server_port,#012            sender, sender_domain,#012            sasl_username, sasl_domain,#012            recipient, recipient_domain)#012        VALUES (#012            '2022-09-22 05:02:32', 1663822952,#012            '451', "4.7.1 Sorry, I'm a bit tired, sleeping for a while, please try again later", '5a18.632bec68.340.0',#012            '52.64.221.35', 'smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', 'smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', 'smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com',#012            'TLSv1.2', 'ECDHE-RSA-AES256-GCM-SHA384',#012            '', '',#012            'camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', 'sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com',#012            '', '',#012            'camp@todomain.org.au', 'todomain.org.au')
Sep 22 15:02:37 nebula journal: iredapd [srs][sender]  input: get camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com
Sep 22 15:02:37 nebula journal: iredapd [SQL] query local domain (sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com): #012SELECT domain#012                   FROM domain#012                  WHERE domain='sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com' AND active=1 #012                  LIMIT 1
Sep 22 15:02:37 nebula journal: iredapd SQL query result: None
Sep 22 15:02:37 nebula journal: iredapd [SQL] query alias domain (sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com): #012"SELECT alias_domain.alias_domain\n                       FROM alias_domain, domain\n                      WHERE domain.active=1\n                            AND domain.domain=alias_domain.target_domain\n                            AND alias_domain.alias_domain='sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com'\n                      LIMIT 1"
Sep 22 15:02:37 nebula journal: iredapd [SQL] query result: None
Sep 22 15:02:37 nebula journal: iredapd [srs][sender]  [SQL] Query srs_exclude_domains: SELECT id FROM srs_exclude_domains WHERE domain IN ('sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', '.sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', 'com', '.com', 'salesforce.com', '.salesforce.com', 'bnc.salesforce.com', '.bnc.salesforce.com', 'aus25.bnc.salesforce.com', '.aus25.bnc.salesforce.com', '28-1deyqeai.aus25.bnc.salesforce.com', '.28-1deyqeai.aus25.bnc.salesforce.com', '8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', '.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com') LIMIT 1
Sep 22 15:02:37 nebula journal: iredapd [srs][sender]  [SQL] Query result: None
Sep 22 15:02:37 nebula journal: iredapd [srs][sender]  rewrote: camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com -> SRS0=eHde=ZZ=sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com=camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@nebula.snowdrift.com.au
Sep 22 15:02:37 nebula journal: iredapd [srs][sender]  200 SRS0=eHde=ZZ=sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com=camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@nebula.snowdrift.com.au
Sep 22 15:02:37 nebula journal: iredapd [srs][sender]  input: get SRS0=eHde=ZZ=sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com=camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@nebula.snowdrift.com.au
Sep 22 15:02:37 nebula journal: iredapd [srs][sender]  500 Domain is srs_domain, bypassed.

MYSQL

Table iredapd

SELECT * FROM `smtp_sessions` where `client_address` like "52.64.221.35" order by `time_num` desc

The first record returned matches the timestamp of the above log - it is show below from PMA.

--
-- Dumping data for table `smtp_sessions`
--

INSERT INTO `smtp_sessions` (`id`, `time`, `time_num`, `action`, `reason`, `instance`, `client_address`, `client_name`, `reverse_client_name`, `helo_name`, `sender`, `sender_domain`, `sasl_username`, `sasl_domain`, `recipient`, `recipient_domain`, `encryption_protocol`, `encryption_cipher`, `server_address`, `server_port`) VALUES
(258187, '2022-09-21 19:02:32', 1663822952, '451', '4.7.1 Sorry, I''m a bit tired, sleeping for a while, please try again later', '5a18.632bec68.340.0', '52.64.221.35', 'smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', 'smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', 'smtp-0d5ce930e03b4af95.core1.sfdc-vwfla6.mta.salesforce.com', 'camping=auscamps.asn.au__0-3qafwzhck7nyn1.4y4ia58bf54k8ius@sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', 'sg7owh9315q2gasi.8ybbbmc.28-1deyqeai.aus25.bnc.salesforce.com', '', '', 'camp@todomain.org.au', 'todomain.org.au', 'TLSv1.2', 'ECDHE-RSA-AES256-GCM-SHA384', '', '');

5 Reply by rob.ired

  • rob.ired
  • Member
  • Offline
  • Registered: 2017-05-09
  • Posts: 36

Re: Grey Listing appears to not work for some emails

Interestingly, I discovered I have had this problem before - and resolved it by whitelisting the IP address.

I was going to write that there are some "salesforce" emails that are being inserted to the greylisting_tracking table (as shown next)


--
-- Dumping data for table `greylisting_tracking`
--

INSERT INTO `greylisting_tracking` (`id`, `sender`, `recipient`, `client_address`, `sender_domain`, `rcpt_domain`, `init_time`, `block_expired`, `record_expired`, `blocked_count`, `passed`) VALUES
(34002, 'noreply=momentum.com.au__0-1d5sp9vv5iuzj7@gbqjc281czbzxj.28-1eoxdea2.ap7.bnc.salesforce.com', 'treasurer@todomain.org.au', '101.53.164.237', 'gbqjc281czbzxj.28-1eoxdea2.ap7.bnc.salesforce.com', 'todomain.org.au', 1662945312, 1662945612, 1665537614, 1, 1);

but, then I noticed that the IP address is listed in the greylisting table.
I must have added that a long time ago and forgotten.


MYSQL

Table iredapd.greylisting

"id","account","priority","sender","sender_priority","comment","active"
"2","@.","0","101.53.164.213","80",,"0"
"3","@.","0","101.53.164.214","80",,"0"
"4","@.","0","101.53.164.221","80",,"0"
"5","@.","0","101.53.164.222","80",,"0"
"22","@.","0","@.","0",,"1"

What that means is there is something specific about Salesforce emails that breaks the INSERT to the greylisting_tracking table.

Your thoughts?

Thanks, Rob.

6 Reply by rob.ired

  • rob.ired
  • Member
  • Offline
  • Registered: 2017-05-09
  • Posts: 36

Re: Grey Listing appears to not work for some emails

Err, not quite.

The table `greylisting_tracking` has IP of 101.53.164.237
The table `greylisting` has 101.53.164.*   - BUT NOT ending in .237

So I am still stumped as to why some salesforce emails are inserted to the table `greylisting_tracking`, and others are not.

Rob.

7 Reply by ZhangHuangbin

  • ZhangHuangbin
  • ZhangHuangbin
  • iRedMail Developers
  • Offline
  • Registered: 2009-05-06
  • Posts: 31,082

Re: Grey Listing appears to not work for some emails

I see the IP is 52.64.221.35, but your last post is "101.53.164.237".
Greylisting applies to sender server IP address, if salesforce reties with another mail server, then it will never pass the greylisting.

8 Reply by rob.ired

  • rob.ired
  • Member
  • Offline
  • Registered: 2017-05-09
  • Posts: 36

Re: Grey Listing appears to not work for some emails

Hello Zhang.

Please read post #4.
The subsequent post #5 and #6 are misdirections to a degree.

The reason for the different IPs is that Salesforce.com send from many addresses. 
Some are 52.64.22*.* and others are 101.53.16*.* depending on the customer they represent.

The issue of this topic is the 52.64.22*.* addresses, however it is noteworthy that the Salesforce emails sent from 101.53.164.237 are being inserted to "greylisting_tracking", but those from 52.64.221.35 are not.

Thanks, Rob.

9 Reply by RikuS

  • RikuS
  • Member
  • Offline
  • Registered: 2016-06-10
  • Posts: 116

Re: Grey Listing appears to not work for some emails

Here are some details about Salesforce IP addresses, if it helps:
https://help.salesforce.com/s/articleVi … amp;type=1

10 Reply by Cthulhu (edited by Cthulhu 2022-10-03 04:50:49)

  • Cthulhu
  • Member
  • Offline
  • Registered: 2019-06-04
  • Posts: 907

Re: Grey Listing appears to not work for some emails

Won't work with your setup, if you need to whitelist literally all subnets, you can aswell disable greylisting by itself