1, Background

When we write unit tests, we occasionally need to obtain the contents of the logger output of the tested object for assertion or troubleshooting through unit tests.

For example: (1) You need to Assert that a log has been output (you can't just change the output object to the Appender of Console, output it to the Console to view the content, and you can't Assert it through Assert)

(2) A certain method is complex. The logs are printed at many places in the middle. After the objects that mock depends on in the single test, you need to see which logs are output. (when running a unit test, it is usually not output to the console. Usually, many students will temporarily add print statements to the target object and delete them after passing the test, which is very troublesome)

Think for yourself:

(1) Listen to log events, get the event content for printing or assertion (usually strongly related to the log framework) (2) Using the ArgumentCaptor function of Mockito (3) You can implement the Logger interface or encapsulate a LoggerWrapper as a shell. During the test, use the Logger mock as our customized Logger class When the log method is called, the corresponding content is stored in the member variable container When asserting or printing later, you can take it out.

Today, we will introduce a mature solution: log captor

2, Introduction

GITHUB address: https://github.com/Hakky54/log-captor

Latest version: https://mvnrepository.com/artifact/io.github.hakky54/logcaptor

Latest version on November 22, 2021

<dependency>
    <groupId>io.github.hakky54groupId>
    <artifactId>logcaptorartifactId>
    <version>2.7.2version>
    <scope>testscope>
dependency>

2.1 routine test

Tested class:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class FooService {

    private static final Logger LOGGER = LogManager.getLogger(FooService.class);

    public void sayHello() {
        LOGGER.info("Keyboard not responding. Press any key to continue...");
        LOGGER.warn("Congratulations, you are pregnant!");
    }

}

Unit test:

import static org.assertj.core.api.Assertions.assertThat;

import nl.altindag.log.LogCaptor;
import org.junit.jupiter.api.Test;

public class FooServiceShould {

    @Test
    public void logInfoAndWarnMessages() {
        LogCaptor logCaptor = LogCaptor.forClass(FooService.class);

        FooService fooService = new FooService();
        fooService.sayHello();

        // Get logs based on level
        assertThat(logCaptor.getInfoLogs()).containsExactly("Keyboard not responding. Press any key to continue...");
        assertThat(logCaptor.getWarnLogs()).containsExactly("Congratulations, you are pregnant!");

        // Get all logs
        assertThat(logCaptor.getLogs())
                .hasSize(2)
                .contains(
                    "Keyboard not responding. Press any key to continue...",
                    "Congratulations, you are pregnant!"
                );
    }
}

2.2 reuse logCaptor

import nl.altindag.log.LogCaptor;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.AfterAll;
import org.junit.jupiter.api.AfterEach;
import org.junit.jupiter.api.BeforeAll;

public class FooServiceShould {

    private static LogCaptor logCaptor;
    private static final String EXPECTED_INFO_MESSAGE = "Keyboard not responding. Press any key to continue...";
    private static final String EXPECTED_WARN_MESSAGE = "Congratulations, you are pregnant!";
    
    @BeforeAll
    public static setupLogCaptor() {
        logCaptor = LogCaptor.forClass(FooService.class);
    }

    @AfterEach
    public void clearLogs() {
        logCaptor.clearLogs();
    }
    
    @AfterAll
    public static void tearDown() {
        logCaptor.close();
    }

    @Test
    public void logInfoAndWarnMessagesAndGetWithEnum() {
        FooService service = new FooService();
        service.sayHello();

        assertThat(logCaptor.getInfoLogs()).containsExactly(EXPECTED_INFO_MESSAGE);
        assertThat(logCaptor.getWarnLogs()).containsExactly(EXPECTED_WARN_MESSAGE);

        assertThat(logCaptor.getLogs()).hasSize(2);
    }

    @Test
    public void logInfoAndWarnMessagesAndGetWithString() {
        FooService service = new FooService();
        service.sayHello();

        assertThat(logCaptor.getInfoLogs()).containsExactly(EXPECTED_INFO_MESSAGE);
        assertThat(logCaptor.getWarnLogs()).containsExactly(EXPECTED_WARN_MESSAGE);

        assertThat(logCaptor.getLogs()).hasSize(2);
    }

}

2.3 setting log level

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.Logger;

public class FooService {

    private static final Logger LOGGER = LogManager.getLogger(FooService.class);

    public void sayHello() {
        if (LOGGER.isDebugEnabled()) {
            LOGGER.debug("Keyboard not responding. Press any key to continue...");
        }
        LOGGER.info("Congratulations, you are pregnant!");
    }

}

Test log level

import static org.assertj.core.api.Assertions.assertThat;

import nl.altindag.log.LogCaptor;
import org.junit.jupiter.api.Test;

public class FooServiceShould {

    @Test
    public void logInfoAndWarnMessages() {
        LogCaptor logCaptor = LogCaptor.forClass(FooService.class);
        logCaptor.setLogLevelToInfo();

        FooService fooService = new FooService();
        fooService.sayHello();

        assertThat(logCaptor.getInfoLogs()).contains("Congratulations, you are pregnant!");
        assertThat(logCaptor.getDebugLogs())
            .doesNotContain("Keyboard not responding. Press any key to continue...")
            .isEmpty();
    }
}

2.4 exception log

import nl.altindag.log.service.Service;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import java.io.IOException;

public class FooService {

    private static final Logger LOGGER = LoggerFactory.getLogger(ZooService.class);

    @Override
    public void sayHello() {
        try {
            tryToSpeak();
        } catch (IOException e) {
            LOGGER.error("Caught unexpected exception", e);
        }
    }

    private void tryToSpeak() throws IOException {
        throw new IOException("KABOOM!");
    }
}

Exception log assertion

import static org.assertj.core.api.Assertions.assertThat;

import nl.altindag.log.LogCaptor;
import nl.altindag.log.model.LogEvent;
import org.junit.jupiter.api.Test;

public class FooServiceShould {

    @Test
    void captureLoggingEventsContainingException() {
        LogCaptor logCaptor = LogCaptor.forClass(ZooService.class);

        FooService service = new FooService();
        service.sayHello();

        List<LogEvent> logEvents = logCaptor.getLogEvents();
        assertThat(logEvents).hasSize(1);

        LogEvent logEvent = logEvents.get(0);
        assertThat(logEvent.getMessage()).isEqualTo("Caught unexpected exception");
        assertThat(logEvent.getLevel()).isEqualTo("ERROR");
        assertThat(logEvent.getThrowable()).isPresent();

        assertThat(logEvent.getThrowable().get())
                .hasMessage("KABOOM!")
                .isInstanceOf(IOException.class);
    }
}

For more advanced usage, please refer to the github example or unit test in the source code.

3, Summary

When you encounter unsatisfied scenes during development, you should give priority to looking for whether predecessors have solved the problem well. On the one hand, you can verify whether your ideas are reliable. On the other hand, even if the other party doesn't solve it well, you can refer to the ideas of others and improve yourself.

If you have a better way, please leave a message and discuss with me.

It's not easy to create. If this article is helpful to you, you are welcome to praise, collect and pay attention. Your support and encouragement are the biggest driving force of my creation.