如何在日志记录器中对消息进行JUnit断言

310

我有一些测试代码,它调用Java记录器来报告其状态。 在JUnit测试代码中,我想验证是否已经在记录器中正确地生成了日志条目。以下是大致的代码:

methodUnderTest(bool x){
    if(x)
        logger.info("x happened")
}

@Test tester(){
    // perhaps setup a logger first.
    methodUnderTest(true);
    assertXXXXXX(loggedLevel(),Level.INFO);
}

我认为可以通过一个特别适应的日志记录器(或处理程序,或格式化程序)来实现这一点,但我更希望重用已经存在的解决方案。(而且,说实话,我不清楚如何从日志记录器获取logRecord,但假设那是可能的。)

33个回答

173
我也多次需要这个功能。下面我提供了一个小示例,你可以根据自己的需求进行调整。基本上,你需要创建自己的Appender并将其添加到所需的logger中。如果你想收集所有日志,那么根logger是一个好的开始位置,但如果你想要更具体的内容,可以使用更加具体的logger。记得在完成后删除Appender,否则可能会导致内存泄漏。在下面的测试中我已经实现了它,但是根据你的需求,setUp或者@BeforetearDown或者@After可能是更好的选择。
另外,以下实现将所有日志都收集到内存中的List中。如果你的日志记录非常频繁,你可能需要添加一个过滤器来删除无用的条目,或者将日志写入到临时文件中(提示: LoggingEventSerializable的,因此如果你的日志消息也是可序列化的,你应该能够直接序列化事件对象)。
import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.apache.log4j.spi.LoggingEvent;
import org.junit.Test;

import java.util.ArrayList;
import java.util.List;

import static org.hamcrest.CoreMatchers.is;
import static org.junit.Assert.assertThat;

public class MyTest {
    @Test
    public void test() {
        final TestAppender appender = new TestAppender();
        final Logger logger = Logger.getRootLogger();
        logger.addAppender(appender);
        try {
            Logger.getLogger(MyTest.class).info("Test");
        }
        finally {
            logger.removeAppender(appender);
        }

        final List<LoggingEvent> log = appender.getLog();
        final LoggingEvent firstLogEntry = log.get(0);
        assertThat(firstLogEntry.getLevel(), is(Level.INFO));
        assertThat((String) firstLogEntry.getMessage(), is("Test"));
        assertThat(firstLogEntry.getLoggerName(), is("MyTest"));
    }
}

class TestAppender extends AppenderSkeleton {
    private final List<LoggingEvent> log = new ArrayList<LoggingEvent>();

    @Override
    public boolean requiresLayout() {
        return false;
    }

    @Override
    protected void append(final LoggingEvent loggingEvent) {
        log.add(loggingEvent);
    }

    @Override
    public void close() {
    }

    public List<LoggingEvent> getLog() {
        return new ArrayList<LoggingEvent>(log);
    }
}

6
这个方法很好用。我唯一的改进建议是调用logger.getAllAppenders(),然后逐个调用appender.setThreshold(Level.OFF)(完成后要重置它们!)。这样可以确保您尝试生成的“错误”消息不会显示在测试日志中并且不会让下一个开发人员感到困惑。 - Coderer
3
在Log4j 2.x中,创建自定义appender稍微有些复杂,需要创建一个插件,请参考这个链接:https://dev59.com/8GAf5IYBdhLWcg3w2Vso - panza
2
谢谢您的回复。但是,如果您正在使用LogBack,您可以使用ListAppender<ILoggingEvent>而不是创建自己的自定义appender。 - sinujohn
6
但是这对于slf4j并不起作用!您知道我该如何更改使其也能与slf4j一起使用吗? - Shilan
3
如果将Logger转换为org.apache.logging.log4j.core.Logger(实现该接口的实现类),则可以再次访问setAppender()/removeAppender() - David Moles
显示剩余2条评论

127

这里是一个简单而高效的Logback解决方案。
它不需要添加/创建任何新类。
它依赖于ListAppender:一个白盒子logback appender,其中日志条目被添加到一个public List字段中,我们可以使用它来进行断言。

下面是一个简单的示例:

Foo类:

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Foo {

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

    public void doThat() {
        LOGGER.info("start");
        //...
        LOGGER.info("finish");
    }
}

FooTest类:

import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;

public class FooTest {

    @Test
    void doThat() throws Exception {
        // get Logback Logger 
        Logger fooLogger = (Logger) LoggerFactory.getLogger(Foo.class);

        // create and start a ListAppender
        ListAppender<ILoggingEvent> listAppender = new ListAppender<>();
        listAppender.start();

        // add the appender to the logger
        // addAppender is outdated now
        fooLogger.addAppender(listAppender);

        // call method under test
        Foo foo = new Foo();
        foo.doThat();

        // JUnit assertions
        List<ILoggingEvent> logsList = listAppender.list;
        assertEquals("start", logsList.get(0)
                                      .getMessage());
        assertEquals(Level.INFO, logsList.get(0)
                                         .getLevel());

        assertEquals("finish", logsList.get(1)
                                       .getMessage());
        assertEquals(Level.INFO, logsList.get(1)
                                         .getLevel());
    }
}

JUnit断言似乎不太适合于断言列表元素的某些特定属性。
像AssertJ或Hamcrest这样的Matcher/Assertion库似乎更适合于这个问题:

使用AssertJ,可以这样做:

import org.assertj.core.api.Assertions;

Assertions.assertThat(listAppender.list)
          .extracting(ILoggingEvent::getMessage, ILoggingEvent::getLevel)
          .containsExactly(Tuple.tuple("start", Level.INFO), Tuple.tuple("finish", Level.INFO));

如果记录错误,如何防止测试失败? - Ghilteras
@Ghilteras,我不确定是否理解。记录错误不应该导致测试失败。你的意思是什么? - davidxxx
3
在我的情况下,直到我获取了根记录器(而不是类记录器),appenderlist 才为空: Logger logger = (Logger) LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME) - xardbaiz
11
如果找不到“addAppender”方法,你需要将fooLogger强制转换为实现类,比如“ch.qos.logback.classic.Logger”,然后就可以使用“addAppender”方法了。 - danny
1
实际上,可以使用getFormattedMessage来显示应用所有参数后的最终日志消息,例如对于log.info("foo {}", "bar");logsList.get(0).getMessage()将返回foo {},而logsList.get(0).getFormattedMessage()则会返回foo bar - Vasilen Donchev
显示剩余3条评论

66

对于 Junit 5(Jupiter)而言,Spring 的 OutputCaptureExtension 非常有用。可以通过 @ExtendWith 注解为整个测试类或单个测试方法注册它。自 Spring Boot 2.2 起可用,并且在 spring-boot-test 工件中提供。

示例(摘自 javadoc):

@ExtendWith(OutputCaptureExtension.class)
class MyTest {
    @Test
    void test(CapturedOutput output) {
        System.out.println("ok");
        assertThat(output).contains("ok");
        System.err.println("error");
    }

    @AfterEach
    void after(CapturedOutput output) {
        assertThat(output.getOut()).contains("ok");
        assertThat(output.getErr()).contains("error");
    }
}

4
这正是我在寻找的答案(尽管问题与Spring Boot无关)! - dragi
2
@Ram 无论是拦截记录器还是拦截实际的记录字符串,只要记录器被配置为打印到控制台,它都可以正常工作。 - aemaem
1
哇!就是这样。不需要使用静态模拟记录器。捕获实际输出。 - cwa
1
这是一个 AssertJ 断言。导入语句应该是 import static org.assertj.core.api.Assertions.*; - aemaem
1
为我工作。附注:请将断言代码替换为以下内容:assertTrue(output.getOut().contains("xxx log")); - lei li
显示剩余2条评论

47

非常感谢这些(意外地)快速和有帮助的答案;它们为我的解决方案指明了正确的方向。

我想在代码库中使用这个,它使用 java.util.logging 作为其日志记录机制,但我对那些代码不太熟悉,无法完全将其更改为 log4j 或日志记录器接口/门面。但基于这些建议,我编写了一个 j.u.l.handler 扩展,并且它运行得很好。

以下是简要总结。扩展 java.util.logging.Handler

class LogHandler extends Handler
{
    Level lastLevel = Level.FINEST;

    public Level  checkLevel() {
        return lastLevel;
    }    

    public void publish(LogRecord record) {
        lastLevel = record.getLevel();
    }

    public void close(){}
    public void flush(){}
}

显然,你可以从LogRecord中存储尽你想要/需要的数据,或将它们全部压入栈中直到溢出。

在junit测试准备阶段,你创建了一个java.util.logging.Logger并向其添加了一个新的LogHandler

@Test tester() {
    Logger logger = Logger.getLogger("my junit-test logger");
    LogHandler handler = new LogHandler();
    handler.setLevel(Level.ALL);
    logger.setUseParentHandlers(false);
    logger.addHandler(handler);
    logger.setLevel(Level.ALL);

调用setUseParentHandlers()是为了禁止正常的处理程序,以便(对于这个junit测试运行)不会发生不必要的日志记录。执行您的被测代码需要使用此记录器,运行测试并assertEquality:

    libraryUnderTest.setLogger(logger);
    methodUnderTest(true);  // see original question.
    assertEquals("Log level as expected?", Level.INFO, handler.checkLevel() );
}

(当然,你可以将这项工作的大部分移动到一个@Before方法中,并进行其他各种改进,但那会使这个演示变得杂乱无章。)


任何想了解Spring Boot的方法的人,请查看https://dev59.com/W3I-5IYBdhLWcg3wfoa1#60527144 - nitin angadi
如果libraryUnderTest.setLogger(logger);没有被定义,这在日志记录器作为private static final field时经常发生,该怎么办? - Eric Duminil

21

我也遇到了同样的挑战,最终来到了这个页面。虽然我回答问题已经晚了11年,但我认为这可能仍然对其他人有用。我发现davidxxx的答案使用Logback和ListAppender非常有用。我将相同的配置用于多个项目,但是复制/粘贴并在需要更改时维护所有版本并不那么有趣。我认为最好将其制作成库并回馈社区。它适用于SLFJ4、Apache Log4j2、Java Util Logging、JBoss Logging、Google Flogger以及Lombok注释。请查看此处:LogCaptor,了解详细示例以及如何将其添加到您的项目中。

示例情况:

public class FooService {

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

    public void sayHello() {
        LOGGER.warn("Congratulations, you are pregnant!");
    }

}

使用LogCaptor的单元测试示例:

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

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

public class FooServiceTest {

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

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

        assertThat(logCaptor.getWarnLogs())
            .contains("Congratulations, you are pregnant!");
    }
}

我不太确定是否应该在这里发布这篇文章,因为它也可以被视为推广“我的库”,但我认为这可能对有同样挑战的开发者有所帮助。

2
非常容易使用且代码量较少!对我来说是一个很好的解决方案。谢谢! - Tiemo Vorschütz
1
请加上导入项? - Readren
2
@Readren 刚刚添加了它。 - Hakan54

20

实际上,您正在测试一个依赖类的副作用。对于单元测试,您只需要验证使用正确参数调用了

logger.info()

因此使用 mocking 框架来仿真 logger,使您可以测试自己的类行为。


12
你如何模拟一个私有的静态不可变字段,例如大多数日志记录器?使用PowerMockito?玩得开心。 - Stefano L
Stefano:那个最终字段以某种方式被初始化了,我看到过各种注入Mock而不是真实对象的方法。可能需要在设计时考虑一定程度的可测试性。https://blog.codecentric.de/en/2011/11/testing-and-mocking-of-static-methods-in-java/ - djna
正如Mehdi所说,可能使用适当的Handler就足够了。 - djna
2
如果使用 private static final Logger LOGGER = Logger.getLogger(someString); 定义了日志记录器,你仍然可以通过 Logger.getLogger(someString); 在单元测试中访问它,修改它并添加处理程序(就像接受的答案中所示)。 - Eric Duminil

18

另一个选项是模拟Appender并验证消息是否已记录到此Appender。Log4j 1.2.x和Mockito的示例:

import static org.junit.Assert.assertEquals;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;

import org.apache.log4j.Appender;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
import org.apache.log4j.spi.LoggingEvent;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.mockito.ArgumentCaptor;

public class MyTest {

    private final Appender appender = mock(Appender.class);
    private final Logger logger = Logger.getRootLogger();

    @Before
    public void setup() {
        logger.addAppender(appender);
    }

    @Test
    public void test() {
        // when
        Logger.getLogger(MyTest.class).info("Test");

        // then
        ArgumentCaptor<LoggingEvent> argument = ArgumentCaptor.forClass(LoggingEvent.class);
        verify(appender).doAppend(argument.capture());
        assertEquals(Level.INFO, argument.getValue().getLevel());
        assertEquals("Test", argument.getValue().getMessage());
        assertEquals("MyTest", argument.getValue().getLoggerName());
    }

    @After
    public void cleanup() {
        logger.removeAppender(appender);
    }
}

我们如何在log4j2.x中完成相同的操作? - PAA

11

对于log4j2,解决方案略有不同,因为AppenderSkeleton不再可用。此外,如果您希望多个日志消息,则使用Mockito或类似库创建一个带有ArgumentCaptor的Appender将不起作用,因为MutableLogEvent在多个日志消息中重复使用。我找到的log4j2最佳解决方案是:

import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.Logger;
import org.apache.logging.log4j.core.appender.AbstractAppender;

private static MockedAppender mockedAppender;
private static Logger logger;

@Before
public void setup() {
    mockedAppender.message.clear();
}

/**
 * For some reason mvn test will not work if this is @Before, but in eclipse it works! As a
 * result, we use @BeforeClass.
 */
@BeforeClass
public static void setupClass() {
    mockedAppender = new MockedAppender();
    logger = (Logger)LogManager.getLogger(MatchingMetricsLogger.class);
    logger.addAppender(mockedAppender);
    logger.setLevel(Level.INFO);
}

@AfterClass
public static void teardown() {
    logger.removeAppender(mockedAppender);
}

@Test
public void test() {
    // do something that causes logs
    for (String e : mockedAppender.message) {
        // add asserts for the log messages
    }
}

private static class MockedAppender extends AbstractAppender {

    List<String> message = new ArrayList<>();

    protected MockedAppender() {
        super("MockedAppender", null, null);
    }

    @Override
    public void append(LogEvent event) {
        message.add(event.getMessage().getFormattedMessage());
    }
}

11

受@RonaldBlaschke解决方案启发,我想出了这个:

public class Log4JTester extends ExternalResource {
    TestAppender appender;

    @Override
    protected void before() {
        appender = new TestAppender();
        final Logger rootLogger = Logger.getRootLogger();
        rootLogger.addAppender(appender);
    }

    @Override
    protected void after() {
        final Logger rootLogger = Logger.getRootLogger();
        rootLogger.removeAppender(appender);
    }

    public void assertLogged(Matcher<String> matcher) {
        for(LoggingEvent event : appender.events) {
            if(matcher.matches(event.getMessage())) {
                return;
            }
        }
        fail("No event matches " + matcher);
    }

    private static class TestAppender extends AppenderSkeleton {

        List<LoggingEvent> events = new ArrayList<LoggingEvent>();

        @Override
        protected void append(LoggingEvent event) {
            events.add(event);
        }

        @Override
        public void close() {

        }

        @Override
        public boolean requiresLayout() {
            return false;
        }
    }

}

...这使你能够做到:

@Rule public Log4JTester logTest = new Log4JTester();

@Test
public void testFoo() {
     user.setStatus(Status.PREMIUM);
     logTest.assertLogged(
        stringContains("Note added to account: premium customer"));
}

你可能可以更加聪明地使用Hamcrest,但我已经保留了现有的内容。


11

虚拟化是一种选择,但实际上可能会很困难,因为记录器通常是私有静态常量。因此,设置一个模拟记录器并不容易,或者需要修改测试类。

你可以创建一个自定义的Appender(或称为日志输出器),并将其注册 - 通过测试专用的配置文件或运行时方式(依赖于日志框架)。 然后,你可以获取该appender(如果在配置文件中声明,可以静态地获取;如果是在运行时插入,则可以通过当前引用获取),并验证其内容。


网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接