NEOHAPSIS - Peace of Mind Through Integrity and Insight

Neohapsis is currently accepting applications for employment. For more information, please visit our website www.neohapsis.com or email hr@neohapsis.com

Neohapsis > Archives > Postfix Discussion> 2009-09

Weird postfix looping for some emails

From: Preston Lord (plordinetx.ca)
Date: Wed Sep 09 2009 - 12:58:05 CDT

Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hi All,

We are having an issue with postfix where some messages keep looping to the
local recipient every hour or so. Servers that we consistently have trouble
with are apple.com servers : in this example bz1.apple.com .

I will post the details below, but the server bz1.apple.com sends them
message fine, we receive it in the users account, but in the logs of
bz1.apple.com it shows as unresponsive so it sends again a while later, and
then again, and again, creating a loop.

I have tried disabling amavis-new and postgrey and even adding the IP of
bz1.apple.com to mynetworks, all with the same result.

Here is a debug log from 1 example transaction:

Sep 9 10:08:29 mx postfix/smtpd[641]: connect from
bz1.apple.com[17.254.13.36]
Sep 9 10:08:29 mx postfix/smtpd[641]: match_hostname: bz1.apple.com ~?
17.254.13.36
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]: 220
mx.static.intricatenetworks.com ESMTP Postfix (Debian/GNU)
Sep 9 10:08:29 mx postfix/smtpd[641]: < bz1.apple.com[17.254.13.36]: EHLO
bz1.apple.com
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-mx.static.intricatenetworks.com
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-PIPELINING
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-SIZE 20480000
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-VRFY
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-ETRN
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-AUTH PLAIN LOGIN CRAM-MD5
Sep 9 10:08:29 mx postfix/smtpd[641]: match_list_match: bz1.apple.com: no
match
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-AUTH=PLAIN LOGIN CRAM-MD5
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-ENHANCEDSTATUSCODES
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]:
250-8BITMIME
Sep 9 10:08:29 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]: 250
DSN
Sep 9 10:08:34 mx postfix/smtpd[641]: < bz1.apple.com[17.254.13.36]: MAIL
FROM:<donotreplyapple.com> SIZE=27230 ENVID=ADR34000010549502
Sep 9 10:08:34 mx postfix/smtpd[641]: extract_addr: input:
<donotreplyapple.com>
Sep 9 10:08:34 mx postfix/smtpd[641]: smtpd_check_addr:
addr=donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: send attr address =
donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: input attribute value:
donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: rewrite_clnt: local:
donotreplyapple.com -> donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: send attr address =
donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: input attribute value: apple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: input attribute value:
donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: resolve_clnt: `' ->
`donotreplyapple.com' -> transp=`smtp' host=`apple.com'
rcpt=`donotreplyapple.com' flags= class=default
Sep 9 10:08:34 mx postfix/smtpd[641]: ctable_locate: install entry key
donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: extract_addr: in:
<donotreplyapple.com>, result: donotreplyapple.com
Sep 9 10:08:34 mx postfix/smtpd[641]: match_list_match: bz1.apple.com: no
match
Sep 9 10:08:34 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]: 250
2.1.0 Ok
Sep 9 10:08:35 mx postfix/smtpd[641]: < bz1.apple.com[17.254.13.36]: RCPT
TO:<PLORDSWT.CA> ORCPT=rfc822;PLORDSWT.CA NOTIFY=FAILURE
Sep 9 10:08:35 mx postfix/smtpd[641]: check_mail_access:
donotreplyapple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: ctable_locate: move existing entry
key donotreplyapple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: check_access: donotreplyapple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: check_domain_access: apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: reject_non_fqdn_address:
donotreplyapple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: reject_unknown_address:
donotreplyapple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: ctable_locate: leave existing entry
key donotreplyapple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: reject_unknown_mailhost: apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: lookup apple.com type MX flags 0
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_query: apple.com (MX): OK
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_get_answer: type MX for apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_get_answer: type MX for apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_get_answer: type MX for apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_get_answer: type MX for apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_get_answer: type MX for apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_get_answer: type MX for apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: dns_get_answer: type MX for apple.com
Sep 9 10:08:35 mx postfix/smtpd[641]: permit_mynetworks: bz1.apple.com
17.254.13.36
Sep 9 10:08:35 mx postfix/smtpd[641]: match_hostname: bz1.apple.com ~?
17.254.13.36
Sep 9 10:08:35 mx postfix/smtpd[641]: permit_inet_interfaces: bz1.apple.com
17.254.13.36
Sep 9 10:08:35 mx postfix/smtpd[641]: 107B78B2629:
client=bz1.apple.com[17.254.13.36]
Sep 9 10:08:35 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]: 250
2.1.5 Ok
Sep 9 10:08:35 mx postfix/smtpd[641]: < bz1.apple.com[17.254.13.36]: DATA
Sep 9 10:08:35 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]: 354
End data with <CR><LF>.<CR><LF>
Sep 9 10:12:10 mx postfix/cleanup[5569]: 107B78B2629:
message-id=<ADR34000010549502apple.com>
Sep 9 10:19:50 mx postfix/smtpd[928]: connect from
mail-out3.apple.com[17.254.13.22]
Sep 9 10:19:55 mx postfix/smtpd[928]: A85258B25C0:
client=mail-out3.apple.com[17.254.13.22]
Sep 9 10:23:57 mx postfix/cleanup[1603]: A85258B25C0:
message-id=<C3293F9B-498E-44D5-B8AE-0E4131F8801Aapple.com>
Sep 9 10:33:57 mx postfix/qmgr[426]: 107B78B2629:
from=<donotreplyapple.com>, size=27424, nrcpt=1 (queue active)
Sep 9 10:33:57 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]: 250
2.0.0 Ok: queued as 107B78B2629
Sep 9 10:33:57 mx postfix/smtpd[641]: < bz1.apple.com[17.254.13.36]: QUIT
Sep 9 10:33:57 mx postfix/smtpd[641]: > bz1.apple.com[17.254.13.36]: 221
2.0.0 Bye
Sep 9 10:33:57 mx postfix/smtpd[641]: match_hostname: bz1.apple.com ~?
17.254.13.36
Sep 9 10:33:57 mx postfix/smtpd[641]: disconnect from
bz1.apple.com[17.254.13.36]
Sep 9 10:33:57 mx postfix/cleanup[7058]: B0D128B262E:
message-id=<ADR34000010549502apple.com>
Sep 9 10:33:57 mx postfix/qmgr[426]: B0D128B262E:
from=<donotreplyapple.com>, size=27922, nrcpt=1 (queue active)
Sep 9 10:33:57 mx amavis[7986]: (07986-03) Passed CLEAN, [17.254.13.36]
[17.34.124.12] <donotreplyapple.com> -> <plordholderswt.ca>, Message-ID:
<ADR34000010549502apple.com>, mail_id: D-2doSDv8klX, Hits: -, size: 27424,
queued_as: B0D128B262E, 152 ms
Sep 9 10:49:41 mx postfix/smtpd[928]: disconnect from
mail-out3.apple.com[17.254.13.22]
Sep 9 10:49:41 mx postfix/qmgr[426]: A85258B25C0:
from=<cthornsberryapple.com>, size=32222, nrcpt=1 (queue active)
Sep 9 10:49:41 mx postfix/cleanup[9049]: E1E008B2629:
message-id=<C3293F9B-498E-44D5-B8AE-0E4131F8801Aapple.com>
Sep 9 10:49:41 mx postfix/qmgr[426]: E1E008B2629:
from=<cthornsberryapple.com>, size=32720, nrcpt=1 (queue active)
Sep 9 10:49:41 mx amavis[9389]: (09389-03) Passed CLEAN, [17.254.13.22]
[17.107.83.56] <cthornsberryapple.com> -> <plordholderswt.ca>, Message-ID:
<C3293F9B-498E-44D5-B8AE-0E4131F8801Aapple.com>, mail_id: dHOP8AS2Mfdj,
Hits: -, size: 32222, queued_as: E1E008B2629, 180 ms

mx:~# postconf -n
alias_database = hash:/etc/aliases
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
body_checks = pcre:/etc/postfix/body_checks
broken_sasl_auth_clients = yes
config_directory = /etc/postfix
debug_peer_list = 142.165.20.181 17.34.124.12 17.254.13.36
inet_interfaces = all
local_transport = error:no local mail delivery
mailbox_command = procmail -a "$EXTENSION"
mailbox_size_limit = 0
message_size_limit = 20480000
mydestination =
mydomain = intricatenetworks.com
myhostname = mx.static.intricatenetworks.com
mynetworks = 17.254.13.36 17.34.124.12 75.152.248.17 209.115.234.5
207.195.37.91 10.50.90.0/24 127.0.1.1 127.0.0.0/8 [::ffff:127.0.0.0]/104
[::1]/128
myorigin = intricatenetworks.com
readme_directory = no
recipient_delimiter = +
relayhost =
smtp_connect_timeout = 180s
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_error_sleep_time = 60
smtpd_hard_error_limit = 10
smtpd_helo_required = yes
smtpd_recipient_restrictions = permit_mynetworks, permit_sasl_authenticated,
reject_unauth_destination, reject_unlisted_recipient, check_recipient_access
hash:/etc/postfix/reject_over_quota, check_sender_access
hash:/etc/postfix/rbl_sender_exceptions, check_client_access
hash:/etc/postfix/rbl_client_exceptions, check_recipient_access
hash:/etc/postfix/rbl_recipient_exceptions, reject_rbl_client
sbl-xbl.spamhaus.org, check_recipient_access
hash:/etc/postfix/greylist_sender_exceptions, check_client_access
cidr:/etc/postfix/cidr_greylist_network_exceptions, check_client_access
pcre:/etc/postfix/check_client_fqdn
smtpd_restriction_classes = check_greylist
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
smtpd_sasl_local_domain = $myhostname
smtpd_sasl_path = private/auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = dovecot
smtpd_sender_restrictions = check_sender_access
hash:/etc/postfix/sender_access, reject_non_fqdn_sender,
reject_unknown_sender_domain
smtpd_soft_error_limit = 60
smtpd_tls_CAfile = /etc/apache2/BundledRootCA.crt
smtpd_tls_cert_file = /etc/apache2/mail.intricatenetworks.com.crt
smtpd_tls_key_file = /etc/apache2/mail.intricatenetworks.com.key
smtpd_tls_received_header = yes
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
transport_maps = hash:/etc/postfix/transport
virtual_alias_maps = proxy:mysql:/etc/postfix/mysql_virtual_alias_maps.cf,
hash:/etc/postfix/virtual
virtual_gid_maps = static:6060
virtual_mailbox_base = /var/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
virtual_minimum_uid = 6060
virtual_transport = dovecot
virtual_uid_maps = static:6060

#master.cf
# service type private unpriv chroot wakeup maxproc command + args

smtp inet n - - - - smtpd
# -o smtp_connect_timeout=120
  -o smtpd_sasl_auth_enable=yes
  -o content_filter=smtp-amavis:[127.0.0.1]:10024
submission inet n - - - - smtpd
  -o smtpd_tls_security_level=may
  -o smtpd_sasl_auth_enable=yes
  -o smtpd_client_restrictions=permit_sasl_authenticated,reject
  -o
-receive_override_options=no_unknown_recipient_checks,no_address_mappings,no
_header_body_checks
  -o content_filter=smtp-amavis:[127.0.0.1]:10026
smtps inet n - - - - smtpd
  -o smtpd_tls_security_level=encrypt
  -o smtpd_tls_wrappermode=yes
  -o smtpd_sasl_auth_enable=yes
  -o smtpd_client_restrictions=permit_sasl_authenticated,reject
  -o content_filter=smtp-amavis:[127.0.0.1]:10026
4650 inet n - - - - smtpd
  -o smtpd_tls_security_level=encrypt
  -o smtpd_sasl_auth_enable=yes
  -o smtpd_client_restrictions=permit_sasl_authenticated,reject
  -o content_filter=smtp-amavis:[127.0.0.1]:10026
pickup fifo n - - 60 1 pickup
  -o content_filter=
cleanup unix n - - - 0 cleanup
amavis-cleanup unix n - - - 0 cleanup
    -o virtual_alias_maps=hash:/etc/postfix/amavis_virtual
qmgr fifo n - n 300 1 qmgr
tlsmgr unix - - - 1000? 1 tlsmgr
rewrite unix - - - - - trivial-rewrite
bounce unix - - - - 0 bounce
defer unix - - - - 0 bounce
trace unix - - - - 0 bounce
verify unix - - - - 1 verify
flush unix n - - 1000? 0 flush
proxymap unix - - n - - proxymap
proxywrite unix - - n - 1 proxymap
smtp unix - - - - - smtp
# When relaying mail as backup MX, disable fallback_relay to avoid MX loops
relay unix - - - - - smtp
        -o smtp_fallback_relay=
# -o smtp_helo_timeout=5 -o smtp_connect_timeout=5
showq unix n - - - - showq
error unix - - - - - error
retry unix - - - - - error
discard unix - - - - - discard
local unix - n n - - local
virtual unix - n n - - virtual
lmtp unix - - - - - lmtp
anvil unix - - - - 1 anvil
scache unix - - - - 1 scache
#
# ====================================================================
# Interfaces to non-Postfix software. Be sure to examine the manual
# pages of the non-Postfix software to find out what options it wants.
#
# Many of the following services use the Postfix pipe(8) delivery
# agent. See the pipe(8) man page for information about ${recipient}
# and other message envelope options.
# ====================================================================
#
# maildrop. See the Postfix MAILDROP_README file for details.
# Also specify in main.cf: maildrop_destination_recipient_limit=1
#
maildrop unix - n n - - pipe
  flags=DRhu user=vmail argv=/usr/bin/maildrop -d ${recipient}
#
# See the Postfix UUCP_README file for configuration details.
#
uucp unix - n n - - pipe
  flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail
($recipient)
#
# Other external delivery methods.
#
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 -d ${recipient}
-e
vacation unix - n n - - pipe
  flags=Rq user=vacation argv=/var/spool/vacation/vacation.pl -f ${sender}
-- ${recipient}
smtp-amavis unix - - n - 6 smtp
    -o smtp_data_done_timeout=1200
    -o smtp_send_xforward_command=yes
    -o disable_dns_lookups=yes
127.0.0.1:10025 inet n - n - - smtpd
    -o content_filter=
    -o cleanup_service_name=amavis-cleanup
    -o local_recipient_maps=
    -o relay_recipient_maps=
    -o smtpd_restriction_classes=
    -o smtpd_delay_reject=no
    -o smtpd_client_restrictions=permit_mynetworks,reject
    -o smtpd_helo_restrictions=
    -o smtpd_sender_restrictions=
    -o smtpd_recipient_restrictions=permit_mynetworks,reject
    -o smtpd_data_restrictions=reject_unauth_pipelining
    -o smtpd_end_of_data_restrictions=
    -o mynetworks=127.0.0.0/8
    -o smtpd_error_sleep_time=0
    -o smtpd_soft_error_limit=1001
    -o smtpd_hard_error_limit=1000
    -o smtpd_client_connection_count_limit=0
    -o smtpd_client_connection_rate_limit=0
    -o
receive_override_options=no_header_body_checks,no_unknown_recipient_checks,n
o_milters
# port 10035 is where amavisd-new sends notifications
127.0.0.1:10035 inet n - n - - smtpd
    -o content_filter=
    -o local_recipient_maps=
    -o relay_recipient_maps=
    -o smtpd_restriction_classes=
    -o smtpd_delay_reject=no
    -o smtpd_client_restrictions=permit_mynetworks,reject
    -o smtpd_helo_restrictions=
    -o smtpd_sender_restrictions=
    -o smtpd_recipient_restrictions=permit_mynetworks,reject
    -o smtpd_data_restrictions=reject_unauth_pipelining
    -o smtpd_end_of_data_restrictions=
    -o mynetworks=127.0.0.0/8
    -o smtpd_error_sleep_time=0
    -o smtpd_soft_error_limit=1001
    -o smtpd_hard_error_limit=1000
    -o smtpd_client_connection_count_limit=0
    -o smtpd_client_connection_rate_limit=0
    -o
receive_override_options=no_header_body_checks,no_unknown_recipient_checks,n
o_milters

Any help is GREATLY appreciated.

Thanks.

Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]