On Thu, Nov 01, 2012 at 12:38:26AM +0800, Fred Ho wrote: > OK, smtpd[9647]: disconnect happened at 13:04:23. There's no > smtpd[9647] entries after 10:15:16. > > Oct 31 10:15:16 mailgate2 postfix/smtpd[9647]: > connect from ttsenmta2.ttasia.com[210.17.183.8] > Oct 31 10:15:17 mailgate2 postfix/smtpd[9647]: 4803D7F20: > client=ttsenmta2.ttasia.com[210.17.183.8] > Oct 31 10:15:17 mailgate2 postfix/cleanup[9648]: 4803D7F20: > message-id=<002601cdb70d$8e5363e0$aafa2ba0$@com.tw> > Oct 31 13:04:23 mailgate2 postfix/smtpd[9647]: > disconnect from ttsenmta2.ttasia.com[210.17.183.8] > Oct 31 13:04:23 mailgate2 postfix/qmgr[4869]: 4803D7F20: > from=<v...@otogarment.com>, size=595890, nrcpt=3 (queue active) > [...]
As suspected the disconnect coincides with the start of delivery processing. There are two possibilities: 1. The smtpd(8) server did not see the ".<CRLF>" from the client until the client disconnected. This could be a bug in the client PIPELINING implementation, or some firewall between the client and SMTP server. 2. The ".<CRLF>" was received in a timely manner, but smtpd(8) and/or cleanup(8) took a long time to commit the message to the incoming queue, by which time the client had long disconnected, but this fact was only discovered once the message processing was completed. One possibility for case 2 is very slow processing of virtual alias expansion or very slow transport resolution, ... which block the cleanup(8) service. Does the problem happen intermittently with all senders, or just with some senders and not others? You can add one of the more frequent problem senders to "debug_peer_list" and we'll see when the SMTP server receives ".<CRLF>". Otherwise you need to capture a tcpdump "pcap" file of the problem transactions and look at packet timestamps. > Here's the postconf -n output: > default_destination_concurrency_limit = 100 This is a bad idea. > default_destination_recipient_limit = 300 This violates RFC limits and is also a bad idea. > message_size_limit = 838860800 I'd recommend something <= 100 MB, the default is 10 MB. > relay_domains = $mydestination Make "relay_domains" empty instead. If you want to relay specific sub-domains of domains listed in mydestination, list them explicitly, and set "parent_domain_matches_subdomains" to just list "smtpd_access_maps", and omit "relay_domains". With local delivery disabled, you should probably also have mydestination empty! > smtp_connect_timeout = 300s This is too long the default is probably better. > smtp_data_init_timeout = 300s > smtp_data_xfer_timeout = 240s You probably don't need to tune these. > smtpd_policy_service_timeout = 300s > smtpd_proxy_timeout = 300s Are you using a proxy filter? Your logs don't show this. Could it be responsible for the delay? > smtpd_timeout = 600s You probably don't need to change this, and Postfix by default makes this stress-dependent, which is a good idea. There's no evidence of any slow lookup mechanisms used for address rewriting or transport lookups, so firewall issues or pipelining bugs in clients are the most likely. -- Viktor.