使用JUnit断言日志消息

最后修改:2024年12月7日

by baeldung

1. Introduction

In this tutorial, we’ll look at how we can cover generated logs in JUnit testing.

We’ll use the slf4j-api and the logback implementation and create a custom appender that we can use for log assertion.

2. Maven Dependencies

Before we begin, let’s add the logback dependency. As it natively implements the slf4j-api, it is automatically downloaded and injected into the project by Maven transitivity:

<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>. 
    <version>1.2.6</version>
</dependency>

AssertJ offers very useful functions when testing, so let’s add its dependency to the project as well:

<dependency>
    <groupId>org.assertj</groupId>
    <artifactId>assertj-core</artifactId>
    <version>3.26.0</version>
    <scope>test</scope>
</dependency>

3. A Basic Business Function

Now, let’s create an object that will generate logs we can base our tests on.

Our BusinessWorker object will only expose one method. This method will generate a log with the same content for each log level. Although this method isn’t that useful in the real world, it’ll serve well for our testing purposes:

public class BusinessWorker {
    private static Logger LOGGER = LoggerFactory.getLogger(BusinessWorker.class);

    public void generateLogs(String msg) {
        LOGGER.trace(msg);
        LOGGER.debug(msg);
        LOGGER.info(msg);
        LOGGER.warn(msg);
        LOGGER.error(msg);
    }
}

4. Testing the Logs

We want to generate logs, so let’s create a logback.xml file in the src/test/resources folder. Let’s keep it as simple as possible and redirect all logs to a CONSOLE appender:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>
                %d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n
            </Pattern>
        </layout>
    </appender>

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

4.1. MemoryAppender

Now, let’s create a custom appender that keeps logs in memory. We’ll extend the ListAppender that logback offers, and we’ll enrich it with a few useful methods:

public class MemoryAppender extends ListAppender<ILoggingEvent> {
    public void reset() {
        this.list.clear();
    }

    public boolean contains(String string, Level level) {
        return this.list.stream()
          .anyMatch(event -> event.toString().contains(string)
            && event.getLevel().equals(level));
    }

    public int countEventsForLogger(String loggerName) {
        return (int) this.list.stream()
          .filter(event -> event.getLoggerName().contains(loggerName))
          .count();
    }

    public List<ILoggingEvent> search(String string) {
        return this.list.stream()
          .filter(event -> event.toString().contains(string))
          .collect(Collectors.toList());
    }

    public List<ILoggingEvent> search(String string, Level level) {
        return this.list.stream()
          .filter(event -> event.toString().contains(string)
            && event.getLevel().equals(level))
          .collect(Collectors.toList());
    }

    public int getSize() {
        return this.list.size();
    }

    public List<ILoggingEvent> getLoggedEvents() {
        return Collections.unmodifiableList(this.list);
    }
}

The MemoryAppender class handles a List that is automatically populated by the logging system.

It exposes a variety of methods in order to cover a wide range of test purposes:

  • reset() – clears the list
  • contains(msg, level) – returns true only if the list contains an ILoggingEvent matching the specified content and severity level
  • countEventForLoggers(loggerName) – returns the number of ILoggingEvent generated by named logger
  • search(msg) – returns a List of ILoggingEvent matching the specific content
  • search(msg, level) – returns a List of ILoggingEvent matching the specified content and severity level
  • getSize() – returns the number of ILoggingEvents
  • getLoggedEvents() – returns an unmodifiable view of the ILoggingEvent elements

4.2. Unit Test

Next, let’s create a JUnit test for our business worker.

We’ll declare our MemoryAppender as a field and programmatically inject it into the log system. Then, we’ll start the appender.

For our tests, we’ll set the level to DEBUG:

@Before
public void setup() {
    Logger logger = (Logger) LoggerFactory.getLogger(LOGGER_NAME);
    memoryAppender = new MemoryAppender();
    memoryAppender.setContext((LoggerContext) LoggerFactory.getILoggerFactory());
    logger.setLevel(Level.DEBUG);
    logger.addAppender(memoryAppender);
    memoryAppender.start();
}

Now we can create a simple test where we instantiate our BusinessWorker class and call the generateLogs method. We can then make assertions on the logs that it generates:

@Test
public void test() {
    BusinessWorker worker = new BusinessWorker();
    worker.generateLogs(MSG);
        
    assertThat(memoryAppender.countEventsForLogger(LOGGER_NAME)).isEqualTo(4);
    assertThat(memoryAppender.search(MSG, Level.INFO).size()).isEqualTo(1);
    assertThat(memoryAppender.contains(MSG, Level.TRACE)).isFalse();
}

This test uses three features of the MemoryAppender:

  • Four logs have been generated — one entry per severity should be present, with the trace level filtered
  • Only one log entry with the content message with the level severity of INFO
  • No log entry is present with content message and severity TRACE

If we plan to use the same instance of this class inside the same test class when generating a lot of logs, the memory usage will creep up. We can invoke the MemoryAppender.clear()* method before each test to free memory and avoid *OutOfMemoryException.

In this example, we’ve reduced the scope of the retained logs to the LOGGER_NAME package, which we defined as “com.baeldung.junit.log“. We could potentially retain all logs with LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME), but we should avoid this whenever possible as it can consume a lot of memory.

4.3. Handling Multiple Logs with Varying Levels

To validate application logs effectively in scenarios where multiple entries are generated at various levels (INFO, WARN, ERROR, and more), we can use methods such as counting, filtering, and asserting specific content:

@Test
public void whenMultipleLogLevel_thenReturnExpectedResult() {
    BusinessWorker worker = new BusinessWorker();
    worker.generateLogs("Transaction started for Order ID: 1001");

    assertThat(memoryAppender.countEventsForLogger(LOGGER_NAME)).isEqualTo(4);
    assertThat(memoryAppender.search("Transaction started", Level.INFO).size()).isEqualTo(1);
    assertThat(memoryAppender.search("Transaction started", Level.WARN).size()).isEqualTo(1);
    assertThat(memoryAppender.search("Transaction started", Level.ERROR).size()).isEqualTo(1);
    assertThat(memoryAppender.search("Transaction started", Level.TRACE)).isEmpty();
}

In the @Before setup method, the logger’s level is programmatically set to DEBUG. A logger set to DEBUG will log everything from DEBUG to higher levels (INFO, WARN, ERROR), but it will exclude TRACE logs because TRACE has a lower priority than DEBUG.

4.4. Using Pattern Matching for Dynamic Log Content

When log messages contain dynamic data like timestamps, user IDs, or transaction IDs, we can use regular expressions to validate their content. This ensures that the structure and key details of the log messages are correct.

Let’s create a method for pattern-based validation:

boolean containsPattern(Pattern pattern, Level level) {
    return this.list.stream()
      .filter(event -> event.getLevel().equals(level))
      .anyMatch(event -> pattern.matcher(event.getFormattedMessage()).matches());
}

This utility method provides a clean way to check if any log message matches a given pattern at a specific level.

Let’s demonstrate how to validate log messages with dynamic content using regex:

@Test
public void whenUsingPattern_thenReturnExpectedResult() {
    BusinessWorker worker = new BusinessWorker();
    worker.generateLogs("Order processed successfully for Order ID: 12345");

    Pattern orderPattern = Pattern.compile(".*Order ID: \\d{5}.*");

    assertThat(memoryAppender.containsPattern(orderPattern, Level.INFO)).isTrue();
    assertThat(memoryAppender.containsPattern(orderPattern, Level.WARN)).isTrue();
    assertThat(memoryAppender.containsPattern(orderPattern, Level.ERROR)).isTrue();
    assertThat(memoryAppender.containsPattern(orderPattern, Level.TRACE)).isFalse();
}

The regex .*Order ID: \\d{5}.* ensures the message contains an order ID followed by exactly 5 digits. With this, we can ensure the test remains valid even if the dynamic part of the log (order ID) changes.

In cases where multiple patterns are expected, we can create a containPatterns() method for matching multiple patterns:

boolean containsPatterns(List<Pattern> patternList, Level level) {
    return patternList.stream()
      .allMatch(pattern -> containsPattern(pattern, level));
}

Then, we can validate all of them in a single test:

@Test
public void whenUsingMultiplePatterns_thenReturnExpectedResult() {
    BusinessWorker worker = new BusinessWorker();
    worker.generateLogs("User Login: username=user123, timestamp=2024-11-25T10:15:30");

    List patterns = List.of(
      Pattern.compile(".*username=user\\w+.*"),
      Pattern.compile(".*timestamp=\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}.*")
    );

    assertThat(memoryAppender.containsPatterns(patterns, Level.INFO)).isTrue();
    assertThat(memoryAppender.containsPatterns(patterns, Level.WARN)).isTrue();
}

5. Conclusion

With this tutorial, we’ve demonstrated how to cover log generation in our unit tests. Additionally, we introduced pattern matching with regular expressions to validate dynamic log messages, ensuring logs conform to expected formats.

As always, the code can be found over on GitHub.

« 上一篇： Java Weekly, 第332期
» 下一篇： 如何为Jsoup添加代理支持？