Re: [exim] Queue time logging incorrect in 4.94?

On 27/10/2020 13:59, Matt Rubright via Exim-users wrote:
> While troubleshooting some user complaints about email queue times, I
> discovered some cases where emails are logged as having longer queue times
> than they actually do.

> The QT log entry shows the total queue time to be 1m24s, but the timestamps
> show 5 seconds start to finish. Am I misreading this somehow? The message
> ID doesn't show up anywhere else in the log,
>
> My log_selector configuration looks like this:
>
> +queue_time_overall +smtp_incomplete_transaction

With queue_time_overall set, the QT value includes reception time - from
the start of the smtp transaction. The acceptance ( <= ) log line is
not made until reception is complete, So, if *transmission* of the
message took up the missing 1m 19s that would account for what we
see for that case.

If you are getting these frequently enough for a fair chance of
spotting another, I suggest you add smtp_connection to the logging.
It won't be perfect - there could still be a long delay between
accepting the connection and the start of a message transaction -
but it may be indicative.

More deeply, if you can characterize these messages, or connections,
enough to recognise them in ACL: turn on debug just for them.
You might want to add millisecond logging; it also affects debug.
--
Cheers,
Jeremy