Application Logging in Java: Adding Configuration

TL;DR: If you need to write a logging framework, you want to set up configuration so that end user applications can override what they need to and ignore the details that they don't care about. This is how you do that.

This is part of the series of blog posts:

Overview

The difference between a framework and a library is that a framework includes a level of default configuration, and a level of overrides. Specifically, variables can be defined at one level, and overridden at another.

The key here is to ensure that as much as possible, changing the configuration does not involve changing program logic.

We'll do this in two stages. First, we'll point out what Logback gives you out of the box and how that's insufficient. Then, we'll expand on the out of the box configuration leveraging Typesafe Config.

The terse-logback projects demonstrates this configuration in the logback-structured-config project, and you can see examples of it.

Logback Configuration

Logback does have some configuration options. From the Logback configuration page, variable substitution is managed from several different scopes, ranging from local scope, context scope, system property scope, and finally using environment variables, in that order.

Using this scheme, you could define environment variables for Logback as defaults, and then override that with system properties when starting up the JVM. This would be pretty unwieldy, and Logback does give you the option to do better than that.

For example, you could define in src/main/resources/logback-defaults.properties the following properties:

console.withJansi=false
console.encoder.pattern=[%highlight(%-5level)] %logger{15} -  %message%n%xException{10}

And refer to the resource inside logback configuration:

<configuration>
  <property resource="logback-defaults.properties" scope="local"/>
 
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${console.encoder.pattern}</pattern>
        </encoder>
        <withJansi>${console.withJansi}</withJansi>
    </appender>

   <root>
      <appender-ref ref="CONSOLE"/> 
   </root>
</configuration>

The problem comes in when you try to define an optional resource – for example, you want a project to be able to override the settings in a logback-local.properties file that they define:

<configuration>
  <property resource="logback-defaults.properties" scope="local"/>
  <property resource="logback-local.properties" scope="local"/>
 
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${console.encoder.pattern}</pattern>
        </encoder>
        <withJansi>${console.withJansi}</withJansi>
    </appender>

   <root>
      <appender-ref ref="CONSOLE"/> 
   </root>
</configuration>

When you do this, you'll get the following:

20:10:21,989 |-ERROR in ch.qos.logback.core.joran.action.PropertyAction - Could not find resource [logback-local.properties].

Because logback-local.properties is not optional. You can't just not have a properties file there. (I know you can disable logback errors by using NopStatusListener but an error is still an error even if you're not listening to it.)

You can get around this a bit by using include files, which can be optional, and so don't spit out an error:

<configuration>
  <property resource="logback-defaults.properties" scope="local"/>
 
  <include optional="true" resource="logback-local.xml"/>
  
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${console.encoder.pattern}</pattern>
        </encoder>
        <withJansi>${console.withJansi}</withJansi>
  </appender>

   <root>
      <appender-ref ref="CONSOLE"/> 
   </root>
</configuration>  

where logback-local.xml is defined as follows:

<included>
<property resource="logback-local.properties" scope="local"/>
</included>

But this is pretty cludgy.

There are also some general issues with Logback configuration. Properties are strings: you can't create maps or lists using properties. Likewise, although LoggerContext has an object map, you can't add maps or lists to that object map from the XML file. This means although you can do things like this in code:

List urls = Collections.singletonList("http://example.com");
context.putObject("urls", urls);

It's tough to do this in XML configuration.

Most central of all, there's no facility to define logger levels as overriddable properties. You define logger levels in XML, and you can sort of configure them through properties:

<configuration>
   <!-- ... -->
   <logger name="com.example.Logger" level="${com.example.logger.level:-INFO}">
   <root level="${root.level:-INFO}">
      <appender-ref ref="CONSOLE"/> 
   </root>
</configuration>

but again, if you want to do something completely general then you have to use optional includes:

<configuration>
   <!-- logger-levels.xml contains logger name="foo" level="INFO" settings... -->
   <include optional="true" resource="loggers-levels.xml"/>
   <root level="${root.level:-INFO}"> <!-- root is awkward and must be defined directly -->
      <appender-ref ref="CONSOLE"/> 
   </root>
</configuration>

So, using logback configuration is awkward, and we can do better.

Typesafe Config

Typesafe Config is a library that incorporates HOCON, a file format that is explicitly set up for configuration. It does this by adding two features: “merging” (two objects or two files can be combined in a defined way), and “substitution” (a reference syntax ${foo} used to point to other parts of the config or to environment variables). Include statements are also supported (defined in terms of merging, that is, an include inserts another file inline and merges its fields).

I'm not going to go into the details of Typesafe Config here. Havoc Cunningham, the primary author, writes about the design and motivation of HOCON and I recommend the README and the file format breakdown.

The key thing to note about Typesafe Config is that it has fallback behavior which incorporates resources explicitly:

The idea is that libraries and frameworks should ship with a reference.conf in their jar. Applications should provide an application.conf, or if they want to create multiple configurations in a single JVM, they could use ConfigFactory.load("myapp") to load their own myapp.conf.

The plan is to set up Typesafe Config with Logback, using similiar fallback behavior. We'll specify the following fallbacks, so a property is looked up in the following order:

  • System properties: -Dfoo=bar always wins.
  • Explicitly defined file: -Dlogback.config=config.conf will win after that.
  • Test Resources: a property in logback-test.conf is used if found in resources.
  • Resources: logback.conf contains application properties.
  • Reference: logback-reference.conf contains the defaults.

Using Typesafe Config with Logback means that most applications will only need to specify logback.conf in their application, and can override logging settings in logback-test.conf, leaving most of the defaults in logback-reference.conf. All overrides will be in HOCON format, and so will be easier to manage than specifying an include file and managing the XML directly.

We'll then use three categories, levels, local, and context, which will write to the LoggerContext object:

# Contains logger levels that are set directly in Logback
levels {
   ROOT = INFO
   com.example.Logger = INFO
}

# Contains properties which are set in the "local" scope of Logback
local {
}

# Contains properties which are set in the "context" scope of Logback
context {
}

We'll also include a facility that will map from more complex HOCON objects like maps and lists into the LoggerContext object map.

Defining TypesafeConfigAction

The way to set up custom behavior in Logback is by defining custom actions. This is easiy done with the newRule action, which we'll hook in with a typesafeConfig action, and a setLoggerLevels action.

<configuration>
    <newRule pattern="*/typesafeConfig"
             actionClass="com.tersesystems.logback.typesafeconfig.TypesafeConfigAction"/>

    <newRule pattern="*/setLoggerLevels"
             actionClass="com.tersesystems.logback.SetLoggerLevelsAction"/>

    <typesafeConfig>
        <object name="highlightMap" path="highlight" scope="context"/>
    </typesafeConfig>

    <root>
        <appender-ref ref="CONSOLE"/>
    </root>

    <!-- Set the logger levels at the very end -->
    <setLoggerLevels/>

</configuration>

These map to TypesafeConfigAction.java and SetLoggerLevelsAction.java in Github.

There's not much to the underlying code, but it is worthwhile to see how the local scope and context scope map to the InterpretationContext and Context classes, as setting properties is slightly different between the two. Also, we place levels and the config object directly into the object map so we can do more complex things later if we feel like it:

context.putObject(TYPESAFE_CONFIG_CTX_KEY, config);
context.putObject(LEVELS_KEY, levelsMap);

There is a facility for referencing complex objects directly as well, which means that the highlight map in HOCON can be referenced in code:

Map<String,String> highlights = (Map<String,String>) config.getObject("highlightMap");

The SetLoggerLevel code is fairly straightforward and does what you think – it sets all the loggers up directly from configuration, without the need to touch XML.

Using Configuration

Using the above example as a guide, it's easy to define a logback.conf file in the src/main/resources folder, and rely on the logback.xml file defined in the library. For example, an example logback.conf file could look like this:

# Set logger levels here.
levels = {
  # Override the default root log level with ROOT_LOG_LEVEL environment variable, if defined...
  ROOT = ${?ROOT_LOG_LEVEL}

  # You can set a logger with a simple package name.
  com.example.Logger = DEBUG
}

local {
  console.withJansi=true
  console.encoder.pattern=[%highlight(%-5level)] %logger{15} -  %message%n%xException{10}
}

# You can also include settings from other places
include "myothersettings"

The example project in terse-logback discusses loading TypesafeConfigAction with a more complex example that uses structured logging.

This covers out to pull out static variables out of Logback. Next week, we go into what happens when you need to pull dynamic values out of Logback, aka call-by-name.

More …