Tuesday, September 14, 2010

Simplifying logging with Maven and SLF4J

UPDATE:Ceki commented below which prompted me to rewrite the third paragraph.

UPDATE 2:I have a better way of configuring Maven and SLF4J now.

The mismatch between logging frameworks always seems to come up in projects I've developed over the years. Little-by-little I've learned and relearned how to navigate the nest of runtime logging that occurs in non-trivial applications. With my latest project I think I finally converged on a solution that I'll carry forward to future projects.

So what am I really talking about? Have you ever been stumped, even for a short time, about where a certain log message is going and why it might not appear in your log? Often this happens when you are trying to debug an issue with a third-party library that's using a different logging implementation them your application. If you are nodding from familiarity, skip the next paragraph.

Let's start from the beginning. There are several logging implementations available for Java, the best known being Log4J and the java.util.logging (JUL) API that was added in JDK 1.4. You may also encounter Apache commons-logging which is a logging facade for library developers to abstract their logging so library users are free to choose their own implementation such as Log4J. But commons-logging has well-documented issues so that's where slf4j comes in as my logging facade of choice. I actually code all my new applications to use the slf4j API directly because it adds functionality over the logging implementations like parameterized log messages that are only evaluated if the associated logging level is enabled. But that's tangent to this post.

So how have you solved the usage of multiple logging implementations? In the past I've tried different techniques:

  1. Configure each framework separately and have them write to their own log files.
    • Pro: Is there one?
    • Con: You need to monitor multiple files
    • Con: You need to understand the usage and configuration of each framework.
    • Con: If you are in a J2EE container you lose the log adminstration it provides.
  2. Redirect everyone to standard out and redirect standard out to a file.
    • Pro: Its all going one place.
    • Con: Its all in standard out, even errors which can make adminstration tools fail to filter messages properly.
    • Con: You still need to configure each secondary framework including message formatting so all log lines follow the same pattern.
  3. Write and connect bridges for each secondary framework so that they will log to one framework that is responsible for writing to the file, which I'll call the primary framework.
    • Pro: Its all going one place and category names, and levels are preserved through to the primary framework.
    • Pro: If the primary framework supports programmatic changes to log levels, it works for all frameworks.
    • Pro: If you are in a J2EE container that support live updating of log levels, it works for everything.
    • Con: You need to know what you are doing to develop the bridges, configure the bridge in each secondary framework and connect it all together properly.

So what's the magic solution I found? Well its a variation of #3 but it doesn't require any coding or any real knowledge of how to configure secondary frameworks. And I'll show you how to accomplish it using Maven and a logging facade API called SLF4J.

Here is the overview of the steps:
  1. Decide what the primary framework will be.
  2. Ban all secondary logging framework in your projects.
  3. Update your dependencies to exclude the banned dependencies.
  4. Configure your project to depend on drop-in replacements of each secondary logging framework from SLF4J and to use SLF4J to send everything to your primary framework.

Decide what the primary framework will be.

For my latest project, I'll be deploying to Glassfish which use JUL internally and has support in its admin console for live updating log levels without restarting the server, so it was easy to pick JUL as my primary framework.

Ban all secondary logging frameworks

Add the following plugin to your pom.xml

Add exclusions

This is where mvn dependency:tree -Dincludes=log4j:log4j is really helpful. If you try to build now, your build fail on the enforcer rule. Run this command to find which dependency is including log4j and add the necessary <exclusion>. Repeat until you find no more dependencies on log4j. Repeat for each of the banned dependencies.

Add dependency on SLF4J

Add the following to your pom.xml


So in 4 steps you can redirect all your logging to your primary logging framework without changing a line of code!