I have a Postfix (2.10.1) / Dovecot server running on Centos 7. From specific servers I get about 50 copies of the same email every weekend, I tried a wireshark but it uses STARTTLS so its all encrypted, so I turned on logging in postfix. Everything looks fine, then I get a huge delay in-between the DATA and the QUEUED. See Below. Note the time stamp, it takes 4 minutes and 14 seconds, there also is no QUIT at the end and I think and the remote server is timing out so it just keeps sending the message. I noticed the delay appears to be with opendkim, so any idea how to fix this? Is this a opendkim issue? Why is it checking the DKIM during the DATA transmission? Why would it take that long to check a DKIM Signature? So far this is only happening to about three senders I know of, but its getting quite bothersome. Thanks!
Sep 5 15:15:10 services postfix/smtpd[17135]: > unknown[54.240.15.240]: 250 2.1.5 Ok
Sep 5 15:15:10 services postfix/smtpd[17135]: < unknown[54.240.15.240]: DATA
Sep 5 15:15:10 services postfix/smtpd[17135]: report data to all milters
Sep 5 15:15:10 services postfix/smtpd[17135]: milter_macro_lookup: "i"
Sep 5 15:15:10 services postfix/smtpd[17135]: milter_macro_lookup: result "4A0FB12A7"
Sep 5 15:15:10 services postfix/smtpd[17135]: milter8_data_event: milter inet:127.0.0.1:8891: data command
Sep 5 15:15:10 services postfix/smtpd[17135]: skipping non-protocol event SMFIC_DATA for milter inet:127.0.0.1:8891
Sep 5 15:15:10 services postfix/smtpd[17135]: send 1 milters
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr conn_macros = j {daemon_name} v
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr helo_macros = {tls_version} {cipher} {cipher_bits} {cert_subject} {cert_issuer}
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr mail_macros = i {auth_type} {auth_authen} {auth_author} {mail_addr} {mail_host} {mail_mailer}
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr rcpt_macros = i {rcpt_addr} {rcpt_host} {rcpt_mailer}
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr data_macros = i
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr eoh_macros = i
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr eod_macros = i
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr unk_macros =
Sep 5 15:15:10 services postfix/smtpd[17135]: milter8_send: milter inet:127.0.0.1:8891
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_name = inet:127.0.0.1:8891
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_version = 2
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_actions = 273
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_events = 2
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_non_events = 768
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_state = 4
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_conn_timeout = 30
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_cmd_timeout = 30
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_msg_timeout = 300
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_action = accept
Sep 5 15:15:10 services postfix/smtpd[17135]: send attr milter_macro_list = 0
Sep 5 15:15:10 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: dummy
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute name: dummy
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute value: (end)
Sep 5 15:15:10 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: (list terminator)
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute name: (end)
Sep 5 15:15:10 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: dummy
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute name: dummy
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute value: (end)
Sep 5 15:15:10 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: (list terminator)
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute name: (end)
Sep 5 15:15:10 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: status
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute name: status
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute value: 0
Sep 5 15:15:10 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: (list terminator)
Sep 5 15:15:10 services postfix/smtpd[17135]: input attribute name: (end)
Sep 5 15:15:10 services postfix/smtpd[17135]: > unknown[54.240.15.240]: 354 End data with <CR><LF>.<CR><LF>
Sep 5 15:15:10 services postfix/cleanup[17137]: 4A0FB12A7: message-id=<010001830f0b97bf-95e8fbf3-db43-47f5-b374-375fb854f93d-000000@email.amazonses.com>
Sep 5 15:15:10 services opendkim[844]: 4A0FB12A7: [54.240.15.240] [54.240.15.240] not internal
Sep 5 15:15:10 services opendkim[844]: 4A0FB12A7: not authenticated
Sep 5 15:19:24 services opendkim[844]: 4A0FB12A7: message has signatures from primevideo.com, amazonses.com
Sep 5 15:19:24 services opendkim[844]: 4A0FB12A7: DKIM verification successful
Sep 5 15:19:24 services postfix/qmgr[17047]: 4A0FB12A7: from=<202209051906004530ab8903c4489cb0803dfa57e0p0na-C2PQNMO0KKWW5B@bounces.primevideo.com>, size=98742, nrcpt=1 (queue activ
e)
Sep 5 15:19:24 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: status
Sep 5 15:19:24 services postfix/smtpd[17135]: input attribute name: status
Sep 5 15:19:24 services postfix/smtpd[17135]: input attribute value: 0
Sep 5 15:19:24 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: reason
Sep 5 15:19:24 services postfix/smtpd[17135]: input attribute name: reason
Sep 5 15:19:24 services postfix/smtpd[17135]: input attribute value: (end)
Sep 5 15:19:24 services postfix/smtpd[17135]: public/cleanup socket: wanted attribute: (list terminator)
Sep 5 15:19:24 services postfix/smtpd[17135]: input attribute name: (end)
Sep 5 15:19:24 services postfix/smtpd[17135]: > unknown[54.240.15.240]: 250 2.0.0 Ok: queued as 4A0FB12A7
Added master.cf -
command_directory = /usr/sbin
daemon_directory = /usr/libexec/postfix
data_directory = /var/lib/postfix
debug_peer_level = 2
smtp_tls_loglevel = 4
debugger_command =
PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin
ddd $daemon_directory/$process_name $process_id & sleep 5
sendmail_path = /usr/sbin/sendmail.postfix
newaliases_path = /usr/bin/newaliases.postfix
mailq_path = /usr/bin/mailq.postfix
setgid_group = postdrop
html_directory = no
manpage_directory = /usr/share/man
sample_directory = /usr/share/doc/postfix-2.10.1/samples
readme_directory = /usr/share/doc/postfix-2.10.1/README_FILES
myorigin = origindom.com
inet_protocols = all
mydestination = /etc/postfix/mydestination
unknown_local_recipient_reject_code = 550
mynetworks = 127.0.0.0/8
alias_database = hash:/etc/postfix/aliases
alias_maps = hash:/etc/postfix/aliases
home_mailbox = Maildir/
mail_spool_directory = /var/spool/mail
mailbox_command = /usr/bin/procmail
smtpd_banner = mail.origindom.com ESMTP $mail_name ($mail_version)
mynetworks_style = class
ignore_mx_lookup_error = yes
smtpd_recipient_restrictions = permit_sasl_authenticated reject_unauth_destinati on
smtpd_sender_restrictions = permit_sasl_authenticated reject_unauth_destination
smtpd_sasl_authenticated_header = yes
smtpd_tls_cert_file = /etc/letsencrypt/live/mail.origindom.com/fullchain.pem
smtpd_tls_key_file = /etc/letsencrypt/live/mail.origindom.com/privkey.pem
smtpd_tls_session_cache_database = btree:/var/lib/postfix/smtpd_tls_session_cach e
smtpd_use_tls = yes
smtpd_tls_security_level = may
tls_random_source = dev:/dev/urandom
mailbox_size_limit = 5368709120
debug_peer_list = origindom.com
message_size_limit = 31457280
myhostname = origindom.com
smtpd_sasl_type = dovecot
smtpd_sasl_path = private/auth
smtpd_sasl_auth_enable = yes
smtp_sasl_security_options = noanonymous
smtpd_relay_restrictions = permit_mynetworks permit_inet_interfaces permit_sasl_ authenticated
milter_protocol = 2
smtpd_milters = inet:127.0.0.1:8891
non_smtpd_milters = $smtpd_milters
milter_default_action = accept
receive_override_options = no_address_mappings
sender_bcc_maps = hash:/etc/postfix/sender_bcc_maps
sender_canonical_maps = regexp:/etc/postfix/sender_canonical_maps
canonical_maps = hash:/etc/postfix/canonical