16.1 What Qmail Logs

Qmail logs quite a lot of information about what it's doing, although it can be daunting to collect it all together. If you're using daemontools, each daemon has its own set of logs, kept in a rotating set of log files maintained by multilog, usually with a TAI64N timestamp (see TAI64 Time Stamps). The qmail-send process logs each message queued and each delivery attempt. The qmail-smtpd process logs each incoming SMTP connection, although it won't describe what happened during the connection. tcpserver logs every connection denied due to entries in the connection rules file, and rblsmtpd logs every connection it blocked due to a DNSBL entry. If you use QMAILQUEUE to run other programs at SMTP time, anything they send to stderr is logged, and if you've added other patches to qmail-smtpd, anything they write to stderr is logged, too.

A system can be set up to do logs analysis on the fly, every time multilog switches to a new log file or once a day in a batch. It often makes sense to combine the two, doing some work at switching time and the rest daily. Although it's usually more convenient to keep the logs for each application separate, it's not hard to create combined logs for analysis or just to keep around in case someone needs to look at them later. If a set of logs from different programs all have TAI64N timestamps, merge them using the standard sort program sort -m. TAI64N timestamps are fixed-length hex strings, so merging them in alphanumeric order is the same as date order.^[1] Once they're merged, tai64local can make the timestamps readable by people. So to merge a set of log files, all of which have the standard multilog TAI64N names that start with an at-sign:

^[1] Well, unless your system uses EBCDIC rather than ASCII. Unless you're running an obscure mainframe Unix version from the 1970s, it doesn't, so we won't worry about it.

sort -m \@* | tai64nlocal > merged-log

TAI64 Time Stamps

TAI stands for International Atomic Time, an extremely precise standard maintained by the International Bureau of Weights and Measures (BIPM). The BIPM is in France, so the acronyms are for Temps Atomique Inernational and Bureau International des Poids et Measures. Dan Bernstein noted that Unix has no generally accepted way to store times at a granularity of less than a second, and the standard 32-bit timestamps can't represent times before 1970 or after 2038, so he devised a new set of TAI-based timestamp conventions for his logs.

A TAI64 label is a 16-digit hex number that represents a 64-bit number of seconds. 4000000000000000 is the beginning of 1970, the same time as a zero Unix timestamp. Smaller or larger numbers represent earlier or later times. A TAI64N label is a timestamp in nanoseconds represented as a 12-digit hex number, which is a TAI64N label followed by another four-digit hex number representing the number of nanoseconds within the second. TAI64N labels are conventionally preceded by an @ sign, like @400000003ff4ccf806d0f4fc. The multilog program can prefix TAI64N timestamps to each line of the information that it logs, and tai64nlocal translates those timestamps to readable dates and times.

See http://cr.yp.to/libtai/tai64.html for more detail.