1 Topic by alec

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Topic: amavisd_wblist Not Blocking

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

Hi

I followed the official guide for blacklisting ( https://docs.iredmail.org/manage.iredapd.html ):

- I added the plugin to /opt/iredapd/settings.py

# Enabled plugins.
plugins = ["reject_null_sender", "wblist_rdns", "reject_sender_login_mismatch", "greylisting", "throttle", "amavisd_wblist", "sql_alias_access_policy"]

- Added the mail account to the blacklist

$ python3 wblist_admin.py --add --blacklist test@domain.com

- then printed out the list of all blacklisted accounts and I can see my fresh entry.

$ python3 wblist_admin.py --list --blacklist
* Establishing SQL connection.
* List all inbound blacklist for account: @.
test@domain.com

But if I email me from the blacklisted account the mail will pass through without being blocked. Any suggestions, please?

----

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

2 Reply by Cthulhu

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

Re: amavisd_wblist Not Blocking

is it from same, local domain?

3 Reply by alec

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

Cthulhu wrote:

is it from same, local domain?

Nope, it's from an external domain that is sending us harmful emails.

4 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

Please turn on debug mode in iRedAPD, then send a new testing email to trigger the verbose logging, extract full log of this testing email and paste here for troubleshooting.
FYI: https://docs.iredmail.org/debug.iredapd.html

5 Reply by alec (edited by alec 2022-05-09 18:17:56)

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

ZhangHuangbin wrote:

Please turn on debug mode in iRedAPD, then send a new testing email to trigger the verbose logging, extract full log of this testing email and paste here for troubleshooting.
FYI: https://docs.iredmail.org/debug.iredapd.html

I've turned on debug mode from settings.py and restarted the service as described in the guide.

Then I sent an email from the blocked account and received it anyway.

In the log I have only this:

May  9 10:08:09 mx iredapd Starting iRedAPD (version: 5.0.4, backend: pgsql), listening on 127.0.0.1:7777.
May  9 10:08:09 mx iredapd Loading plugin (priority: 100): reject_null_sender
May  9 10:08:09 mx iredapd Loading plugin (priority: 99): wblist_rdns
May  9 10:08:09 mx iredapd Loading plugin (priority: 90): reject_sender_login_mismatch
May  9 10:08:09 mx iredapd Loading plugin (priority: 80): greylisting
May  9 10:08:09 mx iredapd Loading plugin (priority: 60): throttle
May  9 10:08:09 mx iredapd Loading plugin (priority: 50): sql_alias_access_policy
May  9 10:08:09 mx iredapd Loading plugin (priority: 40): amavisd_wblist
May  9 10:08:09 mx iredapd Starting SRS sender rewriting channel, listening on 127.0.0.1:7778
May  9 10:08:09 mx iredapd Starting SRS recipient rewriting channel, listening on 127.0.0.1:7779

But it's from 2 hours ago. It seems that it didn't log anything.

6 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

Please show me output of command below, seems you don't have iRedAPD integrated in Postfix at all.

postconf smtpd_recipient_restrictions smtpd_end_of_data_restrictions

7 Reply by alec

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

ZhangHuangbin wrote:

Please show me output of command below, seems you don't have iRedAPD integrated in Postfix at all.

postconf smtpd_recipient_restrictions smtpd_end_of_data_restrictions

That is what I thought in the first place as well.
This is the output of the command:

smtpd_recipient_restrictions = 
  reject_non_fqdn_recipient 
  reject_unlisted_recipient 
  check_policy_service inet:127.0.0.1:7777 
  permit_mynetworks 
  permit_sasl_authenticated 
  reject_unauth_destination 
  check_policy_service inet:127.0.0.1:12340

smtpd_end_of_data_restrictions = 
  check_policy_service inet:127.0.0.1:7777

8 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

Could you please turn on debug mode in iRedAPD, then try to reproduce the issue, and copy relevant iRedAPD log lines here for troubleshooting?
FYI: https://docs.iredmail.org/debug.iredapd.html

9 Reply by alec (edited by alec 2022-05-16 22:04:16)

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

I have already enabled debug mode in /opt/iredapd/settings.py :

# Log level: info, debug.
log_level = 'debug'

# Backend: ldap, mysql, pgsql.
backend = "pgsql"

# Enabled plugins.
plugins = ["reject_null_sender", "wblist_rdns", "reject_sender_login_mismatch", "greylisting", "throttle", "amavisd_wblist", "sql_alias_access_policy"]

Then restarted iredapd.service and postfix.service.
I also checked my blocked accounts with:

python3 wblist_admin.py --list --blacklist

and I sent a mail with my blocked account, and this shows up:

May 16 13:54:30 mx iredapd [SQL] Query result: []
May 16 13:54:30 mx iredapd No sender throttle setting.
May 16 13:54:30 mx iredapd Bypass recipient throttling (found sasl_username).
May 16 13:54:30 mx iredapd <-- Result: DUNNO
May 16 13:54:30 mx iredapd Skip plugin: sql_alias_access_policy (protocol_state != END-OF-MESSAGE)
May 16 13:54:30 mx iredapd Skip plugin: amavisd_wblist (protocol_state != END-OF-MESSAGE)
May 16 13:54:30 mx iredapd Session ended.

10 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

Please show the full log lines related to this testing email.

11 Reply by alec

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

ZhangHuangbin wrote:

Please show the full log lines related to this testing email.

I don't have them. When I send the email, nothing is logged in /var/log/iredapd.log. The emails are coming through without leaving anything in the log file.

Maybe iredapd and postfix aren't communicating at all.

I checked the daemon, and it seems working fine.

& sudo systemctl status iredapd.service 
● iredapd.service - iRedAPD (A simple posfix policy server)
     Loaded: loaded (/lib/systemd/system/iredapd.service; enabled; vendor preset: enabled)
     Active: active (running) since Sun 2022-05-29 22:36:47 UTC; 14h ago
    Process: 1024 ExecStart=/usr/bin/python3 /opt/iredapd/iredapd.py (code=exited, status=0/SUCCESS)
   Main PID: 1597 (python3)
      Tasks: 1 (limit: 14267)
     Memory: 34.2M
     CGroup: /system.slice/iredapd.service
             └─1597 /usr/bin/python3 /opt/iredapd/iredapd.py

12 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

In post #7, you showed us the output of command "postconf smtpd_recipient_restrictions smtpd_end_of_data_restrictions", according to the pasted content, iRedAPD is integrated in Postfix.

Could you please show us the original output again?

postconf smtpd_recipient_restrictions smtpd_end_of_data_restrictions

13 Reply by alec (edited by alec 2022-05-31 14:47:30)

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

ZhangHuangbin wrote:

In post #7, you showed us the output of command "postconf smtpd_recipient_restrictions smtpd_end_of_data_restrictions", according to the pasted content, iRedAPD is integrated in Postfix.

Could you please show us the original output again?

postconf smtpd_recipient_restrictions smtpd_end_of_data_restrictions

Yes, sure. The output is the following:

smtpd_recipient_restrictions = reject_non_fqdn_recipient reject_unlisted_recipient check_policy_service inet:127.0.0.1:7777 permit_mynetworks permit_sasl_authenticated reject_unauth_destination check_policy_service inet:127.0.0.1:12340
smtpd_end_of_data_restrictions = check_policy_service inet:127.0.0.1:7777

Is there anything else that I can check? Logs, config?

Thanks in advance for your patience

14 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

Postfix config is ok.

Do you have a personal Gmail account? try to block your personal Gmail account with the "/opt/iredapd/tools/wblist_admin.py" script, then send an email from your Gmail account, and show us the full iRedAPD log lines related to this testing email.

15 Reply by alec (edited by alec 2022-06-10 23:08:03)

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

ZhangHuangbin wrote:

Postfix config is ok.

Do you have a personal Gmail account? try to block your personal Gmail account with the "/opt/iredapd/tools/wblist_admin.py" script, then send an email from your Gmail account, and show us the full iRedAPD log lines related to this testing email.

This is my procedure.
First I block my personal gmail address:

$ python3 wblist_admin.py --add --blacklist alec@gmail.com

Then check the blacklist:

$ python3 wblist_admin.py --list --blacklist
  * Establishing SQL connection.
  * List all inbound blacklist for account: @.
  alec@gmail.com

Then I send a test mail from my gmail account to the iRedMail server and I receive it in the inbox.
I received the mail at 16:28 10 June 2022.

Now log files:

a)  /var/log/iredapd/iredapd.log 

Jun 10 14:08:17 mx iredapd [192.16.11.114] RCPT, person1@company.com => person2@gmail.com, DUNNO [sasl_username=person1@company.com, sender=person1@company.com, client_name=unknown, reverse_client_name=person1, helo=smtpclient.apple, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=587, process_time=0.0065s]
Jun 10 14:08:17 mx iredapd [policy] request=smtpd_access_policy
Jun 10 14:08:17 mx iredapd [policy] protocol_state=END-OF-MESSAGE
Jun 10 14:08:17 mx iredapd [policy] protocol_name=ESMTP
Jun 10 14:08:17 mx iredapd [policy] client_address=192.16.11.114
Jun 10 14:08:17 mx iredapd [policy] client_name=unknown
Jun 10 14:08:17 mx iredapd [policy] client_port=60421
Jun 10 14:08:17 mx iredapd [policy] reverse_client_name=person1
Jun 10 14:08:17 mx iredapd [policy] server_address=192.16.11.247
Jun 10 14:08:17 mx iredapd [policy] server_port=587
Jun 10 14:08:17 mx iredapd [policy] helo_name=smtpclient.apple
Jun 10 14:08:17 mx iredapd [policy] sender=person1@company.com
Jun 10 14:08:17 mx iredapd [policy] recipient=
Jun 10 14:08:17 mx iredapd [policy] recipient_count=5
Jun 10 14:08:17 mx iredapd [policy] queue_id=4LKN8x0TLzzltv5
Jun 10 14:08:17 mx iredapd [policy] instance=2b29d.62a35050.e907a.0
Jun 10 14:08:17 mx iredapd [policy] size=15184
Jun 10 14:08:17 mx iredapd [policy] etrn_domain=
Jun 10 14:08:17 mx iredapd [policy] stress=
Jun 10 14:08:17 mx iredapd [policy] sasl_method=PLAIN
Jun 10 14:08:17 mx iredapd [policy] sasl_username=person1@company.com
Jun 10 14:08:17 mx iredapd [policy] sasl_sender=
Jun 10 14:08:17 mx iredapd [policy] ccert_subject=
Jun 10 14:08:17 mx iredapd [policy] ccert_issuer=
Jun 10 14:08:17 mx iredapd [policy] ccert_fingerprint=
Jun 10 14:08:17 mx iredapd [policy] ccert_pubkey_fingerprint=
Jun 10 14:08:17 mx iredapd [policy] encryption_protocol=TLSv1.2
Jun 10 14:08:17 mx iredapd [policy] encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384
Jun 10 14:08:17 mx iredapd [policy] encryption_keysize=256
Jun 10 14:08:17 mx iredapd [policy] policy_context=
Jun 10 14:08:17 mx iredapd Skip plugin: reject_null_sender (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: wblist_rdns (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: reject_sender_login_mismatch (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: greylisting (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd --> Apply plugin: throttle
Jun 10 14:08:17 mx iredapd Found sasl_username, consider this sender as an internal sender.
Jun 10 14:08:17 mx iredapd Check sender throttling.
Jun 10 14:08:17 mx iredapd [SQL] query target domain of given alias domain (company.com): #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='company.com'\n              LIMIT 1"
Jun 10 14:08:17 mx iredapd [SQL] query result: None
Jun 10 14:08:17 mx iredapd [SQL] Query throttle setting: #012        SELECT id, account, priority, period, max_msgs, max_quota, max_rcpts, msg_size#012          FROM throttle#012         WHERE kind='outbound' AND account IN ('192.16.11.114', '@ip', 'person1@company.com', '@company.com', '@.', '@.company.com', '@.it', '192.16.11.*', '192.168.*.114')#012         ORDER BY priority DESC#012         
Jun 10 14:08:17 mx iredapd [SQL] Query result: []
Jun 10 14:08:17 mx iredapd No sender throttle setting.
Jun 10 14:08:17 mx iredapd Bypass recipient throttling (found sasl_username).
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO
Jun 10 14:08:17 mx iredapd Skip plugin: sql_alias_access_policy (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: amavisd_wblist (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Session ended.
Jun 10 14:08:17 mx iredapd [192.16.11.114] END-OF-MESSAGE, person1@company.com => , DUNNO [recipient_count=5, size=15184, process_time=0.0051s]
Jun 10 14:08:17 mx 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-06-10 14:08:17', 1654870097,#012            'DUNNO', '', '2b29d.62a35050.e907a.0',#012            '192.16.11.114', 'unknown', 'person1', 'smtpclient.apple',#012            'TLSv1.2', 'ECDHE-RSA-AES256-GCM-SHA384',#012            '192.16.11.247', '587',#012            'person1@company.com', 'company.com',#012            'person1@company.com', 'company.com',#012            '', '')#012

But as you can see the last entry in the log is at 2:08pm (14:08) and I sent the message at 4:28pm (16:28).
"person1" and "person2" are other addresses of trusted people, they aren't part of the test.

====================================================================================

b)  /var/log/iredapd/iredapd.log.1

Jun  4 22:02:25 mx iredapd [SPF] Error while querying DNS SPF record zoho.com: NoNameservers('All nameservers failed to answer the query zoho.com. IN TXT: Server 127.0.0.53 UDP port 53 answered SERVFAIL')
Jun  4 22:02:25 mx iredapd [SPF][zoho.com] MX: smtpin.zoho.com
Jun  4 22:02:25 mx iredapd [SPF][zoho.com] MX: smtpin2.zoho.com
Jun  4 22:02:25 mx iredapd [SPF][zoho.com] MX: smtpin3.zoho.com
Jun  4 22:02:25 mx iredapd [DNS][A] smtpin.zoho.com -> 136.143.191.23
Jun  4 22:02:25 mx iredapd [DNS][A] smtpin3.zoho.com -> 136.143.191.23
Jun  4 22:02:25 mx iredapd [DNS][A] smtpin2.zoho.com -> 136.143.183.23
Jun  5 00:11:18 mx iredapd Starting iRedAPD (version: 5.0.4, backend: pgsql), listening on 127.0.0.1:7777.
Jun  5 00:11:18 mx iredapd Loading plugin (priority: 100): reject_null_sender
Jun  5 00:11:18 mx iredapd Loading plugin (priority: 99): wblist_rdns
Jun  5 00:11:18 mx iredapd Loading plugin (priority: 90): reject_sender_login_mismatch
Jun  5 00:11:18 mx iredapd Loading plugin (priority: 80): greylisting
Jun  5 00:11:18 mx iredapd Loading plugin (priority: 60): throttle
Jun  5 00:11:18 mx iredapd Loading plugin (priority: 50): sql_alias_access_policy
Jun  5 00:11:18 mx iredapd Loading plugin (priority: 40): amavisd_wblist
Jun  5 00:11:18 mx iredapd Starting SRS sender rewriting channel, listening on 127.0.0.1:7778
Jun  5 00:11:18 mx iredapd Starting SRS recipient rewriting channel, listening on 127.0.0.1:7779

But even here the last entry of the log is from 5 days ago.

===================================================================================

As you can see, nothing about the email that I sent from alec@gmail.com has been logged.

16 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

alec wrote:

Jun 10 14:08:17 mx iredapd [192.16.11.114] RCPT, person1@company.com => person2@gmail.com, DUNNO [sasl_username=person1@company.com, sender=person1@company.com, client_name=unknown, reverse_client_name=person1, helo=smtpclient.apple, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=587, process_time=0.0065s]

I need log lines above this one.
Plugin "amavisd_wblist" works in RCPT state, but you didn't paste any log lines of RCPT state.

17 Reply by alec

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

Sorry for the delay, this is the log with the leading part that I unintentionally omitted:

Jun 10 14:08:17 mx iredapd [192.168.11.114] RCPT, person1@company.com => person3@company2.com, DUNNO [sasl_username=person1@company.com, sender=person1@company.com, client_name=unknown, reverse_client_name=person1, helo=smtpclient.apple, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=587, process_time=0.0072s]
Jun 10 14:08:17 mx iredapd [policy] request=smtpd_access_policy
Jun 10 14:08:17 mx iredapd [policy] protocol_state=RCPT
Jun 10 14:08:17 mx iredapd [policy] protocol_name=ESMTP
Jun 10 14:08:17 mx iredapd [policy] client_address=192.168.11.114
Jun 10 14:08:17 mx iredapd [policy] client_name=unknown
Jun 10 14:08:17 mx iredapd [policy] client_port=60421
Jun 10 14:08:17 mx iredapd [policy] reverse_client_name=person1
Jun 10 14:08:17 mx iredapd [policy] server_address=192.168.11.247
Jun 10 14:08:17 mx iredapd [policy] server_port=587
Jun 10 14:08:17 mx iredapd [policy] helo_name=smtpclient.apple
Jun 10 14:08:17 mx iredapd [policy] sender=person1@company.com
Jun 10 14:08:17 mx iredapd [policy] recipient=person2@gmail.com
Jun 10 14:08:17 mx iredapd [policy] recipient_count=0
Jun 10 14:08:17 mx iredapd [policy] queue_id=4LKN8x0TLzzltv5
Jun 10 14:08:17 mx iredapd [policy] instance=2b29d.62a35050.e907a.0
Jun 10 14:08:17 mx iredapd [policy] size=0
Jun 10 14:08:17 mx iredapd [policy] etrn_domain=
Jun 10 14:08:17 mx iredapd [policy] stress=
Jun 10 14:08:17 mx iredapd [policy] sasl_method=PLAIN
Jun 10 14:08:17 mx iredapd [policy] sasl_username=person1@company.com
Jun 10 14:08:17 mx iredapd [policy] sasl_sender=
Jun 10 14:08:17 mx iredapd [policy] ccert_subject=
Jun 10 14:08:17 mx iredapd [policy] ccert_issuer=
Jun 10 14:08:17 mx iredapd [policy] ccert_fingerprint=
Jun 10 14:08:17 mx iredapd [policy] ccert_pubkey_fingerprint=
Jun 10 14:08:17 mx iredapd [policy] encryption_protocol=TLSv1.2
Jun 10 14:08:17 mx iredapd [policy] encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384
Jun 10 14:08:17 mx iredapd [policy] encryption_keysize=256
Jun 10 14:08:17 mx iredapd [policy] policy_context=
Jun 10 14:08:17 mx iredapd --> Apply plugin: reject_null_sender
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO
Jun 10 14:08:17 mx iredapd --> Apply plugin: wblist_rdns
Jun 10 14:08:17 mx iredapd Found SASL username, bypass rDNS check for outbound.
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO
Jun 10 14:08:17 mx iredapd --> Apply plugin: reject_sender_login_mismatch
Jun 10 14:08:17 mx iredapd Sender: person1@company.com, SASL username: person1@company.com
Jun 10 14:08:17 mx iredapd SKIP: sender == sasl username.
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO
Jun 10 14:08:17 mx iredapd --> Apply plugin: greylisting
Jun 10 14:08:17 mx iredapd Found SASL username, bypass greylisting for outbound email.
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO
Jun 10 14:08:17 mx iredapd Skip plugin: throttle (protocol_state != RCPT)
Jun 10 14:08:17 mx iredapd --> Apply plugin: sql_alias_access_policy
Jun 10 14:08:17 mx iredapd [SQL] query access policy: #012SELECT accesspolicy#012               FROM alias#012              WHERE address='person2@gmail.com'#012              LIMIT 1
Jun 10 14:08:17 mx iredapd [SQL] query result: None
Jun 10 14:08:17 mx iredapd [SQL] query target domain of given alias domain (gmail.com): #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='gmail.com'\n              LIMIT 1"
Jun 10 14:08:17 mx iredapd [SQL] query result: None
Jun 10 14:08:17 mx iredapd Recipient domain is not an alias domain.
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO Recipient is not a mail alias account or no access policy
Jun 10 14:08:17 mx iredapd --> Apply plugin: amavisd_wblist
Jun 10 14:08:17 mx iredapd [SQL] query target domain of given alias domain (company.com): #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='company.com'\n              LIMIT 1"
Jun 10 14:08:17 mx iredapd [SQL] query result: None
Jun 10 14:08:17 mx iredapd [SQL] query target domain of given alias domain (gmail.com): #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='gmail.com'\n              LIMIT 1"
Jun 10 14:08:17 mx iredapd [SQL] query result: None
Jun 10 14:08:17 mx iredapd Possible policy senders: ['person1@company.com', '@company.com', '@.', '@.company.com', '@.com', '192.168.11.114', '192.168.11.*', '192.168.*.114']
Jun 10 14:08:17 mx iredapd Possible policy recipients: ['person2@gmail.com', '@gmail.com', '@.', '@.gmail.com', '@.com']
Jun 10 14:08:17 mx iredapd Apply wblist for outbound message.
Jun 10 14:08:17 mx iredapd [SQL] Query local addresses: #012SELECT id, email#012               FROM users#012              WHERE email IN ('person1@company.com', '@company.com', '@.', '@.company.com', '@.com', '192.168.11.114', '192.168.11.*', '192.168.*.114')#012           ORDER BY priority DESC
Jun 10 14:08:17 mx iredapd Local addresses (in `amavisd.users`): [(1, <memory at 0x7ff8865a8940>)]
Jun 10 14:08:17 mx iredapd [SQL] Query external addresses: #012SELECT id, email#012               FROM mailaddr#012              WHERE email IN ('person2@gmail.com', '@gmail.com', '@.', '@.gmail.com', '@.com')#012           ORDER BY priority DESC
Jun 10 14:08:17 mx iredapd No record found in SQL database.
Jun 10 14:08:17 mx iredapd [SQL] Query CIDR network: #012SELECT id, email#012               FROM mailaddr#012              WHERE email LIKE '192.%%'#012           ORDER BY priority DESC
Jun 10 14:08:17 mx iredapd IDs of CIDR network(s): []
Jun 10 14:08:17 mx iredapd No valid sender id or recipient id.
Jun 10 14:08:17 mx iredapd [SQL] query local domain (gmail.com): #012SELECT domain#012                   FROM domain#012                  WHERE domain='gmail.com' AND active=1 #012                  LIMIT 1
Jun 10 14:08:17 mx iredapd SQL query result: None
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO
Jun 10 14:08:17 mx iredapd Session ended.

Jun 10 14:08:17 mx iredapd [192.16.11.114] RCPT, person1@company.com => person2@gmail.com, DUNNO [sasl_username=person1@company.com, sender=person1@company.com, client_name=unknown, reverse_client_name=person1, helo=smtpclient.apple, encryption_protocol=TLSv1.2, encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384, server_port=587, process_time=0.0065s]
Jun 10 14:08:17 mx iredapd [policy] request=smtpd_access_policy
Jun 10 14:08:17 mx iredapd [policy] protocol_state=END-OF-MESSAGE
Jun 10 14:08:17 mx iredapd [policy] protocol_name=ESMTP
Jun 10 14:08:17 mx iredapd [policy] client_address=192.16.11.114
Jun 10 14:08:17 mx iredapd [policy] client_name=unknown
Jun 10 14:08:17 mx iredapd [policy] client_port=60421
Jun 10 14:08:17 mx iredapd [policy] reverse_client_name=person1
Jun 10 14:08:17 mx iredapd [policy] server_address=192.16.11.247
Jun 10 14:08:17 mx iredapd [policy] server_port=587
Jun 10 14:08:17 mx iredapd [policy] helo_name=smtpclient.apple
Jun 10 14:08:17 mx iredapd [policy] sender=person1@company.com
Jun 10 14:08:17 mx iredapd [policy] recipient=
Jun 10 14:08:17 mx iredapd [policy] recipient_count=5
Jun 10 14:08:17 mx iredapd [policy] queue_id=4LKN8x0TLzzltv5
Jun 10 14:08:17 mx iredapd [policy] instance=2b29d.62a35050.e907a.0
Jun 10 14:08:17 mx iredapd [policy] size=15184
Jun 10 14:08:17 mx iredapd [policy] etrn_domain=
Jun 10 14:08:17 mx iredapd [policy] stress=
Jun 10 14:08:17 mx iredapd [policy] sasl_method=PLAIN
Jun 10 14:08:17 mx iredapd [policy] sasl_username=person1@company.com
Jun 10 14:08:17 mx iredapd [policy] sasl_sender=
Jun 10 14:08:17 mx iredapd [policy] ccert_subject=
Jun 10 14:08:17 mx iredapd [policy] ccert_issuer=
Jun 10 14:08:17 mx iredapd [policy] ccert_fingerprint=
Jun 10 14:08:17 mx iredapd [policy] ccert_pubkey_fingerprint=
Jun 10 14:08:17 mx iredapd [policy] encryption_protocol=TLSv1.2
Jun 10 14:08:17 mx iredapd [policy] encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384
Jun 10 14:08:17 mx iredapd [policy] encryption_keysize=256
Jun 10 14:08:17 mx iredapd [policy] policy_context=
Jun 10 14:08:17 mx iredapd Skip plugin: reject_null_sender (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: wblist_rdns (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: reject_sender_login_mismatch (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: greylisting (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd --> Apply plugin: throttle
Jun 10 14:08:17 mx iredapd Found sasl_username, consider this sender as an internal sender.
Jun 10 14:08:17 mx iredapd Check sender throttling.
Jun 10 14:08:17 mx iredapd [SQL] query target domain of given alias domain (company.com): #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='company.com'\n              LIMIT 1"
Jun 10 14:08:17 mx iredapd [SQL] query result: None
Jun 10 14:08:17 mx iredapd [SQL] Query throttle setting: #012        SELECT id, account, priority, period, max_msgs, max_quota, max_rcpts, msg_size#012          FROM throttle#012         WHERE kind='outbound' AND account IN ('192.16.11.114', '@ip', 'person1@company.com', '@company.com', '@.', '@.company.com', '@.it', '192.16.11.*', '192.168.*.114')#012         ORDER BY priority DESC#012         
Jun 10 14:08:17 mx iredapd [SQL] Query result: []
Jun 10 14:08:17 mx iredapd No sender throttle setting.
Jun 10 14:08:17 mx iredapd Bypass recipient throttling (found sasl_username).
Jun 10 14:08:17 mx iredapd <-- Result: DUNNO
Jun 10 14:08:17 mx iredapd Skip plugin: sql_alias_access_policy (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Skip plugin: amavisd_wblist (protocol_state != END-OF-MESSAGE)
Jun 10 14:08:17 mx iredapd Session ended.
Jun 10 14:08:17 mx iredapd [192.16.11.114] END-OF-MESSAGE, person1@company.com => , DUNNO [recipient_count=5, size=15184, process_time=0.0051s]
Jun 10 14:08:17 mx 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-06-10 14:08:17', 1654870097,#012            'DUNNO', '', '2b29d.62a35050.e907a.0',#012            '192.16.11.114', 'unknown', 'person1', 'smtpclient.apple',#012            'TLSv1.2', 'ECDHE-RSA-AES256-GCM-SHA384',#012            '192.16.11.247', '587',#012            'person1@company.com', 'company.com',#012            'person1@company.com', 'company.com',#012            '', '')#012

The new line in the middle of the log is to divide the new leading part from the old one that I had already posted.
The snippet of the log is from an email with multiple receivers, but it's not the one that I need to block. I don't know if this can help you.

18 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

alec wrote:

The snippet of the log is from an email with multiple receivers, but it's not the one that I need to block. I don't know if this can help you.

This is helpless. We need the log triggered by the blocked one for troubleshooting.

19 Reply by alec (edited by alec 2022-06-20 22:44:40)

  • alec
  • Member
  • Offline
  • Registered: 2022-02-24
  • Posts: 18

Re: amavisd_wblist Not Blocking

ZhangHuangbin wrote:
alec wrote:

The snippet of the log is from an email with multiple receivers, but it's not the one that I need to block. I don't know if this can help you.

This is helpless. We need the log triggered by the blocked one for troubleshooting.

This is the problem. Nothing get triggered, so nothing is written in the log. There are nothing in iredapd.log about the blocked email.
Few minutes ago (4:30pm) I sent 4 emails from the blocked gmail account. All three landed in my inbox in the iRedMail server.
The last lines that I have in the log /var/log/iredapd/iredapd.log are from 2:00pm.
No log lines about the gmail emails.

20 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

This doesn't make any sense to me.
iRedAPD is configured in Postfix correctly (smtpd_recipient_restrictions, smtpd_end_of_data_restrictions), all emails processed by Postfix will be passed to iRedAPD, hence there must be some log lines in iRedAPD log file.

21 Reply by Lexa83

  • Lexa83
  • Lexa83
  • Member
  • Offline
  • Registered: 2016-09-15
  • Posts: 67

Re: amavisd_wblist Not Blocking

Did you ever figure this out? Wanted to point out my logs are in UTC and not my local timezone, any chance you are in -2hr timezone? Found your post interesting as I'm having trouble with amavisd_wblist not whitelisting and am currently searching posts for a resolution.

22 Reply by ZhangHuangbin

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

Re: amavisd_wblist Not Blocking

Lexa83 wrote:

Did you ever figure this out? Wanted to point out my logs are in UTC and not my local timezone, any chance you are in -2hr timezone? Found your post interesting as I'm having trouble with amavisd_wblist not whitelisting and am currently searching posts for a resolution.

Please create a new forum topic for your own issue with detailed description and related log lines.