Join Log in
Score:1
avatar Server

The same message delivered multiple times on postfix

in flag
jamez

I have a problem with the postfix server I manage.

Server was working fine for over 4 years, but recently I have one issue with it.

Some e-mail messages are delivered on "my '' server many times. Those multiplied messages come from some big providers like amazon ses or zoho mail. I have found a similar thread on zoho forum, but it ends with a private message to zoho admins and I can't see how this story ends. It seems like the sender server doesn't know the message was delivered and repeats it many times, and every repeated message is delivered making some kind of flood. I thought that it was related to greylisting, but amazon ses is on whitelist... I think “ my '' postfix server doesn't confirm message delivery "enough" and the sender repeats it. Configuration on "my '' server didn't change recently. I don't have any idea where to look for the problem... postfix itself, postgrey or something else. I would be grateful for any help.

My configuration:

main.cf (without hashed lines):

smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
biff = no

append_dot_mydomain = no


readme_directory = no

compatibility_level = 2

smtpd_tls_cert_file = /etc/postfix/smtpd.cert
smtpd_tls_key_file = /etc/postfix/smtpd.key
smtpd_use_tls = yes
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache


smtpd_relay_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination
myhostname = <hidden>
alias_maps = hash:/etc/aliases, hash:/var/lib/mailman/data/aliases
alias_database = hash:/etc/aliases, hash:/var/lib/mailman/data/aliases
myorigin = /etc/mailname
mydestination = $myhostname, localhost
relayhost =
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
mailbox_size_limit = 0
recipient_delimiter = +
inet_interfaces = all
inet_protocols = all
virtual_alias_domains = proxy:mysql:/etc/postfix/mysql-virtual_alias_domains.cf
virtual_alias_maps = hash:/var/lib/mailman/data/virtual-mailman, proxy:mysql:/etc/postfix/mysql-virtual_forwardings.cf, proxy:mysql:/etc/postfix/mysql-virtual_alias_maps.cf, proxy:mysql:/etc/postfix/mysql-virtual_email2email.cf
virtual_mailbox_domains = proxy:mysql:/etc/postfix/mysql-virtual_domains.cf
virtual_mailbox_maps = proxy:mysql:/etc/postfix/mysql-virtual_mailboxes.cf
virtual_mailbox_base = /var/vmail
virtual_uid_maps = proxy:mysql:/etc/postfix/mysql-virtual_uids.cf
virtual_gid_maps = proxy:mysql:/etc/postfix/mysql-virtual_gids.cf
sender_bcc_maps = proxy:mysql:/etc/postfix/mysql-virtual_outgoing_bcc.cf
smtpd_sasl_auth_enable = yes
broken_sasl_auth_clients = yes
smtpd_sasl_authenticated_header = yes
smtpd_restriction_classes = greylisting
greylisting = check_policy_service inet:127.0.0.1:10023
smtpd_recipient_restrictions = permit_mynetworks, reject_unknown_recipient_domain, reject_unlisted_recipient, permit_sasl_authenticated, reject_non_fqdn_recipient, reject_unauth_destination, check_recipient_access proxy:mysql:/etc/postfix/mysql-virtual_recipient.cf, check_recipient_access mysql:/etc/postfix/mysql-virtual_policy_greylist.cf, check_policy_service unix:private/quota-status
smtpd_tls_security_level = may
transport_maps = hash:/var/lib/mailman/data/transport-mailman, proxy:mysql:/etc/postfix/mysql-virtual_transports.cf
relay_domains = proxy:mysql:/etc/postfix/mysql-virtual_relaydomains.cf
relay_recipient_maps = proxy:mysql:/etc/postfix/mysql-virtual_relayrecipientmaps.cf
smtpd_sender_login_maps = proxy:mysql:/etc/postfix/mysql-virtual_sender_login_maps.cf
proxy_read_maps = $local_recipient_maps $mydestination $virtual_alias_maps $virtual_alias_domains $sender_bcc_maps $virtual_mailbox_maps $virtual_mailbox_domains $relay_recipient_maps $relay_domains $canonical_maps $sender_canonical_maps $recipient_canonical_maps $relocated_maps $transport_maps $mynetworks $smtpd_sender_login_maps $virtual_uid_maps $virtual_gid_maps $smtpd_client_restrictions $smtpd_sender_restrictions $smtpd_recipient_restrictions $smtp_sasl_password_maps $sender_dependent_relayhost_maps
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks, check_helo_access regexp:/etc/postfix/helo_access, permit_sasl_authenticated, reject_invalid_helo_hostname, reject_non_fqdn_helo_hostname, check_helo_access regexp:/etc/postfix/blacklist_helo, reject_unknown_helo_hostname, permit
smtpd_sender_restrictions = permit_mynetworks, check_sender_access proxy:mysql:/etc/postfix/mysql-virtual_sender.cf,  permit_sasl_authenticated, reject_non_fqdn_sender, reject_unlisted_sender
smtpd_client_restrictions = check_client_access proxy:mysql:/etc/postfix/mysql-virtual_client.cf, permit_inet_interfaces, permit_mynetworks, permit_sasl_authenticated, reject_rbl_client zen.spamhaus.org, reject_unauth_pipelining, permit
smtpd_client_message_rate_limit = 100
maildrop_destination_concurrency_limit = 1
maildrop_destination_recipient_limit = 1
virtual_transport = dovecot
header_checks = regexp:/etc/postfix/header_checks
mime_header_checks = regexp:/etc/postfix/mime_header_checks
nested_header_checks = regexp:/etc/postfix/nested_header_checks
body_checks = regexp:/etc/postfix/body_checks
owner_request_special = no
smtp_tls_security_level = dane
smtpd_tls_mandatory_protocols = !SSLv2, !SSLv3
smtpd_tls_protocols = !SSLv2,!SSLv3
smtp_tls_protocols = !SSLv2,!SSLv3
smtpd_tls_exclude_ciphers = RC4, aNULL
smtp_tls_exclude_ciphers = RC4, aNULL
dovecot_destination_recipient_limit = 1
smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
message_size_limit = 0
smtpd_milters = inet:localhost:11332
non_smtpd_milters = inet:localhost:11332
milter_protocol = 6
milter_mail_macros = i {mail_addr} {client_addr} {client_name} {auth_authen}
milter_default_action = accept
smtpd_etrn_restrictions = permit_mynetworks, reject
smtpd_data_restrictions = permit_mynetworks, reject_unauth_pipelining, reject_multi_recipient_bounce, permit
smtpd_tls_mandatory_ciphers = medium
tls_medium_cipherlist = ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA256:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA
tls_preempt_cipherlist = yes
address_verify_negative_refresh_time = 60s
enable_original_recipient = no
smtpd_forbidden_commands = CONNECT,GET,POST,USER,PASS
address_verify_sender_ttl = 15686s
smtp_dns_support_level = dnssec
smtpd_reject_unlisted_sender = no
sender_dependent_relayhost_maps = proxy:mysql:/etc/postfix/mysql-virtual_sender-relayhost.cf
smtp_sasl_password_maps = proxy:mysql:/etc/postfix/mysql-virtual_sender-relayauth.cf, texthash:/etc/postfix/sasl_passwd
smtp_sender_dependent_authentication = yes
smtp_sasl_auth_enable = yes
smtp_sasl_security_options = noanonymous, noplaintext
smtp_sasl_tls_security_options = noanonymous
authorized_flush_users =
authorized_mailq_users = nagios, icinga

smtpd_discard_ehlo_keyword_address_maps = cidr:/etc/postfix/esmtp_access

content_filter = amavis:[127.0.0.1]:10024
smtpd_proxy_options = speed_adjust

and master.cf

smtp      inet  n       -       n       -       -       smtpd

submission inet n       -       n       -       -       smtpd
  -o syslog_name=postfix/submission
  -o smtpd_tls_security_level=encrypt
  -o smtpd_sasl_auth_enable=yes
  -o smtpd_reject_unlisted_recipient=no
  -o smtpd_client_restrictions=$mua_client_restrictions
  -o smtpd_helo_restrictions=$mua_helo_restrictions
  -o smtpd_sender_restrictions=$mua_sender_restrictions
  -o smtpd_recipient_restrictions=
  -o smtpd_relay_restrictions=permit_sasl_authenticated,reject
  -o milter_macro_daemon_name=ORIGINATING
  -o content_filter=amavis:[127.0.0.1]:10026

smtps     inet  n       -       n       -       -       smtpd
  -o syslog_name=postfix/smtps
  -o smtpd_tls_wrappermode=yes
  -o smtpd_sasl_auth_enable=yes
  -o smtpd_client_restrictions=$mua_client_restrictions
  -o smtpd_helo_restrictions=$mua_helo_restrictions
  -o milter_macro_daemon_name=ORIGINATING
pickup    unix  n       -       n       60      1       pickup
cleanup   unix  n       -       n       -       0       cleanup
qmgr      unix  n       -       n       300     1       qmgr
tlsmgr    unix  -       -       n       1000?   1       tlsmgr
rewrite   unix  -       -       n       -       -       trivial-rewrite
bounce    unix  -       -       n       -       0       bounce
defer     unix  -       -       n       -       0       bounce
trace     unix  -       -       n       -       0       bounce
verify    unix  -       -       n       -       1       verify
flush     unix  n       -       n       1000?   0       flush
proxymap  unix  -       -       n       -       -       proxymap
proxywrite unix -       -       n       -       1       proxymap
relay     unix  -       -       n       -       -       smtp
showq     unix  n       -       n       -       -       showq
error     unix  -       -       n       -       -       error
retry     unix  -       -       n       -       -       error
discard   unix  -       -       n       -       -       discard
local     unix  -       n       n       -       -       local
virtual   unix  -       n       n       -       -       virtual
lmtp      unix  -       -       n       -       -       lmtp
anvil     unix  -       -       n       -       1       anvil
scache    unix  -       -       n       -       1       scache
maildrop  unix  -       n       n       -       -       pipe
  flags=DRhu user=vmail argv=/usr/bin/maildrop -d vmail ${extension} ${recipient} ${user} ${nexthop} ${sender}
uucp      unix  -       n       n       -       -       pipe
  flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
ifmail    unix  -       n       n       -       -       pipe
  flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp     unix  -       n       n       -       -       pipe
  flags=Fq. user=bsmtp argv=/usr/lib/bsmtp/bsmtp -t$nexthop -f$sender $recipient
scalemail-backend unix  -       n       n       -       2       pipe
  flags=R user=scalemail argv=/usr/lib/scalemail/bin/scalemail-store ${nexthop} ${user} ${extension}
mailman   unix  -       n       n       -       -       pipe
  flags=FR user=list argv=/usr/lib/mailman/bin/postfix-to-mailman.py
  ${nexthop} ${user}

dovecot   unix  -       n       n       -       -       pipe
  flags=DRhu user=vmail:vmail argv=/usr/lib/dovecot/deliver -f ${sender} -d ${user}@${nexthop}


amavis unix - - n - 2 smtp
        -o syslog_name=postfix/amavis
        -o smtp_data_done_timeout=120
        -o smtp_send_xforward_command=yes
                -o smtp_bind_address=


127.0.0.1:10025 inet n - n - - smtpd
        -o syslog_name=postfix/10025
        -o content_filter=
        -o local_recipient_maps=
        -o relay_recipient_maps=
        -o smtpd_restriction_classes=
        -o smtpd_client_restrictions=
        -o smtpd_helo_restrictions=
        -o smtpd_sender_restrictions=
        -o smtpd_recipient_restrictions=permit_mynetworks,reject
        -o smtpd_end_of_data_restrictions=
        -o mynetworks=127.0.0.0/8
        -o strict_rfc821_envelopes=yes
        -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks
        -o smtp_send_xforward_command=yes
        -o disable_dns_lookups=yes


127.0.0.1:10027 inet n - n - - smtpd
        -o content_filter=
        -o local_recipient_maps=
        -o relay_recipient_maps=
        -o smtpd_restriction_classes=
        -o smtpd_client_restrictions=
        -o smtpd_helo_restrictions=
        -o smtpd_sender_restrictions=
        -o smtpd_recipient_restrictions=permit_mynetworks,reject
        -o smtpd_end_of_data_restrictions=
        -o mynetworks=127.0.0.0/8
        -o strict_rfc821_envelopes=yes
        -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks
        -o smtp_send_xforward_command=yes
        -o milter_default_action=accept
        -o milter_macro_daemon_name=ORIGINATING
        -o disable_dns_lookups=yes

Logs:

May 31 13:41:12 webh postgrey[2921214]: action=pass, reason=triplet found, client_name=<hidden>, client_address=<hidden>, sender=<hidden>, recipient=<hidden>
May 31 13:41:12 webh postfix/smtpd[2983539]: DF3A613F931: client=<hidden>
May 31 13:41:13 webh postfix/cleanup[2984139]: DF3A613F931: message-id=<hidden>
May 31 13:43:15 webh postfix/qmgr[2932048]: DF3A613F931: from=<hidden>, size=21379, nrcpt=1 (queue active)
May 31 13:43:15 webh postfix/smtpd[2983539]: disconnect from <hidden> ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
May 31 13:43:15 webh dovecot: lda(<hidden>)<2985193><WrCwN1P/lWLpjC0A/liSRw>: sieve: msgid=<hidden>: stored mail into mailbox 'INBOX'
May 31 13:43:15 webh postfix/pipe[2985192]: DF3A613F931: to=<hidden>, orig_to=<hidden>, relay=dovecot, delay=124, delays=124/0.03/0/0.08, dsn=2.0.0, status=sent (delivered via dovecot service)
May 31 13:43:15 webh postfix/qmgr[2932048]: DF3A613F931: removed
37
0 + 0
anx avatar
fr flag
anx
Please provide your Postfix configuration using commands shown in the tag description. Gather logs noting the receipt of the messages in question. Add them [into the question](https://serverfault.com/posts/1102098/edit). You may [mask private details that identify you (globally routable IP addresses, DNS names)](https://meta.serverfault.com/questions/963/what-information-should-i-include-or-obfuscate-in-my-posts/6063#6063), but make sure it stays consistent.
2
Reply
anx avatar
fr flag
anx
Specifically, I would be looking into clues about *time spent*, whether that is time Postfix spent waiting for a misbehaving recursive resolver, or some milter/filter software failing to update postfix about its progress in scanning mail. [Increase verbosity](https://www.postfix.org/DEBUG_README.html#verbose) if the timestamps of your current log lines do not already pinpoint at which point Postfix is spending more time than the sender is presumably willing to wait.
0
Reply
in flag
jamez
Hello anx, I have added configuration to my question. In the meantime I have asked my business partner about some logs. There was "uncathegorised bound/Read time error", so I have investigated a little. I have found, that the time e-mail is processing may be too long for some servers (as you have pointed). I can see in the logs that e-mail is processed in the phase (a) about 2 minutes. Every e-mail is processed similar (123-124 seconds in first phase). I am sure that is the reason for sending such e-mail once again and again. So now the point is to find why the first phase lasts so long.
1
Reply
in flag
jamez
I have also run all processes with "-v" switch, I get very detailed log, but during that 2 minutes there was nothing... simply waiting.
0
Reply
in flag
jamez
Thanx anx once again. I have moved my answer from comment to answer, to be more clear for others.
1
Reply
Score:1
avatar Server
in flag
jamez

I have figured out what was the reason. It was that redis server (used by rspamd) was misconfigured. In rspamd logs there was an entry:

cannot get ANNs list from redis: timeout while connecting the server

The answer was found on https://blog.christosoft.de/2019/11/rspamd-redis-connection-refused

I had two entries missed:

write_servers = "127.0.0.1:6379";
read_servers = "127.0.0.1:6379";

I've added it in /etc/rspamd/local.d/redis.conf and delays are now like that: delay=4.7, delays=0.79/0/0.01/3.9 :-)

0 + 0
ธงชาติไทย
Elon Musk
I sit in a Tesla and translated this thread with Ai:

mangohost

Post an answer

Most people don’t grasp that asking a lot of questions unlocks learning and improves interpersonal bonding. In Alison’s studies, for example, though people could accurately recall how many questions had been asked in their conversations, they didn’t intuit the link between questions and liking. Across four studies, in which participants were engaged in conversations themselves or read transcripts of others’ conversations, people tended not to realize that question asking would influence—or had influenced—the level of amity between the conversationalists.