Posftwd is double counting emails when used with Posftix and amavis

Question

Our Postfix mail server uses Amavis with spam assassin for spam and virus scanning. We have it setup in a way , postfix forwards mail to amavis and amavis then re queue the email back to postfix to sending it to destination. I have setup postfwd with a simple rule to reject emails after a threshold for sender but Postfwd is double counting the emails. When I send one email through Outlook as a mail client, Postfwd is counting it as two instead. Im new with SMTP protocols and is struggling to pin point the issue. If anyone could please help. I have pasted some configuration snippets which I think will be useful below.

Below is an output for postconf -n

append_dot_mydomain = no
biff = no
broken_sasl_auth_clients = yes
content_filter = amavis:[127.0.0.1]:10024
disable_vrfy_command = yes
dovecot_destination_recipient_limit = 1
enable_original_recipient = no
header_checks = regexp:/etc/postfix/header_checks
inet_interfaces = all
mailbox_size_limit = 0
maximal_backoff_time = 8000s
maximal_queue_lifetime = 7d
minimal_backoff_time = 1000s
mydestination = $myhostname
myhostname = pXXX
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128,XXX
mynetworks_style = host
myorigin = /etc/hostname
readme_directory = no
recipient_delimiter = +
relay_domains = hash:/etc/postfix/relay_recipients
smtp_enforce_tls = no
smtp_helo_timeout = 60s
smtp_tls_note_starttls_offer = yes
smtp_tls_security_level = may
smtp_use_tls = yes
smtpd_banner = $myhostname ESMTP $mail_name
smtpd_client_connection_count_limit = 30
smtpd_client_recipient_rate_limit = 300
smtpd_client_restrictions = permit_mynetworks, permit_sasl_authenticated, check_client_access hash:/etc/postfix/whitelist, reject_rbl_client sbl.spamhaus.org
smtpd_data_restrictions = reject_unauth_pipelining
smtpd_delay_reject = yes
smtpd_enforce_tls = no
smtpd_hard_error_limit = 12
smtpd_helo_required = yes
smtpd_helo_restrictions = check_client_access hash:/etc/postfix/whitelist, permit_mynetworks, warn_if_reject reject_non_fqdn_hostname, reject_invalid_hostname
smtpd_recipient_limit = 30
smtpd_recipient_restrictions = reject_unauth_pipelining, check_policy_service inet:127.0.0.1:10040, permit_mynetworks, permit_sasl_authenticated, reject_non_fqdn_recipient, reject_unknown_recipient_domain, reject_unauth_destination, check_policy_service inet:127.0.0.1:10023
smtpd_relay_restrictions = permit_mynetworks, check_client_access hash:/etc/postfix/whitelist, check_sender_access hash:/etc/postfix/whitelist, permit_sasl_authenticated, reject_non_fqdn_recipient, reject_unknown_recipient_domain, reject_unauth_destination, check_policy_service inet:127.0.0.1:10023
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
smtpd_sasl_local_domain =
smtpd_sasl_path = private/auth
smtpd_sasl_type = dovecot
smtpd_sender_restrictions = check_sender_access hash:/etc/postfix/sender_access, permit_sasl_authenticated, permit_mynetworks, reject_unknown_sender_domain, reject_unauth_pipelining, warn_if_reject reject_sender_login_mismatch, warn_if_reject reject_non_fqdn_sender, warn_if_reject reject_unlisted_sender, warn_if_reject reject_non_fqdn_sender
smtpd_soft_error_limit = 3
smtpd_tls_cert_file = XXX
smtpd_tls_key_file = XXX
smtpd_tls_loglevel = 1
smtpd_tls_received_header = yes
smtpd_tls_security_level = may
smtpd_tls_session_cache_timeout = 3600s
smtpd_use_tls = yes
tls_random_source = dev:/dev/urandom
transport_maps = hash:/etc/postfix/transport
unknown_local_recipient_reject_code = 450
virtual_alias_maps = proxy:mysql:/etc/postfix/mysql_virtual_alias_maps.cf, proxy:mysql:/etc/postfix/mysql_virtual_alias_domainaliases_maps.cf
virtual_gid_maps = static:125
virtual_mailbox_base = /home/vmail
virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql_virtual_domains_maps.cf
virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql_virtual_mailbox_maps.cf, proxy:mysql:/etc/postfix/mysql_virtual_mailbox_domainaliases_maps.cf
virtual_transport = dovecot
virtual_uid_maps = static:150

Postfwd rules:

id=20perminute; sender=~/Xxxx@xxx.com/; action=rate(sender/20/60/REJECT only 20 messages per minute for $$sender)

Anyone able to help throw some light into this issue?

Answer 1

But... you already discovered almost everything!

You have an additional smtpd service which is usually set up in master.cf like this:

smtp:10025      inet  n       -       n       -       -       smtpd
...

Amavis is configured to reinject mail back to 127.0.0.1:10025 (or whichever port you use). The idea is this: you run special private service on non-default firewalled port to only accept processed mail.

This kind of configuration works like this:

1. One of Postfix smtpd instances, mail exchanger or submission, receives mail from outside and logs it for the first time (and calls policy service)
2. Then, according to a configuration, it pushes it into Amavis
3. Amavis, after processing, reinjects mail back to Postfix, but it gives it to special smtpd instance which is configured to not give mail back to Amavis, because it expects all mail comes into it from Amavis
4. This additional smtpd logs that mail again (and calls policy service) and then forwards it according to usual rules.

There is no way to fix double logging in such setup, because it is caused by this inherently inferior way to insert Amavis into processing via SMTP. But you still have a way to at least reduce the impact of this double logging. You may give your additional smtpd instance distinct log prefix, thereby creating a way to distingush which one processes the mail this time. After the line where the additional smtpd service is defined in the master.cf, add the line:

  -o syslog_name=postfix/reinject

(or whatever you're going to use to distingush it from other smtpd instances, mail exchanger and submission).

Also, you may disable policy service processing for this instance, so the postfwd won't count mail twice. You have to replicate your all smtpd_*_restrictions in the master.cf for this service where, not including this policy service:

...
  -o smtpd_recipient_restrictions=...,reject_unauth_destination
...

never put spaces in master.cf -o parameters!

Messy, I know. This is because this whole setup with reinjection is messy.

It's likely you already have some other parameters there; that's ok, they are still required. Also notice, this only changes smtpd logging behaviour; it then puts mail into the common queue where other daemons pick it up and process and as we didn't created special logging configuration for them, you won't be able to easily distinguish whether they process original mail or processed this time (hint: mail queue ID is useful for that). So this is only a partial fix, but still it is very useful.

---

To completely fix that double logging, you have to redesign your mail system so that no single mail is going to go through it twice. So each mail will be accounted once, as by magic. Postfix has a special dedicated way to do mail processing, called milter ("mail filter"), which you're advised to employ instead of SMTP and reinjecting. You can connect Amavis or any other milter-supporting application (there are myriad of them) through this interface and you'll get much cleaner mail routing pathway inside mail system and less hassle with logs and other problems. Postfix will immediately reject spam mail instead of queuing, checking and then dropping. Read Postfix's perfect manual about Postfix before-queue Milter support