Most of the time you would like to inject dependencies to your class directly – through the class constructor or by setting required properties via setters. No matter what programming style you prefer you may encounter situation when some dependency cannot or shouldn’t be passed directly to your system under test.

Good example of that kind of situation are loggers – most of the time we want to access them directly via static methods. I will show you ideas how to effectively use SLF4J with Logback in unit tests.

SLF4J stands for Simple Logging Facade for Java

How to test logs?

Logs are important piece of production code – they play primary role in debugging and are useful in analytics. We can test them in few ways:

1. We can read them in console output
2. We can dump logs to file and analyze that file (in production or in integration tests)
3. We can provide test double for logger and test logs in unit test

In the next sections we will focus on the third option – testing logger in unit tests

Why would you test logs?

Let’s suppose that your code encounter very specific race condition. You fixed the bug and now you want to have information in your monitoring services if something like this happens again. Those race conditions may be difficult to reproduce in full environment so instead of clicking through app you write automatic test for that case.

How to mock SLF4J Logger?

SLF4J is default logger added to Spring Boot projects. There are high chances that you are already using it.

Let’s consider the following RestController:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.http.HttpStatus;
import org.springframework.http.ResponseEntity;
import org.springframework.web.bind.annotation.*;

import java.util.Collections;
import java.util.List;
import java.util.Map;

@RestController
public class Controller {

    private final ItemsService service;

    private final Logger logger = LoggerFactory.getLogger(Controller.class);

    public Controller(ItemsService service) {
        this.service = service;
    }

    @GetMapping
    public List<Entity> getAll() {
        try {
            return service.getAll();
        } catch (Exception exception) {
            logger.warn("Service.getAll returned exception instead of empty list", exception);
            return Collections.emptyList();
        }
    }

}

As you can see, in this case we log warn when service throws exception, but we are not passing that error to client, rather log it for monitoring purposes.

We could try to move logger into constructor parameter and just change it’s implementation for unit tests. That’s not always possible due to several reasons (legacy code, team programming style, etc.). We will try to provide test double for logger without system under test modification – it will stay private final.

How to assert that SLF4J logged warn?

We will:

1. Grab the logger from LoggerFactory
2. Add appender
3. Assert that specific log with desired level Level.Warn was logged and that it contains proper message

To capture logs without messing with XML configurations, we need to add appender to logger.

But wait, org.slf4j.Logger does not have addAppender method! Appenders are supported by ch.qos.logback.classic.Logger!

To ensure which implementation of Logger runs in your test, you may use debugger or just print logger class:

private final Logger logger = LoggerFactory.getLogger(Controller.class);

public Controller(ItemsService service) {
    this.service = service;
    System.out.println((logger.getClass().toString())); //class ch.qos.logback.classic.Logger

}

For testing purpose we can cast Logger to it’s underlying implementation:

LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME) as ch.qos.logback.classic.Logger

Now we are ready to add appender to this method. We can use some of built-in appenders such as ListAppender or implement our own:

import ch.qos.logback.classic.spi.ILoggingEvent
import ch.qos.logback.core.AppenderBase

class TestAppender : AppenderBase<ILoggingEvent>() {
    private val events: MutableList<ILoggingEvent> = mutableListOf()

    fun lastLoggedEvent() = events.lastOrNull()

    override fun append(eventObject: ILoggingEvent) {
        events.add(eventObject)
    }
}

Logs that come to appender are added to events list

Now we can write rest of the test:

import ch.qos.logback.classic.Level
import ch.qos.logback.classic.Logger
import io.kotest.assertions.assertSoftly
import io.kotest.core.spec.style.StringSpec
import io.kotest.matchers.shouldBe
import io.kotest.matchers.string.shouldContain
import org.mockito.kotlin.doThrow
import org.mockito.kotlin.mock
import org.slf4j.LoggerFactory


class ControllerLoggingTest : StringSpec({

    "given service error when get all called then log warn" {
        //prepare logging context
        val testAppender = TestAppender()

        val logger = LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME) as ch.qos.logback.classic.Logger

        logger.addAppender(testAppender)
        testAppender.start()

        //setup system under test
        val controller = Controller(mock {
            on { getAll() } doThrow Exception("Something failed :(")
        })

        //execute system under test
        controller.getAll()

        //capture last logged event

        val lastLoggedEvent = testAppender.lastLoggedEvent()

        require(lastLoggedEvent != null) {
            "There are on events appended in TestLogger"
        }

        //assertion on last logged event fields
        assertSoftly {
            lastLoggedEvent.level shouldBe Level.WARN
            lastLoggedEvent.message shouldContain "Service.getAll returned exception instead of empty list"
        }
    }
})

I’m using here few techniques described in previous articles – read here how to assertSoftly and check here how to use Mockito with Kotlin

Important! If you are not capturing events in appender, ensure you invoked appender.start() method!

To sum things up:

1. Add custom appender to logger
2. Execute system under test normally
3. Assert that something happened in custom appender

Bonus: TestAppender for SLF4J implementation in Java

I highly encourage you to give Kotlin a try in unit tests, but if you are just looking for SLF4J / Logback test in Java, use the following snippets:

import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.AppenderBase;

import java.util.ArrayList;

class TestLogAppender extends AppenderBase<ILoggingEvent> {

    ArrayList<ILoggingEvent> loggingEvents = new ArrayList<>();

    @Override
    protected void append(ILoggingEvent eventObject) {
        loggingEvents.add(eventObject);
    }

    ILoggingEvent getLastLoggedEvent() {
        if (loggingEvents.isEmpty()) return null;

        return loggingEvents.get(loggingEvents.size() - 1);

    }
}

TestLogAppender

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;
import org.junit.jupiter.api.Test;
import org.mockito.Mockito;
import org.slf4j.LoggerFactory;

import java.util.List;

import static org.junit.jupiter.api.Assertions.assertEquals;
import static org.junit.jupiter.api.Assertions.assertNotNull;

public class ControllerLoggerTestJava {

    @Test
    public void given_service_error_when_get_all_called_then_log_warn() throws Exception {


        ItemsService service = Mockito.mock(ItemsService.class);
        Mockito.when(service.getAll()).thenThrow(new Exception("Something failed :("));
        Controller controller = new Controller(service);


        TestLogAppender testLogAppender = new TestLogAppender();
        Logger logger = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
        logger.addAppender(testLogAppender);

        testLogAppender.start();

        List<Entity> entityList = controller.getAll();

        ILoggingEvent lastLoggedEvent = testLogAppender.getLastLoggedEvent();
        assertNotNull(lastLoggedEvent);
        assertEquals(lastLoggedEvent.getMessage(), "Service.getAll returned exception instead of empty list");
    }
}

The same test case as before, but in Java, with Junit5 and classic Mockito 

Summary

• check if library you are using supports indirect injection (something like adding Appender)
• try to avoid using static methods with side effects in the first place – if you inject your dependencies directly, you have more control!
• What to do if appender cannot be added to logger? Stay tuned for the next articles!

---