Configuring logging for Clojure applications

Banks have thousands of applications, each with large complex code-bases that must be supported long after the original application authors have moved onto something else. When something goes wrong a support engineer will invariably check the log file first. Few things are as common to every application as the humble log file.

It’s quite surprising to think that Java didn’t have an official logging API in the JDK until its fifth major release (1.4).

The sad history of Java logging

In the beginning there was System.out.println which writes out to the console. Many still use that today.

For those who needed more sophisticated logging, a package called log4j emerged in 1999 from IBM ‘alphaworks’. This steadily grew in popularity until it became the de-facto standard. Then Sun decided to write their own logging package and include it in the JDK, as java.util.logging. Not that there was anything significantly wrong with log4j, it was simply an example of the ‘not-invented-here’ syndrome that Sun was suffering from at the time. Despite a hard fought campaign to persuade Sun to incorporate log4j into the platform. Soon after, Sun realised that this sort of thing was damaging to Java’s reputation and created the JSR process to incorporate the wider Java community in decision making.

But the fact that Java had 2 near-identical logging packages led to further complexity. Apache created a facade called commons-logging that attempted to wrap both packages. By deciding to use a Java interface, Apache commons-logging negated the carefully crafted performance of the log4j package it was wrapping.

There have been attempts in the Java world to improve matters. One notable example is slf4j.

Logging in Clojure

Clojure logging neatly solves the problems of Java logging.

First, there’s a single API to use: clojure.tools.logging. Thank Alex Taggart and others for this. Second, it integrates with all the important logging frameworks: log4j, java.util.logging, Apache’s commons-logging and now slf4j. Finally, it side-steps many of the performance penalties associated with logging.

If you have a lot of logging statements in your code-base, you only want to pay the performance penalty for logging statements that are actually being written to the log file. However, too often CPU is wasted in creating a logging message only for that message to be filtered out later on. The conventional workaround in Java is to wrap every complex logging statement with a conditional.

if (logger.isDebugEnabled()) {
    logger.debug(x + " plus " + y + " is " + (x + y));
}

Without the conditional wrapper, the String concatenation would be quite expensive if it was ultimately unnecessary (for example, if the logger in question was configured to output warnings only). But the workaround is obviously cumbersome, implemented inconsistently and adds noise to the code’s readability. (Being the new(est) kid on the block, slf4j is able to make use of the JDK 1.5 varargs feature to avoid common string concatenation until after the message has made it through the filters).

Fortunately for Clojure programmer, the clojure.tools.logging takes care of this for them by using macros. As a Clojure programmer you get the benefit of optimized performance without the unsightly code-bloat.

Configuration

Unfortunately the Clojure logging facility doesn’t offer anything to help configure the logging package being used underneath.

Typically, Java logging is configured using configuration files. As you’d expect from Java, every configuration file is different, each one balancing flexibility with complexity. This is a horrible Java legacy to subject Clojure programmers to. An alternative approach is needed, so I’ve written a library: clj-logging-config.

You start by using requiring the library with :use (or :require) in your namespace declaration. In these examples I assume you are using log4j configuration, but you can configure java.util.logging in a similar way.

(ns my-ns
  (:use clojure.tools.logging 
        clj-logging-config.log4j))

Then you configure the logging system declaring a logger with set-logger!

(set-logger!)

and just start logging :-

(info "Just a plain logging message")

Check your console (not the REPL).

console> INFO - Just a plain logging message

In log4j it is common to set a pattern against the logger. Full syntax can be found in org.apache.log4j.EnhancedPatternLayout. For example, to set a pattern which just displays the message, do this:

(set-logger! :pattern "%m%n")
(info "Just the message this time")

console> Just the message this time

Or this.

(set-logger! :pattern "%d - %m%n")
(info "A logging message with the date in front")

console> 2011-08-07 10:58:21,084 - A logging message with the date in front

In the same way you can set the level of the logger. For example, so that the logger only prints warnings, you can do this :-

(set-logger! :level :warn) 

Or if you want to use the log4j Java class, you can do that as well :-

(set-logger! :level org.apache.log4j.Level/WARN) 

You can also set the appender to one of the appenders provided by the logging package you are using. For example, you can do this :-

(set-logger! :out (org.apache.log4j.DailyRollingFileAppender.))

Or even provide your own appender function.

(set-logger! :out (fn [ev] (println (:message ev))))

You can also set filters in the same way. Filters are useful but rarely used in log4j because they’re fundamentally a function, and log4j configurations formats don’t support writing functions – perhaps they should have used LISP!

(set-logger! :filter (fn [ev] (not (re-seq #"password" (:message ev)))))

For filters and appenders the underlying logging event is converted to a Clojure map (with the original event bound to the :event key, should you need it)

You can also set the additivity of the logger – the default is true but you can set it to false. Addivity is described in the Log4J user-guide – so we won’t repeat it here.

(set-logger! :additivity false)

It (almost) goes without saying that you can combine all these options together :-

(set-logger! :level :warn 
             :additivity false
             :pattern "%p - %m%n"
             :filter (constantly true))

There are some combinations that doesn’t make sense (such as using :pattern and :layout together). In these cases an exception will be thrown.

So much for getting started. In a real system you’ll want to configure multiple loggers in the same place :-

(set-loggers! 

    "com.malcolmsparks.foo" 
    {:level :info :pattern "%m"}

    ["com.malcolmsparks.bar" "com.malcolmsparks.zip"]
    {:level :debug})

You’ll find a lot more in this package, including support for per-thread (per-agent) logging which is useful in certain situations. One of the design goals of this library is that it ‘does the right thing’ most of the time. The aim is to prevent the common experience in log4j where you can’t figure out why you can’t see your logging statements and revert to println in frustration.

I do hope that Clojure programmers find this library useful. The only way to find out is to ask people to use it. It definitely needs more exposure to real projects but I wanted to release it now to get more feedback. The library is licensed under the EPL (same as Clojure’s) and available here.

3 thoughts on “Configuring logging for Clojure applications

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>