question about delay=

Hi,

I was trying to get some statistics from de delay= part of the sendmail
logging. According to some websites delay= shows the total amount of
time the message took to be delivered.

But now I have seen some strange valuse in delay= that dont seem to
correspondend to this information:

Nov 14 11:18:18 netlx010 sendmail-in[28334]: jAE9KLH28334:
from=, size=339773, class=0, nrcpts=1,
msgid=<25352765.1131960024125.JavaMail.tomcat@database>, proto=ESMTP,
daemon=MTA, relay=a80-127-215-107.adsl.xs4all.nl [80.127.215.107]

Nov 14 11:18:18 netlx010 sendmail-in[28334]: jAE9KLH28334:
to=, delay=00:57:57, mailer=esmtp, pri=369773,
stat=queued

Nov 14 11:19:13 netlx010 sendmail[27133]: jAE9KLH28334:
to=, delay=00:58:52, xdelay=00:00:00, mailer=esmtp,
pri=459773, relay=netlx089.utsp.utwente.nl. [130.89.1.10], dsn=2.0.0,
stat=Sent (jAEAJCUc010032 Message accepted for delivery)

As far as I understand delay= should show 00:00:55. Or does delay= show
the total amount of time since the mail from: or rcpt to: in the
delivery process?

--
Peter Peters, senior netwerkbeheerder
Dienst Informatietechnologie, Bibliotheek en Educatie (ITBE)
Universiteit Twente, Postbus 217, 7500 AE Enschede
telefoon: 053 - 489 2301, fax: 053 - 489 2383, http://www.utwente.nl/itbe

Re: question about delay=

Peter Peters wrote:

> Hi,
>
> I was trying to get some statistics from de delay= part of the sendmail
> logging. According to some websites delay= shows the total amount of
> time the message took to be delivered.
>
> But now I have seen some strange valuse in delay= that dont seem to
> correspondend to this information:
>
> Nov 14 11:18:18 netlx010 sendmail-in[28334]: jAE9KLH28334:
> from=, size=339773, class=0, nrcpts=1,
> msgid=<25352765.1131960024125.JavaMail.tomcat@database>, proto=ESMTP,
> daemon=MTA, relay=a80-127-215-107.adsl.xs4all.nl [80.127.215.107]
>
> Nov 14 11:18:18 netlx010 sendmail-in[28334]: jAE9KLH28334:
> to=, delay=00:57:57, mailer=esmtp, pri=369773,
> stat=queued
>
> Nov 14 11:19:13 netlx010 sendmail[27133]: jAE9KLH28334:
> to=, delay=00:58:52, xdelay=00:00:00, mailer=esmtp,
> pri=459773, relay=netlx089.utsp.utwente.nl. [130.89.1.10], dsn=2.0.0,
> stat=Sent (jAEAJCUc010032 Message accepted for delivery)
>
> As far as I understand delay= should show 00:00:55. Or does delay= show
> the total amount of time since the mail from: or rcpt to: in the
> delivery process?
>

While the delay should not be that large, there are occations when a
delay of ~58 minutes can be explained. 1) your system had an excessive
amount of emails to deliver.
2) The remote server was inaccessible or non reponsive. Looking further
through the logs for this particular message may reveal the cause for
the delay. This relies on dsn=4.x.x messages (temporary failure notices).

AK

Re: question about delay=

On Mon, 14 Nov 2005 21:12:03 -0500, AK wrote:

>> Nov 14 11:18:18 netlx010 sendmail-in[28334]: jAE9KLH28334:
>> from=, size=339773, class=0, nrcpts=1,
>> msgid=<25352765.1131960024125.JavaMail.tomcat@database>, proto=ESMTP,
>> daemon=MTA, relay=a80-127-215-107.adsl.xs4all.nl [80.127.215.107]
>>
>> Nov 14 11:18:18 netlx010 sendmail-in[28334]: jAE9KLH28334:
>> to=, delay=00:57:57, mailer=esmtp, pri=369773,
>> stat=queued
>>
>> Nov 14 11:19:13 netlx010 sendmail[27133]: jAE9KLH28334:
>> to=, delay=00:58:52, xdelay=00:00:00, mailer=esmtp,
>> pri=459773, relay=netlx089.utsp.utwente.nl. [130.89.1.10], dsn=2.0.0,
>> stat=Sent (jAEAJCUc010032 Message accepted for delivery)
>>
>> As far as I understand delay= should show 00:00:55. Or does delay= show
>> the total amount of time since the mail from: or rcpt to: in the
>> delivery process?
>
>While the delay should not be that large, there are occations when a
>delay of ~58 minutes can be explained. 1) your system had an excessive
>amount of emails to deliver.
>2) The remote server was inaccessible or non reponsive. Looking further
>through the logs for this particular message may reveal the cause for
>the delay. This relies on dsn=4.x.x messages (temporary failure notices).

These are the only loglines for this message. When I see something
strange I grep for the "strange" part followed by a grep for the queue
ID. And as far as I know the to= line is always the first line in a
normal situation. And the line with stat=Sent is the last.

The only possible situation I can think of is when the timer starts at
the MAIL FROM: in the SMTP session. And with a big message and a slow
connection the delay could be this large.

--
Peter Peters, senior netwerkbeheerder
Dienst Informatietechnologie, Bibliotheek en Educatie (ITBE)
Universiteit Twente, Postbus 217, 7500 AE Enschede
telefoon: 053 - 489 2301, fax: 053 - 489 2383, http://www.utwente.nl/itbe