On Thu, Sep 12, 2013 at 09:12:59AM -0400, Roman Gelfand wrote:
> We have a program which every so often sends a request, using chilkat,
> to postfix to send out email with attachment. With every send it has
> to connect to postfix using sasl authentication. Each send appears to
> take a long time. In the absence of more detailed information, I am
> guessing the connection is taking most of the time.
Don't guess measure. The mail logs record four delay measurements for
each message:
postfix/smtp[<pid>]: <queue_id>: to=<rcpt>, ... delays=a/b/c/d, ...
The components of the "delays" field are:
a. Time elapsed between message creation and the message entering
the active queue. With SMTP the clock starts at the first
accepted "RCPT TO:" command. This does not include the time
from the client's TCP SYN to initiate the connection until
the server responds with "250" to "MAIL FROM:".
The start time is that of the log entry of the form:
postfix/smtpd[<pid>]: <queue-id>: client=...
If your client's IP address triggers slow (failing) PTR
lookups, or slow forward lookups of the resulting name
that time is not seen in the Postfix logs as the
first log message
postfix/smtpd[<pid>]: connect from ...
is logged after attempting to reverse resolve the client's
IP address.
b. Time spent in the active queue, large delays here show a congested
destination or an overall congested queue.
c. Time taken to connect to the remote destination, from the delivery
agent receiving the request to deliver the message to the beginning
of the mail transaction (with SMTP, sending MAIL FROM:)
d. Time taken to complete the mail transaction.
Report all logging for your "slow" deliveries, from the "connect from ..."
message with the same process id as the "smtpd: <queue_id>: client=" message
including all messages with that queue-id, until the "disconnect from".
You may find the Perl script in:
http://www.mail-archive.com/postfix-devel@postfix.org/msg00292.html
useful.
--
Viktor.
