Difference between revisions of "Mail log file analysis"

From SME Server
Jump to navigationJump to search
Line 45: Line 45:
 
'''Important:''' Since incoming messages will not reach qmail if they have been denied by any of the ''qpsmtpd'' spam-fighting features, you cannot get any spam blocking information from the qmail logs.
 
'''Important:''' Since incoming messages will not reach qmail if they have been denied by any of the ''qpsmtpd'' spam-fighting features, you cannot get any spam blocking information from the qmail logs.
  
 +
=== Mail log file analysis ===
 
''Mail log file analysis'' in the server-manager provides access to several reports regarding ''qmail''.   
 
''Mail log file analysis'' in the server-manager provides access to several reports regarding ''qmail''.   
  
 
All of the reports below except for ''Summarize status of mail queue'' examine all of the current qmail log files (''/var/log/qmail/@*'' and ''/var/log/qmail/current'').
 
All of the reports below except for ''Summarize status of mail queue'' examine all of the current qmail log files (''/var/log/qmail/@*'' and ''/var/log/qmail/current'').
  
=== Basic Statistics ===
+
==== Basic Statistics ====
 
  <nowiki>qtime is the time spent by a message in the queue.
 
  <nowiki>qtime is the time spent by a message in the queue.
  
Line 79: Line 80:
 
Average concurrency: 0.000607221</nowiki>
 
Average concurrency: 0.000607221</nowiki>
  
=== List outgoing messages and recipients ===
+
==== List outgoing messages and recipients ====
  
=== Reasons for deferral ===
+
==== Reasons for deferral ====
 
  <nowiki>Reasons for deferral
 
  <nowiki>Reasons for deferral
  
Line 88: Line 89:
 
* xdelay is the total xdelay on those deliveries.</nowiki>
 
* xdelay is the total xdelay on those deliveries.</nowiki>
  
=== Reasons for failure ===
+
==== Reasons for failure ====
 
  <nowiki>Reasons for failure
 
  <nowiki>Reasons for failure
  
Line 98: Line 99:
 
</nowiki>
 
</nowiki>
  
=== Reasons for success ===
+
==== Reasons for success ====
 
  <nowiki>Reasons for success
 
  <nowiki>Reasons for success
  
Line 107: Line 108:
 
   del    xdelay  reason</nowiki>
 
   del    xdelay  reason</nowiki>
  
=== Recipient hosts ===
+
==== Recipient hosts ====
 
  <nowiki>Recipient hosts
 
  <nowiki>Recipient hosts
  
Line 118: Line 119:
 
   sbytes  mess  tries  xdelay  host</nowiki>
 
   sbytes  mess  tries  xdelay  host</nowiki>
  
=== Recipients in best order for mailing lists ===
+
==== Recipients in best order for mailing lists ====
 
  <nowiki>Recipients in the best order for mailing lists
 
  <nowiki>Recipients in the best order for mailing lists
  
Line 127: Line 128:
 
   avg  tries  recipient</nowiki>
 
   avg  tries  recipient</nowiki>
  
=== Recipients statistics ===
+
==== Recipients statistics ====
 
<nowiki>Recipients
 
<nowiki>Recipients
  
Line 138: Line 139:
 
   sbytes  mess  tries  xdelay  recipient</nowiki>
 
   sbytes  mess  tries  xdelay  recipient</nowiki>
  
=== Sender statistics ===
+
==== Sender statistics ====
 
  <nowiki>Senders
 
  <nowiki>Senders
  
Line 152: Line 153:
 
  mess    bytes    sbytes    rbytes  recips  tries        xdelay  sender</nowiki>
 
  mess    bytes    sbytes    rbytes  recips  tries        xdelay  sender</nowiki>
  
=== Sender uids ===
+
==== Sender uids ====
 
  <nowiki>Sender uids
 
  <nowiki>Sender uids
  
Line 166: Line 167:
 
  mess      bytes    sbytes    rbytes  recips  tries        xdelay  uid</nowiki>
 
  mess      bytes    sbytes    rbytes  recips  tries        xdelay  uid</nowiki>
  
=== Sendmail style log ===
+
==== Sendmail style log ====
 
Process and display the qmail log files in a format similar to sendmail's logs.
 
Process and display the qmail log files in a format similar to sendmail's logs.
  
 
Each transaction generates two lines, one with the ''from'' information and one with the ''to'' information.
 
Each transaction generates two lines, one with the ''from'' information and one with the ''to'' information.
  
=== Successful delivery delay distribution ===
+
==== Successful delivery delay distribution ====
 
  <nowiki>Distribution of ddelays for successful deliveries
 
  <nowiki>Distribution of ddelays for successful deliveries
  
Line 179: Line 180:
 
   doneby    avg  pct</nowiki>
 
   doneby    avg  pct</nowiki>
  
=== Summarize status of mail queue ===
+
==== Summarize status of mail queue ====
 
'''Exception!'''<br>
 
'''Exception!'''<br>
 
This report does not process the log files, but instead examines and reports on the actual contents of the qmail queues.
 
This report does not process the log files, but instead examines and reports on the actual contents of the qmail queues.

Revision as of 17:35, 8 November 2008

The SME server manager provides access to almost all of the log files maintained by the system (a very few files are excluded that contain no useful information)

This document describes the email-related log files and what they tell you.

qpsmtpd: Incoming SMTP traffic

All in-bound SMTP connections are handled by qpsmtpd.


View log files

You can examine the qpsmtpd log files using View log files in the server-manager.

Raw qpsmtpd logs

Raw qpsmtpd logs are quite verbose, including a separate line of output for each process that is involved in receiving and analyzing the incoming message. The basic format of each log line is

timestamp processid log_information

At the default logging level (LogLevel 6) for qpsmtpd, there can easily be up to 28 lines of logged information for a single email message.

On a busy server handling up to 40 simultaneous in-bound email connections, this can result in highly interleaved and hard-to-read log files.

view only logterse entries

SME 7.2 and later include the 'logterse' plugin to qpsmtpd. logterse creates a one-line summary of each qpsmtpd transaction and writes it to the log file.

In order to view only these one-line-per-message summaries from the qpsmtpd log:

  • Select View log files in server-manager
  • Specify qpsmtpd/current (or another qpsmtpd log file) under Choose a log file to view
  • Specify ` (a single back-tick) under Filter Pattern (optional)
  • Click Next
  • Sample results are shown below
    • hopefully you will actually have some real email arriving at your server (not all dnsbl entries as shown here)
    • results are <tab> delimited, so you can easily Copy and Paste Special / Text into Excel for further analysis
2008-11-08 06:32:46.354761500 26318 logging::logterse plugin: ` 89.223.216.72	apn-89-223-216-72.vodafone.hu	apn-89-223-216-72.vodafone.hu	<toshiter@donin.com>		rhsbl	901	Not supporting null originator (DSN)	msg denied before queued
2008-11-08 06:33:17.924158500 26331 logging::logterse plugin: ` 208.99.214.236	mx22.ecreditchoices7.com	mx22.ecreditchoices7.com	<moneydiet2@mx22.ecreditchoices7.com>		dnsbl	903	http://www.spamhaus.org/SBL/sbl.lasso?query=SBL69049	msg denied before queued
2008-11-08 06:34:53.318459500 26358 logging::logterse plugin: ` 84.58.57.150	dslb-084-058-057-150.pools.arcor-ip.net	rpemgmu.arcor-ip.net	<sundered@ancientinc.com>		dnsbl	903	http://www.spamhaus.org/query/bl?ip=84.58.57.150	msg denied before queued
2008-11-08 06:35:41.724563500 26375 logging::logterse plugin: ` 58.126.113.198	Unknown	[58.126.113.198]	<benny@surecom.com>		rhsbl	901	Not supporting null originator (DSN)	msg denied before queued
2008-11-08 06:37:31.730609500 26398 logging::logterse plugin: ` 87.103.146.91	pmsn.91.146.103.87.sable.dsl.krasnet.ru	pmsn.91.146.103.87.sable.dsl.krasnet.ru	<dwweem@wee.com>		dnsbl	903	http://www.spamhaus.org/query/bl?ip=87.103.146.91	msg denied before queued
2008-11-08 06:37:41.211401500 26409 logging::logterse plugin: ` 87.103.146.91	pmsn.91.146.103.87.sable.dsl.krasnet.ru	pmsn.91.146.103.87.sable.dsl.krasnet.ru	<dwtrupsm@trups.com>		dnsbl	903	http://www.spamhaus.org/query/bl?ip=87.103.146.91	msg denied before queued

qmail: Outgoing SMTP traffic

Once a message has been accepted by qpsmtpd it is handed to qmail for delivery.

  • If the message is addressed to an email account hosted on your SME server, qmail delivers the file to the local mailbox.
  • If the message is addressed to an email on a domain hosted on your SME that is configured to use an Internal MailServer, qmail delivers the message to the designated server.
  • If the message is addressed to a remote email address, qmail either delivers the message directly to the recipient's mail server, or to the relay mail server value configured at server-manager::email::Address of internet provider's mail

Important: Since incoming messages will not reach qmail if they have been denied by any of the qpsmtpd spam-fighting features, you cannot get any spam blocking information from the qmail logs.

Mail log file analysis

Mail log file analysis in the server-manager provides access to several reports regarding qmail.

All of the reports below except for Summarize status of mail queue examine all of the current qmail log files (/var/log/qmail/@* and /var/log/qmail/current).

Basic Statistics

qtime is the time spent by a message in the queue.

ddelay is the latency for a successful delivery to one recipient---the
end of successful delivery, minus the time when the message was queued.

xdelay is the latency for a delivery attempt---the time when the attempt
finished, minus the time when it started. The average concurrency is the
total xdelay for all deliveries divided by the time span; this is a good
measure of how busy the mailer is.

Completed messages: 213
Recipients for completed messages: 213
Total delivery attempts for completed messages: 250
Average delivery attempts per completed message: 1.17371
Bytes in completed messages: 4282486
Bytes weighted by success: 4282486
Average message qtime (s): 145.726

Total delivery attempts: 250
  success: 213
  failure: 0
  deferral: 37
Total ddelay (s): 31039.462344
Average ddelay per success (s): 145.725175
Total xdelay (s): 36.762560
Average xdelay per delivery attempt (s): 0.147050
Time span (days): 0.700722
Average concurrency: 0.000607221

List outgoing messages and recipients

Reasons for deferral

Reasons for deferral

One line per reason for deferral. Information on each line:
* del is the number of deliveries that ended for this reason.
* xdelay is the total xdelay on those deliveries.

Reasons for failure

Reasons for failure

One line per reason for delivery failure. Information on each line:
* del is the number of deliveries that ended for this reason.
* xdelay is the total xdelay on those deliveries.

del  xdelay  reason

Reasons for success

Reasons for success

One line per reason for successful delivery. Information on each line:
* del is the number of deliveries that ended for this reason.
* xdelay is the total xdelay on those deliveries.

  del    xdelay  reason

Recipient hosts

Recipient hosts

One line per recipient host. Information on each line:
* sbytes is the number of bytes successfully delivered to this host.
* mess is the number of messages sent to this host (success plus failure).
* tries is the number of delivery attempts (success, failure, deferral).
* xdelay is the total xdelay incurred by this host.

   sbytes   mess  tries   xdelay  host

Recipients in best order for mailing lists

Recipients in the best order for mailing lists

One line per recipient, sorted by avg. Information on each line:
* avg is the _average_ xdelay for the recipient.
* tries is the number of deliveries that avg is based on.

  avg  tries  recipient

Recipients statistics

Recipients One line per recipient. Information on each line: * sbytes is the number of bytes successfully delivered to this recipient. * mess is the number of messages sent to this recipient (success plus failure). * tries is the number of delivery attempts (success, failure, deferral). * xdelay is the total xdelay incurred by this recipient. sbytes mess tries xdelay recipient

Sender statistics

Senders

One line per sender. Information on each line:
* mess is the number of messages sent by this sender.
* bytes is the number of bytes sent by this sender.
* sbytes is the number of bytes successfully received from this sender.
* rbytes is the number of bytes from this sender, weighted by recipient.
* recips is the number of recipients (success plus failure).
* tries is the number of delivery attempts (success, failure, deferral).
* xdelay is the total xdelay incurred by this sender.

 mess     bytes    sbytes    rbytes  recips  tries        xdelay  sender

Sender uids

Sender uids

One line per sender uid. Information on each line:
* mess is the number of messages sent by this uid.
* bytes is the number of bytes sent by this uid.
* sbytes is the number of bytes successfully received from this uid.
* rbytes is the number of bytes from this uid, weighted by recipient.
* recips is the number of recipients (success plus failure).
* tries is the number of delivery attempts (success, failure, deferral).
* xdelay is the total xdelay incurred by this uid.

 mess      bytes     sbytes     rbytes  recips  tries        xdelay  uid

Sendmail style log

Process and display the qmail log files in a format similar to sendmail's logs.

Each transaction generates two lines, one with the from information and one with the to information.

Successful delivery delay distribution

Distribution of ddelays for successful deliveries

Meaning of each line: The first pct% of successful deliveries
all happened within doneby seconds. The average ddelay was avg.

  doneby    avg  pct

Summarize status of mail queue

Exception!
This report does not process the log files, but instead examines and reports on the actual contents of the qmail queues.

messages in queue: 0
messages in queue but not yet preprocessed: 0

There should only be messages in the queues for a brief time while they are being processed, or longer if the destination mail server is down or if the destination email account has a temporary problem of some sort.

Email Statistics

More information on obtaining email performance statistics for your SME Server can be found in Email_Statistics.