Logging is generally an easy thing, so it's no surprise that everyone has their own idea about how to do it best, and there are a lot of options to choose from in the Perl ecosystem. The one I've settled on is Log::Any, with a custom adapter I wrote which simply writes to stderr, but with the ability to change the log level on the fly.

Syslog vs. File vs. Pipe

There are a lot of methods to choose from to get logging data out of a program. and to cut straight to my point without a bunch of exploratory prose, the one thing most of them lack is the ability to capture all output from the program, including C libraries. You might want everything to pass through syslog, but if your program develops a corrupt heap, libc will spill a bunch of information on stderr and syslog will never see it. The same can be said about many C libraries, and it gets even worse if you expect all perl code to log through the same object. Lots and lots of perl modules will call "warn" and those bits might be lost from your log unless you take some dramatic global steps to redirect warn, carp, and so on.

The daemontools design which I'm advocating says that all logging should always be done through stderr, because this is the purpose of stderr, and because it is the lowest common denominator that all libraries can make use of. It also frees the program from the setup/configuration of its logging, and leaves that decision to the caller. The only downside of stderr logging is that you often want to include more information, like log levels or timestamps. The simple workaround for this is to establish some formatting patterns that allow this information to be reconstructed later. While it isn't as clean as structured binary data, it saves the politics of trying to get all module authors to agree on a format. Just pick some sensible text prefixes and the problem is generally solved.

The prefix notation I typically use is:


trace: message at trace loglevel
debug: message at debug loglevel
message at info loglevel (no prefix)
notice: etc
warning: etc
error: etc
   
I don't typically use any higher loglevel. My omission of a prefix on "info" is because it seems redundant to write that in front of every message, and also because any module writing to stderr has a good chance of joining my prefix pattern by accident. It also lets me emit other "colon prefixes" like for my Log::Progress module. I don't typically add timestamps from the program itself, and let the logger (the program consuming the stderr pipe) add those if desired.

Log::Any vs. Log4perl vs. Log::Dispatch etc.

My choice of daemontools style stderr is mostly orthogonal to the choice of perl logging framework, since pretty much all of them support stderr. My reason for choosing Log::Any are that its primary goal is to be a generic division between modules that produce logging, and the end-user program that decides how to emit the messages. It is also extremely lightweight (dependencies and object structure) and is mostly API-compatible with the other perl loggers. By writing all my code with Log::Any, it makes it easier for me to roll up parts into CPAN modules and publish them without forcing anyone into my logging pattern.

With Log::Any providing the friendly perl logging interface, there is little reason to use any of the more complicated back ends. I wrote Log::Any::Adapter::Daemontools to give me my typical loglevel prefixes, but also to give me an easy way to change the log level at runtime, which is a feature Log::Any's default stderr adaptor lacks.

Log::Progress

As an example of the cool flexibility stderr logging can provide, I wrote the Log::Progress system to print progress status messages and then efficiently parse them from the log file. There aren't currently any examples of this in the DeLorean project, but I use it frequently at work for tracking progress of scheduled tasks. In these cases, the daemontools-style logger parses progress and error messages, and then can periodically write updates to the database where they can be easily accessed by webapps. This way the task scripts don't need to know anything about the database or how often to write to it, and if I want to make changes the only program I need to edit is the log scraper.