Hello, I've switched few days ago from an old Mac OS X Server 10.3.x / Postfix 2.0.10 to a FreeBSD 7.3 / Postfix 2.7.0. Since then, I've got various problems. This message will present only one of them.
Here is my setup:
A postfix mail gateway (MAILGW) doing address rewriting gets emails from 3
possible sources (the MX, a general purpose SMTP, and a dedicated smtp for
lists : SMTP-LISTES). After rewriting from public email address to internal
email address, it pushes messages to LB, a load-balanced pool of servers
running proprietary software (POP/IMAP/Webmail access).
MX is a independent server, running postfix/spam filter, accepting email from
outside, and sending them to MAILGW for distribution.
MAILGW, SMTP, and SMTP-LISTES are one and only postfix install, running as
postfix-multi.
Since the migration from Postfix 2.0.10 to Postfix 2.7.0, smtp logs on LB pool
display a huge amount of "No answer,timeout" message. From about 0-30 per day,
the timeout count has jumped to 1500-5500 per day.
So it appears that the connection between MAILGW and LB is not always properly
closed. Am I wrong?
Any help is greatly appreciated!
Below you'll find some details, and a tcpdump output for an SMTP session that
ended with a timeout on LB's side.
# postconf -n
authorized_submit_users =
command_directory = /usr/local/sbin
config_directory = /usr/local/etc/postfix-mailgw
daemon_directory = /usr/local/libexec/postfix
data_directory = /var/db/postfix-mailgw
debug_peer_level = 2
empty_address_recipient = MAILER-DAEMON
header_checks = regexp:/usr/local/etc/postfix-mailgw/header_checks
html_directory = /usr/local/share/doc/postfix
inet_interfaces = all
local_recipient_maps =
local_transport = error:local mail delivery is disabled
mail_owner = postfix
mailbox_size_limit = 1000000000
mailq_path = /usr/local/bin/mailq
manpage_directory = /usr/local/man
master_service_disable =
message_size_limit = 10240000
multi_instance_enable = yes
multi_instance_name = postfix-mailgw
mydestination =
myhostname = mailgw.domain.tld
mynetworks_style = host
myorigin = $myhostname
newaliases_path = /usr/local/bin/newaliases
parent_domain_matches_subdomains =
queue_directory = /var/spool/postfix-mailgw
readme_directory = /usr/local/share/doc/postfix
relay_domains = listes.domain.tld mail.domain.tld nemesis.domain.tld
sample_directory = /usr/local/etc/postfix
sendmail_path = /usr/local/sbin/sendmail
setgid_group = maildrop
smtp_destination_concurrency_limit = 10
smtp_destination_recipient_limit = 15
smtpd_banner = $myhostname ESMTP
smtpd_client_restrictions = check_client_access
hash:/usr/local/etc/postfix-mailgw/client_access reject
smtpd_recipient_restrictions = reject_unauth_destination
transport_maps = hash:/usr/local/etc/postfix-mailgw/transport
unknown_local_recipient_reject_code = 450
virtual_alias_domains = hugo.domain.tld ext.domain.tld domain.tld
virtual_alias_maps = hash:/usr/local/etc/postfix-mailgw/virtual_alias
=========================================================================================================
# grep -v ^# master.cf
192.168.0.22:smtp inet n - n - 50 smtpd
-o smtpd_client_connection_count_limit=10
pickup fifo n - n 60 1 pickup
cleanup unix n - n - 0 cleanup
qmgr fifo 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
smtp unix - - n - - smtp
-o inet_interfaces=192.168.0.22
relay unix - - n - - smtp
-o smtp_fallback_relay=
-o inet_interfaces=192.168.0.22
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
=========================================================================================================
tcpdump output:
15:51:22.009561 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: S
4094203971:4094203971(0) win 65535 <mss 1460,nop,wscale 3,sackOK,timestamp
1770875151 0>
E..<.,@....@....t...t.l.......c.........f.............
i.i.....
15:51:22.009976 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: S
2526362832:2526362832(0) ack 4094203972 win 5792 <mss 1460,sackOK,timestamp
1417053630 1770875151,nop,wscale 7>
E..<....@.?....t.l.t........<....D...............
Tv..i.i.....
15:51:22.010021 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: . ack 1 win
8326 <nop,nop,timestamp 1770875152 1417053630>
e.....@.@....T...T.L.......D..<... .)......
i.i.Tv..
15:51:22.010668 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: P 1:35(34)
ack 1 win 46 <nop,nop,timestamp 1417053630 1770875152>
e.....@.?.%'.T.L.T........<....D...........
Tv..i.i.220 co7.domain.tld SMTP ready
15:51:22.010746 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: P 1:28(27)
ack 35 win 8326 <nop,nop,timestamp 1770875153 1417053630>
e.....@.@..n.T...T.L.......D..<... ..+.....
i.i.Tv..EHLO mailgw.domain.tld
15:51:22.011242 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: . ack 28 win
46 <nop,nop,timestamp 1417053630 1770875153>
e.....@.?.%h.t.l.t........<...._....I......
Tv..i.i.
15:51:22.011256 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: P
35:135(100) ack 28 win 46 <nop,nop,timestamp 1417053630 1770875153>
e.....@.?.$..t.l.t........<...._...........
Tv..i.i.250-co7.domain.tld
250-AUTH CRAM-MD5 DIGEST-MD5 GSSAPI LOGIN PLAIN
250-STARTTLS
250 8BITMIME
15:51:22.011337 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: P 28:75(47)
ack 135 win 8326 <nop,nop,timestamp 1770875153 1417053630>
E..c./@....@..y.t...t.l......._..=w.. ........
i.i.Tv..MAIL FROM:<sen...@mail.domain.tld> BODY=7BIT
15:51:22.011736 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: P 135:143(8)
ack 75 win 46 <nop,nop,timestamp 1417053630 1770875153>
E..<....@.?.%>.T.L.T........=W...............
Tv..i.i.250 OK
15:51:22.011803 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: P 75:114(39)
ack 143 win 8326 <nop,nop,timestamp 1770875154 1417053630>
e.....@.@..`.T...T.L..........=_.. .xd.....
i.i.Tv..RCPT TO:<xxxxx...@mail.domain.tld>
15:51:22.021497 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: P 143:151(8)
ack 114 win 46 <nop,nop,timestamp 1417053633 1770875154>
E..<....@.?.%=.t.l.t........=_.........u.....
Tv..i.i.250 OK
15:51:22.021574 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: P 114:120(6)
ack 151 win 8326 <nop,nop,timestamp 1770875163 1417053633>
E..:....@.@....T...T.L..........=g.. ..,.....
i.i.Tv..DATA
15:51:22.022099 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: P
151:197(46) ack 120 win 46 <nop,nop,timestamp 1417053633 1770875163>
e.....@.?.%..t.l.t........=g...............
Tv..i.i.354 Start mail input; end with <CRLF>.<CRLF>
15:51:22.022211 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: .
120:1568(1448) ack 197 win 8326 <nop,nop,timestamp 1770875164 1417053633>
e.....@.@....T...T.L..........=... ........
i.i.Tv..Received: from smtp.domain.tld (smtp.domain.tld [192.168.0.21])
by mailgw.domain.tld (Postfix) with ESMTP id 008D71714FA
for <xxxx.xxxxx...@domain.tld>; Wed, 2 Jun 2010 15:51:21 +0200 (CEST)
Received: from freebsd.domain.tld (localhost [127.0.0.1])
by smtp.domain.tld (Postfix) with ESMTP id EBCAC14DBA4
for <xxxx.xxxxx...@domain.tld>; Wed, 2 Jun 2010 15:51:21 +0200 (CEST)
X-Virus-Scanned: amavisd-new at domain.tld
X-Amavis-Alert: BAD HEADER SECTION, Missing required header field: "Date"
Received: from amavis.at.domain.tld ([127.0.0.1])
by freebsd.domain.tld (smtp.domain.tld [127.0.0.1]) (amavisd-new, port
10024)
with ESMTP id z-dmaOQPHF0a for <xxxx.xxxxx...@domain.tld>;
Wed, 2 Jun 2010 15:51:19 +0200 (CEST)
Received: from co4 (co4.domain.tld [192.168.0.67])
by smtp.domain.tld (Postfix) with ESMTP
for <xxxx.xxxxx...@domain.tld>; Wed, 2 Jun 2010 15:51:19 +0200 (CEST)
From: sen...@mail.domain.tld
To: RAMILLON <xxxx.xxxxx...@domain.tld>
Message-ID: <33219176.10166.1275486674403.javamail.r...@co4>
References: <4c0619ba.7010...@domain.tld>
Subject: Displayed: CP LYON 2
MIME-Version: 1.0
Content-Type: multipart/report; report-type=disposition-notification;
boundary="----=_Part_10165_30308174.1275486674402"
Date: Wed, 2 Jun 2010 15:51:21 +0200 (CEST)
------=_Part_10165_30308174.1275486674402
Content-Type: text/plain; charset=UTF-8
Content-Transfer
15:51:22.022224 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: .
1568:3016(1448) ack 197 win 8326 <nop,nop,timestamp 1770875164 1417053633>
e.....@.@....T...T.L.......c..=... ........
i.i.Tv..-Encoding: quoted-printable
This is a receipt acknowledgement for the message 'CP LYON 2'
that you sent to sen...@mail.domain.tld.
../..
--------------------------------------------------------------
------=_Part_10165_30308174.1275486674402
Content-Type: message/disposition-notification; name="MDNPart2.txt"
Content-Transfer-Encoding: 7bit
Content-Disposition: inline
Reporting-UA: ContactOffice WebMail
Final-Recipient: rfc822; sen...@mail.domain.tld
Original-Message-I
15:51:22.022235 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: P
3016:4216(1200) ack 197 win 8326 <nop,nop,timestamp 1770875164 1417053633>
e.....@.@....T...T.L..........=... ........
i.i.Tv..D: <4c0619ba.7010...@domain.tld>
------=_Part_10165_30308174.1275486674402
Content-Type: text/rfc822-headers; name=MDNPart3.txt; charset=us-ascii
Content-Transfer-Encoding: 7bit
Content-Disposition: inline
../..
Content-Type: multipart/mixed;
boundary="------------00050408000903010207
15:51:22.022751 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: . ack 3016
win 91 <nop,nop,timestamp 1417053633 1770875164>
e.....@.?.%c.t.l.t........=........[=m.....
Tv..i.i.
15:51:22.022766 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: . ack 5664
win 136 <nop,nop,timestamp 1417053633 1770875164>
e.....@.?.%b.t.l.t........=....c....2......
Tv..i.i.
15:51:22.022786 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: P
5664:5721(57) ack 197 win 8326 <nop,nop,timestamp 1770875165 1417053633>
e.....@.@..H.T...T.L.......c..=... .w......
i.i.Tv..0200"
------=_Part_10165_30308174.1275486674402--
.
15:51:22.062987 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: . ack 5721
win 136 <nop,nop,timestamp 1417053643 1770875165>
e.....@.?.%a.t.l.t........=.........2......
Tv..i.i.
15:51:22.275092 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: P 197:205(8)
ack 5721 win 136 <nop,nop,timestamp 1417053696 1770875165>
E..<....@.?.%8.t.l.t........=.........s......
Tv..i.i.250 OK
15:51:22.374644 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: . ack 205
win 8326 <nop,nop,timestamp 1770875517 1417053696>
e.....@.@..k.T...T.L..........=... .. .....
i.j}Tv..
15:51:24.276369 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: F
5721:5721(0) ack 205 win 8326 <nop,nop,timestamp 1770877419 1417053696>
e.....@.@....T...T.L..........=... . ......
i.q.Tv..
15:51:24.276858 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: P
205:265(60) ack 5722 win 136 <nop,nop,timestamp 1417054196 1770877419>
e.....@.?.%..t.l.t........=.........=......
Tv..i.q.221 co7.domain.tld service closing transmission channel
15:51:24.276910 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: R
4094209693:4094209693(0) win 0
E..(....@.@....T...T.L............P....e..
15:51:24.276916 IP mail.domain.tld.smtp > mailgw.domain.tld.49839: F 265:265(0)
ack 5722 win 136 <nop,nop,timestamp 1417054196 1770877419>
e.....@.?.%>.T.L.T........=.........'g.....
Tv..i.q.
15:51:24.276930 IP mailgw.domain.tld.49839 > mail.domain.tld.smtp: R
4094209693:4094209693(0) win 0
E..(....@.@....T...T.L............P....e..
=========================================================================================================
corresponding smtp logs on LB's side:
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 > 220 co7.domain.tld
SMTP ready
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 < EHLO
mailgw.domain.tld
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 > 250-co7.domain.tld
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 < MAIL
FROM:<sen...@mail.domain.tld> BODY=7BIT
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 > 250 OK
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 < RCPT
TO:<xxxxx...@mail.domain.tld>
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 > 250 OK
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 < DATA
2010-06-02 15:51:21,CO7,[INFO],(482183),192.168.0.22:12348 > 354 Start mail
input; end with <CRLF>.<CRLF>
2010-06-02 15:51:22,CO7,[INFO],(482183),192.168.0.22:12348 > 250 OK
2010-06-02 15:51:24,CO7,[INFO],(482183),192.168.0.22:12348 < (No answer,timeout)
2010-06-02 15:51:24,CO7,[INFO],(482183),192.168.0.22:12348 > 221 co7.domain.tld
service closing transmission channel
=========================================================================================================
corresponding smtp logs on MAILGW's side:
Jun 2 15:51:22 ru postfix-mailgw/smtpd[80159]: 008D71714FA:
client=smtp.domain.tld[192.168.0.21]
Jun 2 15:51:22 ru postfix-mailgw/cleanup[79669]: 008D71714FA:
message-id=<33219176.10166.1275486674403.javamail.r...@co4>
Jun 2 15:51:22 ru postfix-mailgw/qmgr[71565]: 008D71714FA:
from=<l...@mail.domain.tld>, size=5598, nrcpt=1 (queue active)
Jun 2 15:51:22 ru postfix-mailgw/smtp[79016]: 008D71714FA:
to=<xxxxx...@mail.domain.tld>, orig_to=<xxxx.xxxxx...@domain.tld>,
relay=192.168.0.76[192.168.0.76]:25, delay=0.3, delays=0.03/0/0/0.26,
dsn=2.0.0, status=sent (250 OK)
Jun 2 15:51:22 ru postfix-mailgw/qmgr[71565]: 008D71714FA: removed
Patrick PRONIEWSKI
--
Administrateur Système - SENTIER - Université Lumière Lyon 2
smime.p7s
Description: S/MIME cryptographic signature
