Viktor Dukhovni:
> On Wed, Jun 08, 2022 at 04:55:50PM -0400, Viktor Dukhovni wrote:
>
> > In particular, was the delay during network transmission, or in
> > content processing after "."? Perhaps you can log a "WARN" or "INFO"
> > action in "end_of_data" restrictiosn, and see when that happens
> > (before milters run, don't recall whether inflow_delay happens
> > first...).
>
> I checked, and in_flow_delay happens before cleanup(8) begins handling a
> new message, so isn't the problem here, since the message envelope and
> headers (at least Message-Id) are handled promptly, so the latency is
> either in the network transmission of the mesage body, the end_of_data
> checks or the milter.
There may be a delay as the cleanup daemon tries to nofity
the queue manager of new email (default: trigger_timeout = 10s).
Again that should should not take 255 seconds.
> You'll have to figure out which. You might make progress by segregating
> the problem messages to arrive on a dedicated port, with a dedicated
> smtpd+cleanup configuration, and enabling verbosity ("-v" in master.cf)
> in cleanup, though a simpler first step would be a "WARN" or "INFO"
> action in an end_of_data restriction, and noting the time delay from
> message start for that to happen. Milter processing of the message
> body will (I believe) happen after end_of_data restrictions.
It would be interesting to see how much time elapses between Postfix
receiving the "." (logged from smtpd_end_of_data_restrictions) and
the actions that follow.
Below is the order of how Postfix receives email. Steps with "*"
are logged with -v or with -v -v, other steps are logged only when
they fail.
* repeat: receive header and send header to milter
* send 'end of headers' to milter
receive body
at this point you could use smtpd_end_of_data_restrictions to
log an info ow warn event
* send end-of-body to milter and allow envelope/header/body changes
flush queue file handle
fsync queue file handle
close queue file handle
optionally change the queue file timestamp if the Postfix
host clock differs from the file server's clock.
* send a 'trigger' to the queue manager
* send queue file status from cleanup daemon to smtpd daemon
* in the smtpd daemon, reply to "."
If there is a delay between any of these steps then we know more.
Wietse
