Application Logging in Java: Creating a Logging Framework

23 Apr 2019 • logging

TL;DR: If you are at a company and you need to have all your projects do logging the same way, instead of having everyone copy a logback.xml file and directly depend on logback in their projects, create a company-wide framework containing logback and the logback.xml configuration and have everyone depend on slf4j-api and your framework. I wrote up a very long sample logging project at https://github.com/tersesystems/terse-logback. You can read through it and use it as a guide for your own logging framework.

This is part of the series of blog posts:

Overview

This is going to be a long series of posts about application logging in Java, mostly in a service oriented environment. I've been working and thinking about logging for literally decades, since I first saw ATG Dynamo's LogEvent implementation back in 1998.

ATG Dynamo had logging sorted. You could walk into any company using ATG, and they'd all log exactly the same way. It never occured to me that the state of the art some two decades later would be searching Google for logback.xml templates you could borrow from, but here we are.

So, this is what I think you should do about setting up a logging framework, at a minimum. Future posts will go into fun things, but this is about the basic structure.

API vs Library vs Logging Frameworks

I want to spell out the distinction between an API, a library, and a framework. The difference is in configuration.

An API has no code attached. It may contain model classes, which are simple data transfer objects, but for the most part an API consists of pure interfaces.

A library is a bundle of code. There are no defaults, or if there are then they are very minimal. There may be some assumption that you can read from a filesystem or classpath resources, but you may well have to write all the set up in code explicitly. (CodaHale/Yammer/Dropwizard) Metrics, Netty, and Akka HTTP are libraries.

A framework is a bundle of code with some attached configuration and some express opinions about where and how things are going to go. Frameworks contain "defaults", and typically contain the ability to override and append defaults. Play, Lagom, and the commercial metric toolkits like Lightbend Instrumentation are frameworks.

In the case of logging, the API is SLF4J. The library is Logback. And there is no agreed-on logging framework – which is why you should build your own, potentially using terse-logback as a guide.

What Do I Do For Logging?

The choices are pretty simple these days.

Use Case: Writing a public library

If you're writing a public library where you don't know your end users: API only. Import slf4j-api library and stick with it. There is one situation where you may want to use java.util.logging in preference to SLF4J, and that's where you're writing to the JVM, i.e. you are writing java agents.

Do not use any kind of fancy logging API on top of SLF4J. If you absolutely must, then shade it so that your end users can upgrade without being tied to your library dependency.

Use Case: One Off Project

If you're writing a one-off stand alone application: write to the SLF4J API, and use Logback for your implementation. You can pick any logback.xml file off the internet, and it'll work fine.

Ideally, you should include a logging.properties file containing handlers = org.slf4j.bridge.SLF4JBridgeHandler and include a dependency on the jul-to-slf4j bridge to enable java.util.logging in Logback. Be sure to add the LevelChangePropagator.

Package the logback.xml file in src/main/resources so it will package with the deployment. If your users want to change logging, they'll have to define -Dlogback.configurationFile=my-logback.xml, and that's fine.

Use Case: Writing a Project at a Company

If you're one of several teams writing applications for your company: use your company's logging framework. It should be in your local Artifactory/Nexus install.

You should be able to change the logging configuration so that you can modify logging levels and override defaults in different environments, without touching the original logback.xml file.

Your company's logging framework may provide additional logging helpers or an API on top of SLF4J to provide context. You may be using libraries which only use SLF4J though, so if you have additional context it may not show through logs produced by those libraries.

Use Case: Writing a Logging Framework

If you are in the position of writing a logging framework for your company, then you'll want to do several things right up front. A single post can't cover all of this, but let's go into what I'd consider the absolute minimum.

First, you'll want to define your structured logging format. The format is, ineluctably, JSON, but the details of the JSON field names are not well defined. The one I tend to default to is Logstash standard field format. The point here is that you'll almost certainly be using an observability tool in the mix, such as Elasticsearch or Splunk, and you'll want to make your format as useful as possible.

You'll want to define your appenders. At a minimum, you'll want a console/stdout appender, a flat file appender, and a JSON file appender: these are needed for local development, so that developers can see output in a shell, be able to search for it in a flat file, and be able to dig into additional context in the JSON file.

You'll want to extract all the variables that could change. This applies not only to users who want to override configuration, but to variables that change between environments. Ideally, you want to be able to tell the logging system (or have it infer) that it is in "dev", "staging" or some other environment and be able to pick up the appropriate IP addresses and configuration from there.

Finally, you'll want to provide a means for users to set or override logging levels, both through configuration and by changing logging levels at runtime. It is highly likely that end users will want to have different logging levels in different environments, and may even want to turn on debugging dynamically in response to unusual events.

The goal here is for users to never have to touch logback.xml by hand, and to make logging an easy to use tool for observability.

An extended Q&A with an imagined casual reader

Q: So you're creating a project in Git and publishing it to Artifactory/Nexus/Bintray just so you can avoid writing a logback.xml file?

A: Yes.

Q: And you suggest that people copy / paste your project to start off a logging framework.

A: Not the whole thing, but yes, go to https://github.com/tersesystems/terse-logback and copy the bits that you find useful. Almost no-one is going to want all the bits. It's under a CC0 license, so don't worry about copyright issues.

Q: Why do you want people to copy / paste? Can't we just use your bintray artifacts?

A: I'd really prefer that you didn't. The code will work, but I'm not trying to maintain binary compatibility, and logging is very domain-specific. Those artifacts are there so I can test out frameworks myself downstream.

Q: Wouldn't it be simpler to let people copy/paste a logback.xml file into their projects?

A: You'd think that would be fine, but there's a huge difference between adding a library dependency and using a copy/pasted logback.xml file. Once you have a logback.xml file, you can have semantic drift, and projects will go out of date. There's no mechanism to keep it up to date. If you have a library dependency, you're still resolving the artifact on every build and you can see at a glance what the version number is. You can bug people to update, or even delete older artifacts out of Artifactory. You can't really do that with logback.xml.

Q: Okay, I can see that working in larger companies. What if you only have one team in a small company?

A: That doesn't really change things. If you have several projects, a logging framework is better. Even if you have a single multi-module project in Maven, you can get the same effect by specifying a logback module and adding a dependency there, and you can break it out into a library after that.

Q: Why do you keep talking about writing to the SLF4J API specifically?

A: Not to put to fine a point on it, but many of the logging APIs that either "wrap" or "replace" the SLF4J API have significant flaws. They either don't implement the Marker API, or they wire in an encoder or a format under the hood, they pull in extra library dependencies which are messy to deal with when they run into binary incompatibilities… the list goes on. I'm not saying don't do it. But don't do it yet.

Q: What about Log4J2?

A: If you're using the SLF4J API, you should be able to swap out your implementation to whatever you like. I personally prefer Logback with the StructuredArgument / LogstashMarker API provided by logstash-logback-encoder, so I stick with it.

Q: So you use custom encoders? And you're using LogstashMarker specifically in front end code?

A: Not quite. You should provide your own domain logic API and provide the logback implementation in a different library. There's a good discussion of custom arguments here.

Q: But you can add your own dependencies into the logging framework, is what you're saying.

A: Generally, as long as the implementation is behind the curtain, and you know you're responsible for it, you can do it. For example, if you use encoders that pull in Jackson 2.8 and you have an end user project that requires 2.10, then you're going to have to publish two different versions of the logging framework. The big difference is that an encoder is already componentized. Replacing an encoder with a custom-built one is a much easier job than trying to upgrade a logging API.

Q: What about testing? You have a logback-test.xml in your framework?

This is an interesting question, and a complicated one. I think we need to make a distinction between test framework code, and test code, but Maven style projects typically jam everything into src/test/java and src/test/resources. This causes problems when you have stubs and generators stuck next to your test suites, because it means that downstream test suites that depend on those test framework classes using compile->compile; test->test end up pulling in multiple logback-test.xml files. I do have an approach in the project, but this is one area I think could stand more considered thought.

Q: What, what's this censor stuff? And proxies? You have a byte code manipulation agent that injects logging statements? What is half this stuff?

A: That's all the time we have for now. Tune in next week for more logging!