Mail log file analysis

The SME server manager provides access to most of the log files maintained by the system.

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.

logterse

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 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

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

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.