On Wed, Oct 31, 2012 at 11:32:20PM +0800, Fred Ho wrote:
> 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/qmgr[4869]: 4803D7F20:
> from=<v...@otogarment.com>, size=595890, nrcpt=3 (queue active)
> Oct 31 13:04:23 mailgate2 postfix/smtp[10206]: 4803D7F20:
> to=<i...@ss-intl.com>, relay=192.168.1.21[192.168.1.21]:25,
> delay=10147, delays=10146/0/0/0.3, dsn=2.0.0, status=sent
> (250 Mail queued for delivery)
> Oct 31 13:04:23 mailgate2 postfix/smtp[10206]: 4803D7F20:
> to=<rick...@ss-intl.com>, relay=192.168.1.21[192.168.1.21]:25,
> delay=10147, delays=10146/0/0/0.3, dsn=2.0.0, status=sent
> (250 Mail queued for delivery)
> Oct 31 13:04:23 mailgate2 postfix/smtp[10206]: 4803D7F20:
> to=<sherry...@ss-intl.com>, relay=192.168.1.21[192.168.1.21]:25,
> delay=10147, delays=10146/0/0/0.3, dsn=2.0.0, status=sent
> (250 Mail queued for delivery)
> Oct 31 13:04:23 mailgate2 postfix/qmgr[4869]: 4803D7F20: removed
Can you also post the corresponding
Oct 31 XX:XX:XX mailgate2 postfix/smtpd[9647]:
disconnect from ttsenmta2.ttasia.com[210.17.183.8]
log entry (match on the process id 9647 and client IP)? It is
possible that the SMTP server did not receive the "DOT<CRLF>" until
shortly before 13:04:23 when the client disconnected.
As Ralf points out, part of the issue could be a firewall that
fails to propagate pipelined "DOT<CRLF>QUIT<CRLF>" until
the client disconnects.
Another possibility is that the cleanup service was blocked syncing
the message to disk or waiting for an inflow delay token. Make sure
your inflow_delay is not misconfigured, and that your system does
not lose clock or file readable events, ...
> Oct 31 10:30:23 mailgate2 postfix/smtpd[9688]:
> connect from ttsenmta2.ttasia.com[210.17.183.8]
> Oct 31 10:30:23 mailgate2 postfix/smtpd[9688]: F097C7F1F:
> client=ttsenmta2.ttasia.com[210.17.183.8]
> Oct 31 10:30:24 mailgate2 postfix/cleanup[9689]: F097C7F1F:
> message-id=<002601cdb70d$8e5363e0$aafa2ba0$@com.tw>
> Oct 31 10:30:26 mailgate2 postfix/qmgr[4869]: F097C7F1F:
> from=<v...@otogarment.com>, size=595890, nrcpt=3 (queue active)
> Oct 31 10:30:26 mailgate2 postfix/smtpd[9688]:
> disconnect from ttsenmta2.ttasia.com[210.17.183.8]
> Oct 31 10:30:26 mailgate2 postfix/smtp[9685]: F097C7F1F:
> to=<i...@ss-intl.com>, relay=192.168.1.21[192.168.1.21]:25,
> delay=2.6, delays=2.3/0/0/0.3, dsn=2.0.0, status=sent
> (250 Mail queued for delivery)
> [...]
> Oct 31 10:30:26 mailgate2 postfix/qmgr[4869]: F097C7F1F: removed
>
> Can someone explain why there's a delay in delivery at 10:15:17
> until 13:04?
> The ISP said they didn't receive the 250 OK after end of DATA
> and hence retry later at 10:30 which was delivered immediately.
--
Viktor.
