43

We have a Postfix hub and I'm trying to better understand the information in the mail.log file. I use tools like qshape, pflogsumm.pl and amavis-logwatch to summarize the log files, but I have still have questions about some of the elements of the raw log file.

My first question is in regard to the delay entry that appears from Postfix when an email is finally delivered. I am guessing that these values are in seconds, but what does this information exactly mean.

delay=2.4, delays=0.18/0.01/1.4/0.81

Did the email take a total of 2.4 seconds to process?

What is the breakdown of timings in the delays section?

Flimzy
  • 2,375
  • 17
  • 26
KodeTitan
  • 871
  • 2
  • 9
  • 15

2 Answers2

43

Postfix feature # 20051103 added the following (from the 2.3.13 release notes):

Better insight into the nature of performance bottle necks, with detailed logging of delays in various stages of message delivery. Postfix logs additional delay information as "delays=a/b/c/d" where a=time before queue manager, including message transmission; b=time in queue manager; c=connection setup time including DNS, HELO and TLS; d=message transmission time.

As I would suspect, the longest delay in your setup is being caused by connection setup, DNS, and the initial SMTP conversation. Seems normal to me.

Evan Anderson
  • 141,071
  • 19
  • 191
  • 328
19

This is mentioned in the FAQ for postfix-logwatch.

In the source code:

# Message delivery time stamps
# delays=a/b/c/d, where
#   a = time before queue manager, including message transmission
#   b = time in queue manager
#   c = connection setup including DNS, HELO and TLS;
#   d = message transmission time.

postfix-logwatch will also give you a delays percentiles report, which gives an overview of how all mail is flowing during the report period.

=== Delivery Delays Percentiles ============================================================
                    0%       25%       50%       75%       90%       95%       98%      100%
--------------------------------------------------------------------------------------------
Before qmgr       0.00      0.03      0.04      0.04     11.60    111.90    176.88    634.00
In qmgr           0.00      0.00      0.02      0.03      0.03      0.03      0.04      0.04
Conn setup        0.00      0.00      0.00      0.00      0.00      0.00      0.01      0.01
Transmission      0.00      0.00      0.01      0.03      0.80      5.40      5.51     14.00
Total             0.01      0.05      0.08      0.14     15.00    116.90    182.80    640.00
============================================================================================
Flimzy
  • 2,375
  • 17
  • 26