Verify logging with Logback

Sometimes you have a piece of logging that is very important, maybe even part of a business requirement. In that case, you might want to verify that in a unit test, so you can rest assured that this requirement is actually met. How to do that?

Mock it away

A first approach might be to just mock your logging framework in a unit test and verify it was called as you expected. It might sound tempting, and easy to do, but not everybody likes it. And in fact, you might run into some issues when walking this path, because some libraries tend to make classes and/or methods final so they can’t always be mocked away. Also, a lot of people tend to create a logger by doing private static final Logger LOG = ..., which makes it even harder to mock it away. Making your logger an instance variable just so you can test it? Nah…

Integration testing - but not as we know it

In fact, a better approach would be to do integration testing. It might sound like a “heavy approach”, but that is not always the case. Let’s see how we can do a light-weight integration test using JUnit and Logback.

As a first step, we need to register a custom Logback appender. The easiest way is to use an OutputStreamAppender that will simply dump log messages to an OutputStream. Note that the order of method calls is important for the Appender; if you first set the OutputStream and then the Encoder, it will not work!

private Logger logger;
private final ByteArrayOutputStream logging = new ByteArrayOutputStream();

@Before
public void setupLogging() {
    final LoggerContext context = (LoggerContext) LoggerFactory
        .getILoggerFactory();

    // Define that pattern that is used for logging.
    final PatternLayoutEncoder encoder = new PatternLayoutEncoder();
    encoder.setPattern("%level|%msg%n");
    encoder.setContext(context);
    encoder.start();

    // Define where the logging should go
    final OutputStreamAppender appender = new OutputStreamAppender();
    appender.setEncoder(encoder);
    appender.setOutputStream(logging);
    appender.setContext(context);
    appender.setName("AppenderForTesting");
    appender.start();

    // Mount the Appender to the Logger
    this.logger = (Logger) LoggerFactory.getLogger(
        "my.class.that.does.Logging");
    logger.addAppender(appender);
}

To make sure this test does not affect other tests, we also need to remove the extra Appender after each test:

@After
public void cleanupLogging() {
    if (this.logger != null) {
        this.logger.detachAppender("AppenderForTesting");
    }
}

Next, we write a little helper method that will do our assertions:

private void verifyLogging(final String level, final String partOfMessage) {
    final String logging = this.logging.toString();
    final String[] parts = logging.split("\\|");
    assertThat(parts[0], is(level));
    assertThat(parts[1], containsString(partOfMessage));
}

Finally, we can do our real tests:

@Test
public void myMethodShouldLog() {
    // Arrange

    // Act
    systemUnderTest.methodUnderTest();

    // Assert
    verifyLogging("DEBUG", "This logging is very important!");
}

We’ve written a real integration test: it verifies we have our logging working from start to end, and we’ve integrated our logging framework of choice correctly. Yet, this integration test runs in just a few milliseconds on modern hardware.