Tag: spring

Logback has the capability to programmatically and explicitly load various configurations. This can be useful when you need to adjust logging levels at runtime, and it’s actually pretty easy to do, as well.
You’d want to use something like this for a long-running application, or one that has an extensive load process: imagine a production environment, where you want to see details that would be hidden by convention.
For example, imagine you track a given method invocation, but your production logs don’t include the tracking, because it’s too verbose. But if a problem occurs, you want to be able to see the invocation. Changing the logging configuration and redeploying (or restarting) is an option, but it’s expensive and embarrassing, when all you really need to do is see more information.
The core operative code looks like this:

LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
context.reset();
JoranConfigurator configurator = new JoranConfigurator();
configurator.setContext(context);
configurator.doConfigure(this.getClass().getResourceAsStream("/logback.xml"));

Note that doConfigure can throw a JoranException if the configuration is invalid somehow.
I built a project (called logback-reloader) to demonstrate this. The project has a LogThing interface, which provides a simple doSomething() method along with an accessor for a Logger; the doSomething() method simply issues a series of calls to generate log entries at different levels.

public interface LogThing {
    Logger getLog();
    default void doSomething() {
        getLog().trace("trace message");
        getLog().debug("debug message");
        getLog().warn("warn message");
        getLog().info("info message");
        getLog().error("error message");
    }
}

I then created two different implementations – ‘FineLogThing’ and ‘CoarseLogThing’ which are identical except that they’re named differently (so that I can easily tune the logging levels).
It would have been easy to use a single implementation and declare two components with Spring, but then I’d be deriving the logger from the Spring name and not the package of the classes. This was just a short path to completion, not necessarily a great design.

Why Spring? Because I’m using Spring at work, and I wanted my test code to be reusable.

Then I created a custom Appender (InMemoryAppender) to provide easy access to logged information. I wanted to do this because I wanted to programmatically check that the logging levels were being changed; the idea is that my custom appender actually maintains a list of logged entries internally so I can query it later. The reason the logged entries is a static List is because Spring doesn’t maintain the Appenders – logback does – so again, this was a short path to completion, not necessarily a “great design.”
So to put it together, I created a TestNG test that had two tests in it. The only difference in the tests is that one uses “logback.xml” – the default configuration, loaded by default but explicitly included here to remove dependency on order of execution in the tests – and the other uses “logback-other.xml“. (I could have parameterized the tests as well – again, shortest path, not “great design.”)
Our default logback configuration is pretty simple, albeit slightly longer than I’d like:

<configuration>
    <appender name="MEMORY" class="com.autumncode.logger.InMemoryAppender"></appender>
    <logger name="com.autumncode.components.fine" level="TRACE"></logger>
    <logger name="com.autumncode.components.coarse" level="INFO"></logger>
    <root level="WARN">
        <appender -ref ref="MEMORY"></appender>
    </root>
</configuration>

Note that it’s appender-ref, no spaces. The Markdown implementation from this site’s software is inserting the space before the dash.

The “other” logback configuration is almost identical. The only difference is in the level for the coarse package:

<configuration>
    <appender name="MEMORY" class="com.autumncode.logger.InMemoryAppender"></appender>
    <logger name="com.autumncode.components.fine" level="TRACE"></logger>
    <logger name="com.autumncode.components.coarse" level="TRACE"></logger>
    <root level="WARN">
        <appender -ref ref="MEMORY"></appender>
    </root>
</configuration>

Here’s the first test:

@Test
public void testBaseConfiguration() throws JoranException {
    LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory();
    context.reset();
    JoranConfigurator configurator = new JoranConfigurator();
    configurator.setContext(context);
    configurator.doConfigure(this.getClass().getResourceAsStream("/logback.xml"));
    appender.reset();
    fineLogThing.doSomething();
    assertEquals(appender.getLogMessages().size(), 5);
    appender.reset();
    coarseLogThing.doSomething();
    assertEquals(appender.getLogMessages().size(), 3);
}

This verifies that the coarse logger doesn’t include as many elements as the fine logger, because the default logback configuration has a more coarse logging granularity set for its package.
The other test is almost identical, as stated: the only differences are in the logback configuration file and the number of messages the coarse logger is expected to have created.
So there you have it: a simple example of reloading logback configuration at runtime.

It’s worth noting that this isn’t “new information.” It’s actually shown pretty well at sites like “Obscured by Clarity,” for example. The only contribution here is the building of a project with running code, as well as loading the configuration from the classpath as opposed to from a filesystem.