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

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.