Qmail Analog

Qmail Analog is a log analyzer tool for Qmail. It takes a standard qmail log (with any syslog record headers stripped off) and creates a “matchup” file, from which extractions (queries) and reports can be run.

Qmail Analog requires Splogger to generate the timestamp field on the record. Splogger is recommended for qmail installations, because its more trustworthy of logging and entry then plain old syslog.

Your standard log entries for a simple message from a remote sender to local user, and vice versa looks something like this. (I’ve munged the addresses and IP address).

Apr 16 10:22:45 mail2 qmail: 1018966965.100348 new msg 214283 Apr 16 10:22:45 mail2 qmail: 1018966965.101342 info msg 214283: bytes 416 from qp 93046 uid 2001 
Apr 16 10:22:45 mail2 qmail: 1018966965.163283 starting delivery 935: msg 214283 to remote feedback@cyberdesk.com 
Apr 16 10:22:46 mail2 qmail: 1018966966.356492 delivery 935: success: 209.204.256.342_accepted_message./Remote_host_said:_Message_accepted_for_delivery/ Apr 16 10:22:46 mail2 qmail: 1018966966.357108 end msg 214283 
Apr 16 10:28:42 mail2 qmail: 1018967322.742740 new msg 214283 
Apr 16 10:28:42 mail2 qmail: 1018967322.743398 info msg 214283: bytes 834 from qp 93073 uid 82 
Apr 16 10:28:42 mail2 qmail: 1018967322.769075 starting delivery 936: msg 214283 to local user@userdomain.com 
Apr 16 10:28:42 mail2 qmail: 1018967322.792578 delivery 936: success: did_1+0+0/ Apr 16 10:28:42 mail2 qmail: 1018967322.793308 end msg 214283

Generate the matchup file the command. First, we strip off the syslog headers (up to the timestamp).

cat /var/log/mailog \
| awk '{$1="";$2="";$3="";$4="";$5="";print}' \
| /usr/local/qmailanalog/bin/checklog \
  > /tmp/qmailana.log

The matchup command locates and combines log entries for a single delivery or message transaction into a single line, suitable for qmail analogs canned queries or your own ad-hoc ones. Since not all deliveries always fit nicely inside a log chunk (its still processing when the log or log chunk ends), the matchup command writes “leftover” information to file descriptor 5. Save this file to feed back into matchup when analyzing the next log chunk if you need.

This produces.

d k 1018966965.101342 1018966965.163283 1018966966.356492 416 qp remote.feedback@cyberdesk.com 0 0 209.204.256.342_accepted_message./Remote_host_said:_Message_accepted_for_delivery/ 
m 1018966965.101342 1018966966.357108 416 1 0 0 qp 0 0 
d k 1018967322.743398 1018967322.769075 1018967322.792578 834 qp local.user@userdomain.com 0 0 did_1+0+0/ 
m 1018967322.743398 1018967322.793308 834 1 0 0 qp 0 0

(Note, records split for formatting purposes.) Okay, its not any prettier, but it is quite easy to process. The fields of the delivery record and message record are defined below. If the record starts with an ‘m’, then its a message record, else its a delivery record.

• Message Record (Description)
  • id - always m
  • birth - Timestamp when message arrived
  • done - Timestamp when message processeing finished
  • bytes - Number of bytes in message
  • numk - Number of successful deliveries
  • numd - Number of failed deliveries
  • numz - Number of deferred deliveries
  • sender - Sender of message
  • qp - messge queue process id (Qmail’s internal id)
  • uid - The unix UID (user id number) of the sender (or SMTP UID)
• Devilery Record (Description)
  • id - always d
  • birth - Timestamp when message started
  • start - Timestamp when delivery started
  • end - Timestamp when deilvery finished
  • bytes - Size of the message sent (message size, not affected by qmail-remote)
  • sender - Sender of message
  • channel.recipient - Delivery Channel (local, remote) + “.” + adddress
  • qp - messge queue process id (Qmail’s internal id)
  • uid - The unix UID (user id number) of the sender (or SMTP UID)
  • reason - response message from delivery (reason)

If fields are not known (because the message birth started before the log chunk in question, qmalanalog uses “?”, 0, or “qp” if the values are unknown.

Qmailanalog ships with a few reports that are made from teh matchup log files. Mostly, these are awk scripts. These are the available reports

• ddist - Distribution of ddelays for successful deliveries
• deferrals - Groups Reasons for deferral
• failures - Groups Reasons for failure
• overall - Basic statistics
• recipients - Statistics by Recipient
• rhosts - Recipient hosts
• rxdelay - Recipients in the best order for mailing lists
• senders - Statistics for each sender
• sendmail - Gives log in sendmail format
• successes - Groups Reasons for success
• suids - Statistics by sender UID

There are “verbose” versions of these reports which print out a header of what the report shows. This is extremely useful in reading them, but not for piping the results to another process. To use the verbose reports, prepend a ‘z’ onto the from the the report name. For instance, the verbose version or ‘rhosts’ is ‘zrhosts’, get it?

The report commands are in /usr/local/qmailanalog/bin/ and are used by piping in a matchup file. So to run the basic “zoverall” command, we issue

/usr/local/qmailanalog/bin/zoverall < /tmp/qmailana.log

try it yourself and see what these reports offer. If its not quite what you need, feel free to write your own awk scripts that interpret the file according to the layout I described previously.

Qmailanalog also has a set of “extraction filters” that show only the datya you want to (hope to) see. These filters are in the same place as the reports. The extration commands start with an “x” and take a parameter to match your data. Thse extractions are as follows: To use the extractions, pipe the matchup file through the filter and send the results to your report script of choice. To track deliveries to a particular address, you may choose something like this.

 cat /tmp/qmailana.log \
 | /usr/local/qmailanalog/bin/xrecipient remote.user@userdomain.com \
 | /usr/local/qmailanalog/bin/zrecipients

Happy analoging! (analoguing?)