Postfix delays explained

This is documented in plenty of other places, but for my own sake, here's the meaning of the delay= and delays= lines in Postfix's maillog.

Note that this example is from debugging badly-delayed mail (almost 2 hours!), so do not take these values as good or typical values. But, here is one such delayed message:

Jun 23 19:33:22 outmx postfix/smtp[7484]: 42A3B481ABC: to=<REDACTED>,
relay=relay1[REDACTED]:25, conn_use=7, delay=6351,
delays=0.22/6286/0.14/65, dsn=2.0.0, status=sent (250 2.0.0
 05NNRvav016970 Message accepted for delivery)

What do those delays mean?

• conn_use=7 is (AFAICT) an indicator of how many times this open SMTP connection has been used by the connection cache. This is not really related to delay but I'm including it because I was curious.
• delay=6351 refers to the total "end-to-end delay" (in seconds). It seemingly should sum to the four delay values below. (Again, this is a ludicrously high value.)
• delays=0.22/6286/0.14/65 is explained in a few different ways. Per log_adhoc.c, the format is delays=pdelay/adelay/sdelay/xdelay.

Those break down as follows below (carrying over the example values from above). All values are in seconds:

• pdelay (0.22): time before queue manager (including message transmission)
• adelay (6286): queue manager latency (time in queue)
• sdelay (0.14): connection set-up latency (including DNS, HELO and TLS)
• xdelay (65): transmission latency ("time in message transmission")

So we can see that it took us about a quarter-second (0.22 sec.) to accept this message. It then sat in the quueue for 6,286 seconds (or almost 105 minutes) before delivery. Upon delivery, it took 140ms (0.14 seconds) to set up the connection, and 65 seconds to actually send the message.

The background for this particular issue is that this is a mail relay which relays all mail to a remote SMTP server. This relay periodically receives a flood of mail, and because it's all going to one upstream server rather than diverse remote SMTP servers per-domain, the default smtp_destination_concurrency_limit limit of 20 becomes problematic.