Subscribe via RSS

4 Steps to Java Logging Nirvana

I have never met an engineer that worked with Java and hasn’t struggled to configure logging. A legacy of poor decisions has made a mess of the ecosystem, but there is hope and a clear path forward. Follow these simple steps and you may grow to love java logging like the crazy uncle it is.

1. SLF4J 4 Life

Java logging has churned through many different logging interfaces and implementations. The most common of which are:

  1. System.out/err - the OG hardcore way to log
  2. java.util.logging (jul) - part of the standard lib as of 1.4, and horribly limited
  3. Apache (née Jakarta) Commons Logging (jcl) - an “interface” with magical classloader hell
  4. Log4j - Ceki Gülcü wrote a pretty good logging implementation in 1999, but it is kinda slow and has some odd quirks
  5. Simple Logging Facade for Java (SLF4J) - Ceki Gülcü decided JCL was a horrible interface, and created a new facade that actually used interfaces
  6. Logback - Ceki Gülcü decided log4j needed to be rewritten from scratch

The details of the history are rather gory, and relatively unimportant to our goal of logging nirvana.

Libraries should never dictate a logging implementation

Because JUL and JCL have significant limitations and issues, people began to depend on log4j directly in libraries, as 99% of the java world was using it. This sucked because, being an implementation, log4j wanted to add new features or deprecate old methods. Hijinks ensued as adding any new dependency might change or break your logging output. So, don’t depend on specific logging implementations in your libraries, leave that up to the projects that include you.

Libraries should always ONLY depend on SLF4J API

There is no reasonable argument against using SLF4J as your interface into logging. It is simple, powerful, well-supported, and leaves the actual logging implementation up to the end-user. Further, it has implementations of the Log4j, JCL, and JUL public APIs which allow you to convince third-party-libraries to talk to your logging framework of choice, even if they depend on an implementation instead of an interface.

2. Use logback

Our hero/villain, Ceki, explains in many words why he thinks we should use logback instead of log4j here. There is a lot in that document I don’t necessarily agree are very important, but the key here is that our implementation choices boil down to:

  1. JUL - limited and hard to configure
  2. Log4j - Ceki’s old unsupported implementation
  3. Logback - Ceki’s new supported implementation

The answer is clear, at least for now. Thanks to SLF4J, if something like tinylog becomes a superior logging implementation it would be trivial to switch to it.

3. MDC is Your Friend

Logback (and log4j) offer a feature called Mapped Diagnostic Context (MDC). This is effectively a thread-local Map<String,String> that can be referenced in your log format. If you are doing any of the following, you should instead be using MDC:

  1. Manually including, or wishing you were including, context information in your log lines, like userid
  2. Creating helper functions that wrap calls to log methods to include standard context
  3. Passing context to functions merely to log it out

To use MDC, you merely call MDC.put("key", "value") and reference the key name in your log format with %X{key}. This feature combines effortlessly with jax-rs Filters. Ankush Goyal used this methodology to add transaction ids, experiments, userids, and more to all of our web app logs. Taking things further, he added standard context like datasource id to our crawler logs.

4. Configure Programmatically

So, you might ask how you best manage your log formatting and log levels across your different projects and environments. Complexity increases multiplicatively with each new service or environment. Logback allows you to configure things with XML, groovy, or programmatically. Using files to configure your logging is a route straight to hell, and that this is still the standard in 2015 is frightening. Lets improve it.

At RelateIQ, we have a simple Guice module (soa-logging) that configures all of the SLF4J veneers and uses a simple injectable configuration object instead of a file. Further, we are working on using a service (qonf) to store configuration information. The combination of these allows us to dynamically and centrally configure the most important aspects of our logging: the format, and the levels for various packages. Look here for an open-source release of qonf in the near future.

So everything is awesome then?

Well, things are not exactly awesome. This is still a lot of anger to merely write out a bunch of formatted Strings. Once you have even a decent amount of logs you will hopefully be using something like Splunk, Sumologic, or Logstash. All these tools spend a lot of their time working to turn your Strings into structured, queryable data. Why not just log structured data to begin with? One can dream…