1 Topic by BenSuffolk

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Topic: iredapd letting email be sent to alias islist when it should reject it

==== Required information ====
- iRedMail version (check /etc/iredmail-release): 0.9.6 MYSQL edition.
- Linux/BSD distribution name and version: Ubuntu 16.04 X86_64
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MySQL
- Web server (Apache or Nginx): Apache
- Manage mail accounts with iRedAdmin-Pro? No
- Related log if you're reporting an issue:
====

I set up an email alias list as per the instructions at http://www.iredmail.org/docs/sql.create.mail.alias.html

I set the accesspolicy='domain' in the alias table but the server still let emails through from a different domain. My list is called #test@domain1.com

This is what I saw in the iredapd  log file

2017-04-21 08:11:57 INFO 77.x.x.x RCPT, ben@domain2.com => #test@domain1.com, REJECT Not authorized [0.0210s]
2017-04-21 08:11:58 INFO 77.x.x.x END-OF-MESSAGE, ben@domain2.com => #test@domain1.com, DUNNO [0.0070s]

I'm not sure how iredapd works, but I'm guessing it goes over each plugin in turn checking each one to see if the message should be rejected or not.

It looks like the sql_alias_access_policy  plugin correctly rejected the message, but then maybe another plugin or some other rule has overridden the REJECT and made it DUNNO

Any tips on how I should debug this?

Regards

Ben

----

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

2 Reply by BenSuffolk

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

I turned debug on to see if it would give me any extra info.

2017-04-21 08:30:05 DEBUG Connect from 127.0.0.1, port 36420.
2017-04-21 08:30:05 DEBUG smtp session: request=smtpd_access_policy
2017-04-21 08:30:05 DEBUG smtp session: protocol_state=RCPT
2017-04-21 08:30:05 DEBUG smtp session: protocol_name=ESMTP
2017-04-21 08:30:05 DEBUG smtp session: client_address=77.x.x.x
2017-04-21 08:30:05 DEBUG smtp session: client_name=xxxxx
2017-04-21 08:30:05 DEBUG smtp session: client_port=29804
2017-04-21 08:30:05 DEBUG smtp session: reverse_client_name=xxxxx
2017-04-21 08:30:05 DEBUG smtp session: helo_name=[10.0.0.13]
2017-04-21 08:30:05 DEBUG smtp session: sender=ben@domain2.com
2017-04-21 08:30:05 DEBUG smtp session: recipient=#test@domain1.com
2017-04-21 08:30:05 DEBUG smtp session: recipient_count=0
2017-04-21 08:30:05 DEBUG smtp session: queue_id=
2017-04-21 08:30:05 DEBUG smtp session: instance=3a3c.58f9b4fd.2d92f.0
2017-04-21 08:30:05 DEBUG smtp session: size=0
2017-04-21 08:30:05 DEBUG smtp session: etrn_domain=
2017-04-21 08:30:05 DEBUG smtp session: stress=
2017-04-21 08:30:05 DEBUG smtp session: sasl_method=PLAIN
2017-04-21 08:30:05 DEBUG smtp session: sasl_username=ben@domain2.com
2017-04-21 08:30:05 DEBUG smtp session: sasl_sender=
2017-04-21 08:30:05 DEBUG smtp session: ccert_subject=
2017-04-21 08:30:05 DEBUG smtp session: ccert_issuer=
2017-04-21 08:30:05 DEBUG smtp session: ccert_fingerprint=
2017-04-21 08:30:05 DEBUG smtp session: ccert_pubkey_fingerprint=
2017-04-21 08:30:05 DEBUG smtp session: encryption_protocol=TLSv1.2
2017-04-21 08:30:05 DEBUG smtp session: encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384
2017-04-21 08:30:05 DEBUG smtp session: encryption_keysize=256
2017-04-21 08:30:05 DEBUG smtp session: policy_context=
2017-04-21 08:30:05 DEBUG --> Apply plugin: reject_null_sender
2017-04-21 08:30:05 DEBUG <-- Result: DUNNO
2017-04-21 08:30:05 DEBUG --> Apply plugin: reject_sender_login_mismatch
2017-04-21 08:30:05 DEBUG Sender: ben@vanilla.net, SASL username: ben@domain2.com
2017-04-21 08:30:05 DEBUG SKIP: sender == sasl username.
2017-04-21 08:30:05 DEBUG <-- Result: DUNNO
2017-04-21 08:30:05 DEBUG --> Apply plugin: greylisting
2017-04-21 08:30:05 DEBUG Found SASL username, bypass greylisting for outbound email.
2017-04-21 08:30:05 DEBUG <-- Result: DUNNO
2017-04-21 08:30:05 DEBUG --> Apply plugin: throttle
2017-04-21 08:30:05 DEBUG Check sender throttling.
2017-04-21 08:30:05 DEBUG [SQL] Query throttle setting:

        SELECT id, account, priority, period, max_msgs, max_quota, msg_size
          FROM throttle
         WHERE kind='outbound' AND account IN ('77.x.x.x', '@ip', '@.', 'ben@domain2.com', '@domain2.com', '@.domain2.com', '@net', '@.net', '77.x.x.*', '77.x.*.x')
         ORDER BY priority DESC
         
2017-04-21 08:30:05 DEBUG [SQL] Query result:
[]
2017-04-21 08:30:05 DEBUG No sender throttle setting.
2017-04-21 08:30:05 DEBUG Bypass recipient throttling (found sasl_username).
2017-04-21 08:30:05 DEBUG <-- Result: DUNNO
2017-04-21 08:30:05 DEBUG --> Apply plugin: sql_alias_access_policy
2017-04-21 08:30:05 DEBUG [SQL] query access policy:
SELECT accesspolicy, goto, moderators
               FROM alias
              WHERE address='#test@domain1.com'
                    AND islist=1
                    AND active=1
              LIMIT 1
   
2017-04-21 08:30:05 DEBUG SQL query result: ('domain', 'goto@domain1.com', '')
2017-04-21 08:30:05 DEBUG Access policy: domain
2017-04-21 08:30:05 DEBUG members: goto@domain1.com
2017-04-21 08:30:05 DEBUG moderators:
2017-04-21 08:30:05 DEBUG [SQL] query alias domains:
SELECT alias_domain
               FROM alias_domain
              WHERE
                    alias_domain='domain2.com'
                    AND target_domain='domain1.com'
              LIMIT 1
             
2017-04-21 08:30:05 DEBUG No alias domain.
2017-04-21 08:30:05 DEBUG <-- Result: REJECT Not authorized
2017-04-21 08:30:05 DEBUG Session ended.
2017-04-21 08:30:05 INFO 77.x.x.x RCPT, ben@domain2.com => #test@domain1.com, REJECT Not authorized [0.0107s]
2017-04-21 08:30:06 DEBUG Connect from 127.0.0.1, port 36430.
2017-04-21 08:30:06 DEBUG smtp session: request=smtpd_access_policy
2017-04-21 08:30:06 DEBUG smtp session: protocol_state=END-OF-MESSAGE
2017-04-21 08:30:06 DEBUG smtp session: protocol_name=ESMTP
2017-04-21 08:30:06 DEBUG smtp session: client_address=77.x.x.x
2017-04-21 08:30:06 DEBUG smtp session: client_name=xxxxx
2017-04-21 08:30:06 DEBUG smtp session: client_port=29804
2017-04-21 08:30:06 DEBUG smtp session: reverse_client_name=xxxxxx
2017-04-21 08:30:06 DEBUG smtp session: helo_name=[10.0.0.13]
2017-04-21 08:30:06 DEBUG smtp session: sender=ben@domain2.com
2017-04-21 08:30:06 DEBUG smtp session: recipient=#test@domain1.com
2017-04-21 08:30:06 DEBUG smtp session: recipient_count=1
2017-04-21 08:30:06 DEBUG smtp session: queue_id=3597B6462A
2017-04-21 08:30:06 DEBUG smtp session: instance=3a3c.58f9b4fd.2d92f.0
2017-04-21 08:30:06 DEBUG smtp session: size=2452
2017-04-21 08:30:06 DEBUG smtp session: etrn_domain=
2017-04-21 08:30:06 DEBUG smtp session: stress=
2017-04-21 08:30:06 DEBUG smtp session: sasl_method=PLAIN
2017-04-21 08:30:06 DEBUG smtp session: sasl_username=ben@domain2.com
2017-04-21 08:30:06 DEBUG smtp session: sasl_sender=
2017-04-21 08:30:06 DEBUG smtp session: ccert_subject=
2017-04-21 08:30:06 DEBUG smtp session: ccert_issuer=
2017-04-21 08:30:06 DEBUG smtp session: ccert_fingerprint=
2017-04-21 08:30:06 DEBUG smtp session: ccert_pubkey_fingerprint=
2017-04-21 08:30:06 DEBUG smtp session: encryption_protocol=TLSv1.2
2017-04-21 08:30:06 DEBUG smtp session: encryption_cipher=ECDHE-RSA-AES256-GCM-SHA384
2017-04-21 08:30:06 DEBUG smtp session: encryption_keysize=256
2017-04-21 08:30:06 DEBUG smtp session: policy_context=
2017-04-21 08:30:06 DEBUG Skip plugin: reject_null_sender (protocol_state != END-OF-MESSAGE)
2017-04-21 08:30:06 DEBUG Skip plugin: reject_sender_login_mismatch (protocol_state != END-OF-MESSAGE)
2017-04-21 08:30:06 DEBUG Skip plugin: greylisting (protocol_state != END-OF-MESSAGE)
2017-04-21 08:30:06 DEBUG --> Apply plugin: throttle
2017-04-21 08:30:06 DEBUG Check sender throttling.
2017-04-21 08:30:06 DEBUG [SQL] Query throttle setting:

        SELECT id, account, priority, period, max_msgs, max_quota, msg_size
          FROM throttle
         WHERE kind='outbound' AND account IN ('77.x.x.x', '@ip', '@.', 'ben@domain2.com', '@domain2.com', '@.domain2.com', '@net', '@.net', '77.x.x.*', '77.x.*.x')
         ORDER BY priority DESC
         
2017-04-21 08:30:06 DEBUG [SQL] Query result:
[]
2017-04-21 08:30:06 DEBUG No sender throttle setting.
2017-04-21 08:30:06 DEBUG Bypass recipient throttling (found sasl_username).
2017-04-21 08:30:06 DEBUG <-- Result: DUNNO
2017-04-21 08:30:06 DEBUG Skip plugin: sql_alias_access_policy (protocol_state != END-OF-MESSAGE)
2017-04-21 08:30:06 DEBUG Skip plugin: amavisd_wblist (protocol_state != END-OF-MESSAGE)
2017-04-21 08:30:06 DEBUG Session ended.
2017-04-21 08:30:06 INFO 77.x.x.x END-OF-MESSAGE, ben@domain2.com => #test@domain1.com, DUNNO [0.0091s]

So it looks like its connecting twice, I'm assuming thats once before amavis and once after it. The first time its being rejected, but postfix is not having any of that, and passing it on for delivery anyway.

3 Reply by BenSuffolk (edited by BenSuffolk 2017-04-21 15:49:28)

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

main.cf

# Recipient restrictions
smtpd_recipient_restrictions =
    reject_unknown_recipient_domain
    reject_non_fqdn_recipient
    reject_unlisted_recipient
    check_policy_service inet:127.0.0.1:7777
    permit_mynetworks
    permit_sasl_authenticated
    reject_unauth_destination

# END-OF-MESSAGE restrictions
smtpd_end_of_data_restrictions =
    check_policy_service inet:127.0.0.1:7777

So the 2 times are actually once for the smtpd_recipient_restrictions (which was rejected, but ignored by postfix) and once for smtpd_end_of_data_restrictions.

Is it because smtpd_recipient_restrictions is then going on to allow the email because the ben@domain2.com address is sasl authenticated, and thus check_policy_service is being overridden by permit_sasl_authenticated?

4 Reply by BenSuffolk

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

Is this the expected behaviour, or should it have blocked the email?

5 Reply by BenSuffolk

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

So I tried from an external email domain not hosted on the iredmail server, and the mail got through, so I'm pretty sure it's not expected behaviour.

Should I be logging this in the bug tracker?

Ben

6 Reply by ZhangHuangbin

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

Re: iredapd letting email be sent to alias islist when it should reject it

If Postfix gets 'REJECT' in RCPT protocol state, it should stop the smtp session immediately and no more requests in 'END-OF-MESSAGE' state. but you got both. This confuses me.

Could you please show us full SQL record of this mail alias account? (of course you should hide the real domain name in output.)

BenSuffolk wrote:

2017-04-21 08:30:05 INFO 77.x.x.x RCPT, ben@domain2.com => #test@domain1.com, REJECT Not authorized [0.0107s]

Is the real email address contains a '#'?

7 Reply by BenSuffolk (edited by BenSuffolk 2017-04-26 12:51:19)

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

Yes it does. I use the hash to show it as a group email,address.

I'll do the sql dump when I'm Near my computer again this evening, just with my iPad at the moment.

Ben

8 Reply by BenSuffolk

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

Ok,

I tried it fresh on a different domain, and this time it should have got blocked by the greylisting filter, even before it got to the list filter, but it let it straight through!

mysql> select * from alias where address = '#test@domain.com';
+-------------------+-----------------+------+------------+--------------+-------------+--------+----------+----------+---------------------+---------------------+---------------------+--------+
| address           | goto            | name | moderators | accesspolicy | domain      | islist | is_alias | alias_to | created             | modified            | expired             | active |
+-------------------+-----------------+------+------------+--------------+-------------+--------+----------+----------+---------------------+---------------------+---------------------+--------+
| #test@domain.com  | ben@domain.com  |      | NULL       | domain       | domain.com  |      1 |        0 |          | 1970-01-01 01:01:01 | 1970-01-01 01:01:01 | 9999-12-31 00:00:00 |      1 |
+-------------------+-----------------+------+------------+--------------+-------------+--------+----------+----------+---------------------+---------------------+---------------------+--------+
1 row in set (0.01 sec)


Apr 27 20:03:59 mx postfix/postscreen[1956]: CONNECT from [108.60.212.145]:52302 to [45.76.137.157]:25
Apr 27 20:04:01 mx CRON[2288]: (sogo) CMD (/usr/sbin/sogo-tool expire-sessions 30 2>/dev/null)
Apr 27 20:04:05 mx postfix/postscreen[1956]: PASS OLD [108.60.212.145]:52302
Apr 27 20:04:05 mx postfix/smtpd[1959]: connect from unknown[108.60.212.145]
Apr 27 20:04:06 mx postfix/smtpd[1959]: 1B2C15E004: client=unknown[108.60.212.145]
Apr 27 20:04:07 mx postfix/cleanup[2295]: 1B2C15E004: message-id=<aff4a273ac8b8d53@95be485b921bdab3>
Apr 27 20:04:07 mx postfix/qmgr[1721]: 1B2C15E004: from=<test@ismyemailworking.com>, size=1661, nrcpt=1 (queue active)
Apr 27 20:04:07 mx postfix/smtpd[1959]: disconnect from unknown[108.60.212.145] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Apr 27 20:04:08 mx postfix/10025/smtpd[2303]: connect from localhost[127.0.0.1]
Apr 27 20:04:08 mx postfix/10025/smtpd[2303]: 8DB5C5E007: client=localhost[127.0.0.1]
Apr 27 20:04:08 mx postfix/cleanup[2295]: 8DB5C5E007: message-id=<aff4a273ac8b8d53@95be485b921bdab3>
Apr 27 20:04:08 mx postfix/qmgr[1721]: 8DB5C5E007: from=<test@ismyemailworking.com>, size=2101, nrcpt=1 (queue active)
Apr 27 20:04:08 mx postfix/10025/smtpd[2303]: disconnect from localhost[127.0.0.1] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
Apr 27 20:04:08 mx amavis[1883]: (01883-02) Passed CLEAN {RelayedInbound}, [108.60.212.145]:52302 [108.60.212.145] ESMTP/ESMTP <test@ismyemailworking.com> -> <ben@domain.com>, (ESMTP://[108.60.212.145]:52302), Queue-ID: 1B2C15E004, Message-ID: <aff4a273ac8b8d53@95be485b921bdab3>, mail_id: pqDo6DrLbzUi, b: rDm0ISvTO, Hits: 1.591, size: 1661, queued_as: 8DB5C5E007, Subject: "IsMyEmailWorking.com - Test ID [2395e42e-59c6-447e-bda3-e486ec3f3357]", From: <test@ismyemailworking.com>, helo=IsMyEmailWorking.com, Tests: [BAYES_50=0.8,RDNS_NONE=0.793,SPF_HELO_PASS=-0.001,SPF_PASS=-0.001], autolearn=no autolearn_force=no, autolearnscore=1.274, 1226 ms
Apr 27 20:04:08 mx postfix/smtp-amavis/smtp[2299]: 1B2C15E004: to=<ben@domain.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=2.9, delays=1.6/0.02/0.01/1.2, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 8DB5C5E007)
Apr 27 20:04:08 mx postfix/qmgr[1721]: 1B2C15E004: removed
Apr 27 20:04:08 mx postfix/pipe[2304]: 8DB5C5E007: to=<ben@domain.com>, relay=dovecot, delay=0.07, delays=0.01/0.01/0/0.05, dsn=2.0.0, status=sent (delivered via dovecot service)
Apr 27 20:04:08 mx postfix/qmgr[1721]: 8DB5C5E007: removed


2017-04-27 20:04:06 DEBUG smtp session: request=smtpd_access_policy
2017-04-27 20:04:06 DEBUG smtp session: protocol_state=RCPT
2017-04-27 20:04:06 DEBUG smtp session: protocol_name=ESMTP
2017-04-27 20:04:06 DEBUG smtp session: client_address=108.60.212.145
2017-04-27 20:04:06 DEBUG smtp session: client_name=unknown
2017-04-27 20:04:06 DEBUG smtp session: client_port=52302
2017-04-27 20:04:06 DEBUG smtp session: reverse_client_name=unknown
2017-04-27 20:04:06 DEBUG smtp session: helo_name=IsMyEmailWorking.com
2017-04-27 20:04:06 DEBUG smtp session: sender=test@ismyemailworking.com
2017-04-27 20:04:06 DEBUG smtp session: recipient=#test@domain.com
2017-04-27 20:04:06 DEBUG smtp session: recipient_count=0
2017-04-27 20:04:06 DEBUG smtp session: queue_id=
2017-04-27 20:04:06 DEBUG smtp session: instance=7a7.590240a5.b765f.0
2017-04-27 20:04:06 DEBUG smtp session: size=0
2017-04-27 20:04:06 DEBUG smtp session: etrn_domain=
2017-04-27 20:04:06 DEBUG smtp session: stress=
2017-04-27 20:04:06 DEBUG smtp session: sasl_method=
2017-04-27 20:04:06 DEBUG smtp session: sasl_username=
2017-04-27 20:04:06 DEBUG smtp session: sasl_sender=
2017-04-27 20:04:06 DEBUG smtp session: ccert_subject=
2017-04-27 20:04:06 DEBUG smtp session: ccert_issuer=
2017-04-27 20:04:06 DEBUG smtp session: ccert_fingerprint=
2017-04-27 20:04:06 DEBUG smtp session: ccert_pubkey_fingerprint=
2017-04-27 20:04:06 DEBUG smtp session: encryption_protocol=
2017-04-27 20:04:06 DEBUG smtp session: encryption_cipher=
2017-04-27 20:04:06 DEBUG smtp session: encryption_keysize=0
2017-04-27 20:04:06 DEBUG smtp session: policy_context=
2017-04-27 20:04:06 DEBUG --> Apply plugin: reject_null_sender
2017-04-27 20:04:06 DEBUG <-- Result: DUNNO
2017-04-27 20:04:06 DEBUG --> Apply plugin: reject_sender_login_mismatch
2017-04-27 20:04:06 DEBUG Not an authenticated sender (no sasl_username).
2017-04-27 20:04:06 DEBUG [SQL] query local domain (ismyemailworking.com):
SELECT domain
                   FROM domain
                  WHERE domain='ismyemailworking.com'
                  LIMIT 1
2017-04-27 20:04:06 DEBUG SQL query result: None
2017-04-27 20:04:06 DEBUG [SQL] query alias domains (ismyemailworking.com):
SELECT alias_domain
                   FROM alias_domain
                  WHERE alias_domain='ismyemailworking.com' OR target_domain='ismyemailworking.com'
                  LIMIT 1
2017-04-27 20:04:06 DEBUG SQL query result: None
2017-04-27 20:04:06 DEBUG Sender domain is not hosted locally.
2017-04-27 20:04:06 DEBUG <-- Result: DUNNO
2017-04-27 20:04:06 DEBUG --> Apply plugin: greylisting
2017-04-27 20:04:06 DEBUG [SQL] Query greylisting whitelists:
SELECT id, sender, comment
               FROM greylisting_whitelists
              WHERE account IN ('#test@domain.com', '@domain.com', '@.')
2017-04-27 20:04:06 DEBUG No whitelist found.
2017-04-27 20:04:06 DEBUG [SQL] query greylisting settings:
SELECT id, account, sender, sender_priority, active
               FROM greylisting
              WHERE account IN ('#test@domain.com', '@domain.com', '@.')
              ORDER BY priority DESC, sender_priority DESC
2017-04-27 20:04:06 DEBUG [SQL] query result: [(1, '@.', '@.', 0, 1)]
2017-04-27 20:04:06 DEBUG Greylisting should be applied according to SQL record: (id=1, account='@.', sender='@.')
2017-04-27 20:04:06 DEBUG [SQL] check whether client address (108.60.212.145) passed greylisting:
SELECT id
               FROM greylisting_tracking
              WHERE client_address='108.60.212.145'
                    AND passed=1
              LIMIT 1
2017-04-27 20:04:06 DEBUG Client address (108.60.212.145) didn't pass greylisting.
2017-04-27 20:04:06 DEBUG [SQL] query greylisting tracking:
SELECT init_time, blocked_count, block_expired, record_expired
               FROM greylisting_tracking
              WHERE sender='test@ismyemailworking.com'
                    AND recipient='#test@domain.com'
                    AND client_address='108.60.212.145'
              LIMIT 1
2017-04-27 20:04:06 INFO [108.60.212.145] Client has not been seen before, greylisted.
2017-04-27 20:04:06 DEBUG [SQL] New tracking:
INSERT INTO greylisting_tracking (sender, sender_domain,
                                                   recipient, rcpt_domain,
                                                   client_address,
                                                   init_time,
                                                   block_expired, record_expired,
                                                   blocked_count)
                      VALUES ('test@ismyemailworking.com', 'ismyemailworking.com', '#test@domain.com', 'domain.com', '108.60.212.145', 1493319846, 1493320746, 1493406246, 1)
2017-04-27 20:04:06 DEBUG <-- Result: 451 4.7.1 Intentional policy rejection, please try again later
2017-04-27 20:04:06 DEBUG Session ended.
2017-04-27 20:04:06 INFO 108.60.212.145 RCPT, test@ismyemailworking.com -> #test@domain.com, 451 4.7.1 Intentional policy rejection, please try again later [0.0381s]
2017-04-27 20:04:07 DEBUG Connect from 127.0.0.1, port 40552.
2017-04-27 20:04:07 DEBUG smtp session: request=smtpd_access_policy
2017-04-27 20:04:07 DEBUG smtp session: protocol_state=END-OF-MESSAGE
2017-04-27 20:04:07 DEBUG smtp session: protocol_name=ESMTP
2017-04-27 20:04:07 DEBUG smtp session: client_address=108.60.212.145
2017-04-27 20:04:07 DEBUG smtp session: client_name=unknown
2017-04-27 20:04:07 DEBUG smtp session: client_port=52302
2017-04-27 20:04:07 DEBUG smtp session: reverse_client_name=unknown
2017-04-27 20:04:07 DEBUG smtp session: helo_name=IsMyEmailWorking.com
2017-04-27 20:04:07 DEBUG smtp session: sender=test@ismyemailworking.com
2017-04-27 20:04:07 DEBUG smtp session: recipient=#test@domain.com
2017-04-27 20:04:07 DEBUG smtp session: recipient_count=1
2017-04-27 20:04:07 DEBUG smtp session: queue_id=1B2C15E004
2017-04-27 20:04:07 DEBUG smtp session: instance=7a7.590240a5.b765f.0
2017-04-27 20:04:07 DEBUG smtp session: size=1477
2017-04-27 20:04:07 DEBUG smtp session: etrn_domain=
2017-04-27 20:04:07 DEBUG smtp session: stress=
2017-04-27 20:04:07 DEBUG smtp session: sasl_method=
2017-04-27 20:04:07 DEBUG smtp session: sasl_username=
2017-04-27 20:04:07 DEBUG smtp session: sasl_sender=
2017-04-27 20:04:07 DEBUG smtp session: ccert_subject=
2017-04-27 20:04:07 DEBUG smtp session: ccert_issuer=
2017-04-27 20:04:07 DEBUG smtp session: ccert_fingerprint=
2017-04-27 20:04:07 DEBUG smtp session: ccert_pubkey_fingerprint=
2017-04-27 20:04:07 DEBUG smtp session: encryption_protocol=
2017-04-27 20:04:07 DEBUG smtp session: encryption_cipher=
2017-04-27 20:04:07 DEBUG smtp session: encryption_keysize=0
2017-04-27 20:04:07 DEBUG smtp session: policy_context=
2017-04-27 20:04:07 DEBUG Skip plugin: reject_null_sender (protocol_state != END-OF-MESSAGE)
2017-04-27 20:04:07 DEBUG Skip plugin: reject_sender_login_mismatch (protocol_state != END-OF-MESSAGE)
2017-04-27 20:04:07 DEBUG Skip plugin: greylisting (protocol_state != END-OF-MESSAGE)
2017-04-27 20:04:07 DEBUG --> Apply plugin: throttle
2017-04-27 20:04:07 DEBUG Check sender throttling.
2017-04-27 20:04:07 DEBUG [SQL] Query throttle setting:

        SELECT id, account, priority, period, max_msgs, max_quota, msg_size
          FROM throttle
         WHERE kind='external' AND account IN ('108.60.212.145', '@ip', '@.', 'test@ismyemailworking.com', '@ismyemailworking.com', '@.ismyemailworking.com', '@com', '@.com', '108.60.212.*', '108.60.*.145')
         ORDER BY priority DESC
         
2017-04-27 20:04:07 DEBUG [SQL] Query result:
[]
2017-04-27 20:04:07 DEBUG No sender throttle setting.
2017-04-27 20:04:07 DEBUG Check recipient throttling.
2017-04-27 20:04:07 DEBUG [SQL] Query throttle setting:

        SELECT id, account, priority, period, max_msgs, max_quota, msg_size
          FROM throttle
         WHERE kind='inbound' AND account IN ('108.60.212.145', '@ip', '@.', '#test@domain.com', '@domain.com', '@.domain.com', '@net', '@.net', '108.60.212.*', '108.60.*.145')
         ORDER BY priority DESC
         
2017-04-27 20:04:07 DEBUG [SQL] Query result:
[]
2017-04-27 20:04:07 DEBUG No recipient throttle setting.
2017-04-27 20:04:07 DEBUG <-- Result: DUNNO
2017-04-27 20:04:07 DEBUG Skip plugin: sql_alias_access_policy (protocol_state != END-OF-MESSAGE)
2017-04-27 20:04:07 DEBUG Skip plugin: amavisd_wblist (protocol_state != END-OF-MESSAGE)
2017-04-27 20:04:07 DEBUG Session ended.
2017-04-27 20:04:07 INFO 108.60.212.145 END-OF-MESSAGE, test@ismyemailworking.com -> #test@domain.com, DUNNO [0.0096s]

9 Reply by ZhangHuangbin

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

Re: iredapd letting email be sent to alias islist when it should reject it

BenSuffolk wrote:

2017-04-27 20:04:06 INFO 108.60.212.145 RCPT, test@ismyemailworking.com -> #test@domain.com, 451 4.7.1 Intentional policy rejection, please try again later [0.0381s]

According to iRedAPD log, it correctly rejects the email (greylisted), and expected behaviour is this smtp session doesn't go through END-OF-MESSAGE state. Could you please show us full "postconf -n"?

10 Reply by BenSuffolk (edited by BenSuffolk 2017-05-01 05:13:32)

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

Please see postconf output. I don't think I have made any changes to the config file for postfix.

It does normally do the grey listing fine, as I see mails rejected, and re trying. Its like the first test I did above, it seems that postfix is ignoring the request from the policy server to reject the mail.

root@mx:~# postconf -n
alias_database = hash:/etc/postfix/aliases
alias_maps = hash:/etc/postfix/aliases
allow_min_user = no
allow_percent_hack = no
biff = no
body_checks = pcre:/etc/postfix/body_checks.pcre
command_directory = /usr/sbin
compatibility_level = 2
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/lib/postfix/sbin
data_directory = /var/lib/postfix
debug_peer_level = 2
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5
disable_vrfy_command = yes
dovecot_destination_recipient_limit = 1
enable_original_recipient = no
header_checks = pcre:/etc/postfix/header_checks
inet_interfaces = all
inet_protocols = all
lmtp_tls_mandatory_protocols = !SSLv2 !SSLv3
lmtp_tls_protocols = !SSLv2 !SSLv3
mail_owner = postfix
mailq_path = /usr/bin/mailq
message_size_limit = 20971520
mydestination = $myhostname, localhost, localhost.localdomain
mydomain = mx.domain.com
myhostname = mx.domain.com
mynetworks = 127.0.0.1
myorigin = mx.domain.com
newaliases_path = /usr/bin/newaliases
postscreen_access_list = permit_mynetworks cidr:/etc/postfix/postscreen_access.cidr
postscreen_blacklist_action = enforce
postscreen_dnsbl_action = enforce
postscreen_dnsbl_reply_map = texthash:/etc/postfix/postscreen_dnsbl_reply
postscreen_dnsbl_sites = zen.spamhaus.org=127.0.0.[2..11]*3 b.barracudacentral.org=127.0.0.[2..11]*2
postscreen_dnsbl_threshold = 2
postscreen_dnsbl_whitelist_threshold = -2
postscreen_greet_action = enforce
proxy_read_maps = $canonical_maps $lmtp_generic_maps $local_recipient_maps $mydestination $mynetworks $recipient_bcc_maps $recipient_canonical_maps $relay_domains $relay_recipient_maps $relocated_maps $sender_bcc_maps $sender_canonical_maps $smtp_generic_maps $smtpd_sender_login_maps $transport_maps $virtual_alias_domains $virtual_alias_maps $virtual_mailbox_domains $virtual_mailbox_maps $smtpd_sender_restrictions $sender_dependent_relayhost_maps
queue_directory = /var/spool/postfix
recipient_bcc_maps = proxy:mysql:/etc/postfix/mysql/recipient_bcc_maps_user.cf proxy:mysql:/etc/postfix/mysql/recipient_bcc_maps_domain.cf
recipient_delimiter = +
relay_domains = $mydestination proxy:mysql:/etc/postfix/mysql/relay_domains.cf
sender_bcc_maps = proxy:mysql:/etc/postfix/mysql/sender_bcc_maps_user.cf proxy:mysql:/etc/postfix/mysql/sender_bcc_maps_domain.cf
sender_canonical_maps = hash:/etc/postfix/sender_canonical
sender_dependent_relayhost_maps = proxy:mysql:/etc/postfix/mysql/sender_dependent_relayhost_maps.cf
sendmail_path = /usr/sbin/sendmail
setgid_group = postdrop
smtp-amavis_destination_recipient_limit = 1
smtp_tls_CAfile = $smtpd_tls_CAfile
smtp_tls_loglevel = 1
smtp_tls_mandatory_protocols = !SSLv2 !SSLv3
smtp_tls_note_starttls_offer = yes
smtp_tls_protocols = !SSLv2 !SSLv3
smtp_tls_security_level = may
smtpd_data_restrictions = reject_unauth_pipelining
smtpd_end_of_data_restrictions = check_policy_service inet:127.0.0.1:7777
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks permit_sasl_authenticated reject_non_fqdn_helo_hostname reject_unknown_helo_hostname check_helo_access pcre:/etc/postfix/helo_access.pcre
smtpd_recipient_restrictions = reject_unknown_recipient_domain reject_non_fqdn_recipient reject_unlisted_recipient check_policy_service inet:127.0.0.1:7777 permit_mynetworks permit_sasl_authenticated reject_unauth_destination
smtpd_reject_unlisted_recipient = yes
smtpd_reject_unlisted_sender = yes
smtpd_sasl_path = private/dovecot-auth
smtpd_sasl_type = dovecot
smtpd_sender_login_maps = proxy:mysql:/etc/postfix/mysql/sender_login_maps.cf
smtpd_sender_restrictions = reject_unknown_sender_domain reject_non_fqdn_sender reject_unlisted_sender permit_mynetworks permit_sasl_authenticated check_sender_access pcre:/etc/postfix/sender_access.pcre
smtpd_tls_CAfile = /etc/letsencrypt/live/mx.domain.com/fullchain.pem
smtpd_tls_cert_file = /etc/letsencrypt/live/mx.domain.com/fullchain.pem
smtpd_tls_dh1024_param_file = /etc/ssl/dh2048_param.pem
smtpd_tls_dh512_param_file = /etc/ssl/dh512_param.pem
smtpd_tls_exclude_ciphers = aNULL, eNULL, EXPORT, DES, RC4, MD5, PSK, aECDH, EDH-DSS-DES-CBC3-SHA, EDH-RSA-DES-CDC3-SHA, KRB5-DE5, CBC3-SHA
smtpd_tls_key_file = /etc/letsencrypt/live/mx.domain.com/privkey.pem
smtpd_tls_loglevel = 1
smtpd_tls_mandatory_protocols = !SSLv2 !SSLv3
smtpd_tls_protocols = !SSLv2 !SSLv3
smtpd_tls_security_level = may
swap_bangpath = no
tls_random_source = dev:/dev/urandom
transport_maps = proxy:mysql:/etc/postfix/mysql/transport_maps_user.cf proxy:mysql:/etc/postfix/mysql/transport_maps_domain.cf
unknown_local_recipient_reject_code = 550
virtual_alias_domains =
virtual_alias_maps = proxy:mysql:/etc/postfix/mysql/virtual_alias_maps.cf proxy:mysql:/etc/postfix/mysql/domain_alias_maps.cf proxy:mysql:/etc/postfix/mysql/catchall_maps.cf proxy:mysql:/etc/postfix/mysql/domain_alias_catchall_maps.cf
virtual_gid_maps = static:2000
virtual_mailbox_base = /var/vmail
virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql/virtual_mailbox_domains.cf
virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql/virtual_mailbox_maps.cf
virtual_minimum_uid = 2000
virtual_transport = dovecot
virtual_uid_maps = static:2000

11 Reply by ZhangHuangbin

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

Re: iredapd letting email be sent to alias islist when it should reject it

Is it possible to give me direct ssh access to debug it on your server?

12 Reply by BenSuffolk

  • BenSuffolk
  • Member
  • Offline
  • Registered: 2017-04-14
  • Posts: 14

Re: iredapd letting email be sent to alias islist when it should reject it

Sure, drop me an email with your public key

Ben

13 Reply by ZhangHuangbin

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

Re: iredapd letting email be sent to alias islist when it should reject it

Mail sent.