syslog - Logging done right

Logfiles are scattered around everywhere. It's tedious to track them down when you just want to know the status of your backup job. You have to think about where to put them when writing your helpful little scripts. And they need to be tamed with logrotate or a similar tool so they don't explode in size.

Log all the things

Is there a better way? Of course there is. Just put this line somewhere on the top of your next shell script:

exec 1> >(logger -s -t $(basename $0)) 2>&1

This command ensures that everything from now on gets logged both to your terminal and to syslog, labeled with the script's filename. Quite handy if you ask me! See for yourself:

% cat logger_test
#!/bin/bash

exec 1> >(logger -s -t $(basename $0)) 2>&1

echo "hi, how are you?"
echo "this goes to stderr" >&2
date
echo "funky stuff"

Now, if you run this script, you'll get the output both to the terminal due to the logger -s flag[^1]:

% ./logger_test
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: hi, how are you?
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: this goes to stderr
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: Fr  3 Apr 2015 20:36:10 CEST
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: funky stuff

... and to the central syslog:

% cat /var/log/system.log | grep logger_test
Apr  3 20:36:10 aiur logger_test[13633]: hi, how are you?
Apr  3 20:36:10 aiur logger_test[13633]: this goes to stderr
Apr  3 20:36:10 aiur logger_test[13633]: Fr  3 Apr 2015 20:36:10 CEST
Apr  3 20:36:10 aiur logger_test[13633]: funky stuff

syslog on OS X

If you don't know syslog, here's the gist of it:

syslog is a widely used standard for message logging. It permits separation of the software that generates messages, the system that stores them, and the software that reports and analyzes them. Computer system designers can use syslog for system management and security auditing as well as general informational, analysis, and debugging messages.

There are many implementations of syslog for different operating systems. Most of those provide the commandline utility logger, which we used above to send messages to the central logging facility. On OS X, aslmanager[^2] manages rotated files and ASL data written by syslogd.

The manpage indicates that /etc/asl.conf is the configuration file for syslogd and aslmanager. Let's look at the settings for system.log:

% cat /etc/asl.conf
# ...
# save everything from emergency to notice
? [<= Level notice] store
# ...
# Rules for /var/log/system.log
> system.log mode=0640 format=bsd rotate=seq compress file_max=5M all_max=50M
? [= Sender kernel] file system.log
? [<= Level notice] file system.log
...

We learn a couple of things:

  • system.log is rotated and compressed, ensuring that it doesn't get to big
  • messages smaller or equal to notice are being logged to system.log; higher levels are ignored
  • Table 2. Syslog Message Severities in RFC 5424: The Syslog Protocol shows that INFO and DEBUG are therefore not stored by ASL

syslog querying

The syslog commandline tool offers a couple of nice features compared to the logfile /var/log/system.log. First of all, you can filter the log messages by Facility. Our logger -t flag sets the Facility to the script's filename logger_test:

% syslog -k Sender logger_test
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: hi, how are you?
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: this goes to stderr
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: Fr  3 Apr 2015 20:36:10 CEST
Apr  3 20:36:10 aiur logger_test[13633] <Notice>: funky stuff

But the syslog tool has some pretty nice tricks up its sleeve when it comes to filtering. The manpage shows more complex search expressions:

# find all messages sent by portmap in the last 2 hours
syslog -k Sender portmap -k Time ge -2h

Conclusion

By using the syslog facility, we don't have to take care of individual logfiles for each little script we write. In turn, we have central place to query for log messages, with nice filter expressions at our hand.

With a lot of nice things, there's also a catch here: as you saw above, all messages are saved with log level Notice, so no distinction made between STDOUT and STDERR. If you want to differentiate, you've got to use logger -p <PRIORITY> for each message.

Further resources

For a full dive into the topic of logging, here are a couple of handy resources to know about:

  • log4sh, very similar to the logging services from the Apache Software Foundation, which means that it comes with different loggers, levels and appenders.
  • syslog-ng, Open Source log management solution with over a million global users, an enhanced syslog daemon: the Babel fish of event processing; the next generation of centralized logging
  • logstash, another awesome centralized logging service. You can use it to collect logs, parse them, and store them for later use (like, for searching). Speaking of searching, logstash comes with a web interface for searching and drilling into all of your logs.

[^1]: from the manpage: -s Log the message to standard error, as well as the system log [^2]: Apple System Log data life-cycle manager