【问题标题】：How to intercept SLF4J (with logback) logging via a JUnit test?如何通过 JUnit 测试拦截 SLF4J（带 logback）日志记录？
【发布时间】：2022-03-28 13:01:54
【问题描述】：

是否有可能以某种方式拦截日志记录（SLF4J + logback）并通过 JUnit 测试用例获得InputStream（或其他可读的内容）...？

【问题讨论】：

标签： java junit slf4j logback

【解决方案1】：

Slf4j API 没有提供这种方式，但 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
        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());
    }
}

您还可以将 Matcher/assertion 库用作 AssertJ 或 Hamcrest。

使用 AssertJ 会是：

import org.assertj.core.api.Assertions;

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

【讨论】：

非常感谢！这正是我想要的！
我收到 Logger fooLogger = (Logger) LoggerFactory.getLogger(Foo.class); 的 ClassCastException。我正在使用LoggerFactory 的org.slf4j.LoggerFactory 和Logger 的ch.qos.logback.classic.Logger
@Hiren 如果您使用 JUnit 5，请确保不要意外导入 org.junit.platform.commons.logging.LoggerFactory，这就是发生在我身上的事情。
重要的是要注意，如果您的日志包含参数值，则应使用 ILoggingEvent::getFormattedMessage 而不是 ILoggingEvent::getMessage。否则，您的断言将失败，因为该值将丢失。
如果您使用SLF4J，此解决方案最终会引发SLF4J: Class path contains multiple SLF4J bindings. 警告，因为您同时拥有 SLF4J 和 logback.classic

【解决方案2】：

您可以创建自定义附加程序

public class TestAppender extends AppenderBase<LoggingEvent> {
    static List<LoggingEvent> events = new ArrayList<>();
    
    @Override
    protected void append(LoggingEvent e) {
        events.add(e);
    }
}

并配置 logback-test.xml 以使用它。现在我们可以从我们的测试中检查日志事件：

@Test
public void test() {
    ...
    Assert.assertEquals(1, TestAppender.events.size());
    ...
}

注意：如果您没有得到任何输出，请使用 ILoggingEvent - 请参阅评论部分了解原因。

【讨论】：

注意，如果你使用 logback classic + slf4j 你需要使用ILoggingEvent 而不是LoggingEvent。这对我有用。
@Evgeniy Dorofeev 你能说明如何配置 logback-test.xml 吗？
我假设您需要在每次测试执行后清除 events。
@hipokito 您可以使用sample0.xml 中提到的[此处] (logback.qos.ch/manual/configuration.html)。不要忘记将附加程序更改为您的实现
@EvgeniyDorofeev 你能帮我解决这个问题吗？ stackoverflow.com/questions/48551083/…

【解决方案3】：

您可以使用来自http://projects.lidalia.org.uk/slf4j-test/ 的 slf4j-test。它用它自己的 slf4j api 实现替换了整个 logback slf4j 实现以进行测试，并提供一个 api 来断言日志事件。

示例：

<build>
  <plugins>
    <plugin>
      <artifactId>maven-surefire-plugin</artifactId>
      <configuration>
        <classpathDependencyExcludes>
          <classpathDependencyExcludes>ch.qos.logback:logback-classic</classpathDependencyExcludes>
        </classpathDependencyExcludes>
      </configuration>
    </plugin>
  </plugins>
</build>

public class Slf4jUser {

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

    public void aMethodThatLogs() {
        logger.info("Hello World!");
    }
}

public class Slf4jUserTest {

    Slf4jUser slf4jUser = new Slf4jUser();
    TestLogger logger = TestLoggerFactory.getTestLogger(Slf4jUser.class);

    @Test
    public void aMethodThatLogsLogsAsExpected() {
        slf4jUser.aMethodThatLogs();

        assertThat(logger.getLoggingEvents(), is(asList(info("Hello World!"))));
    }

    @After
    public void clearLoggers() {
        TestLoggerFactory.clear();
    }
}

【讨论】：

感谢您提供这个替代答案！它看起来非常有用，将来我很可能也会尝试这种方法！不幸的是，我已经接受了另一个正确的答案。
使用lidalia的slf4j-test包的完整示例可以在这里找到：github.com/jaegertracing/jaeger-client-java/pull/378/files
如果您不使用 Spring，此解决方案可以正常工作。如果你使用 Spring，它会抛出一个 class not found 异常（JoranConfigurator）。

【解决方案4】：

使用 JUnit5 + AssertJ

private ListAppender<ILoggingEvent> logWatcher;

@BeforeEach
void setup() {
  this.logWatcher = new ListAppender<>();
  this.logWatcher.start();
  ((Logger) LoggerFactory.getLogger(MyClass.class)).addAppender(this.logWatcher);
}


@Test
void myMethod_logs2Messages() {

  ...
  int logSize = logWatcher.list.size();
  assertThat(logWatcher.list.get(logSize - 2).getFormattedMessage()).contains("EXPECTED MSG 1");
  assertThat(logWatcher.list.get(logSize - 1).getFormattedMessage()).contains("EXPECTED MSG 2");
}

归功于：@davidxxx 的回答。查看import ch.qos.logback...详情：https://stackoverflow.com/a/52229629/601844

【讨论】：

【解决方案5】：

一个简单的解决方案是使用 Mockito 模拟 appender（例如）

MyClass.java

@Slf4j
class MyClass {
    public void doSomething() {
        log.info("I'm on it!");
    }
}

MyClassTest.java

import static org.hamcrest.MatcherAssert.assertThat;
import static org.hamcrest.Matchers.containsString;
import static org.hamcrest.Matchers.is;
import static org.mockito.Mockito.verify;         

@RunWith(MockitoJUnitRunner.class)
public class MyClassTest {    

    @Mock private Appender<ILoggingEvent> mockAppender;
    private MyClass sut = new MyClass();    

    @Before
    public void setUp() {
        Logger logger = (Logger) LoggerFactory.getLogger(MyClass.class.getName());
        logger.addAppender(mockAppender);
    }

    @Test
    public void shouldLogInCaseOfError() {
        sut.doSomething();

        verify(mockAppender).doAppend(ArgumentMatchers.argThat(argument -> {
            assertThat(argument.getMessage(), containsString("I'm on it!"));
            assertThat(argument.getLevel(), is(Level.INFO));
            return true;
        }));

    }

}

注意：我使用的是断言而不是返回 false，因为它使代码和（可能的）错误更易于阅读，但如果您有多个验证，它将不起作用。在这种情况下，您需要返回 boolean 指示该值是否符合预期。

【讨论】：

如果我使用像 Slf4j 这样的 lombok.extern.slf4j 注释，这是否有效？如果它甚至不是我的类中的对象，你如何模拟或监视记录器？即 log.error 仅通过在我的类上提供注释 Slf4j 来使用...
@ennth 它应该可以工作，因为您正在使用静态方法 LoggerFactory.getLogger().addAppender(mockAppender) 注入模拟。当您使用 Lombok 创建记录器时，其工作方式相同
有同样的不工作问题。 Logger 和 LoggerFactory 类的“导入”是什么？为什么列出了静态导入而没有列出其他导入？

【解决方案6】：

虽然创建自定义 logback appender 是一个很好的解决方案，但这只是第一步，你最终将开发/重新发明 slf4j-test，如果你走得更远一点：spf4j-slf4j-test 或其他我不知道的框架还不知道。

您最终将需要担心您在内存中保留了多少事件，在记录错误（而不是断言）时使单元测试失败，在测试失败时提供调试日志等等......

免责声明：我是 spf4j-slf4j-test 的作者，我编写这个后端是为了能够更好地测试 spf4j，这是一个很好的地方来查看如何使用 spf4j-slf4j-test 的示例。我实现的主要优势之一是减少了构建输出（Travis 限制了它），同时在发生故障时仍然拥有我需要的所有细节。

【讨论】：

【解决方案7】：

我会推荐一个简单、可重用的间谍实现，它可以作为 JUnit 规则包含在测试中：

public final class LogSpy extends ExternalResource {

    private Logger logger;
    private ListAppender<ILoggingEvent> appender;

    @Override
    protected void before() {
        appender = new ListAppender<>();
        logger = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); // cast from facade (SLF4J) to implementation class (logback)
        logger.addAppender(appender);
        appender.start();
    }

    @Override
    protected void after() {
        logger.detachAppender(appender);
    }

    public List<ILoggingEvent> getEvents() {
        if (appender == null) {
            throw new UnexpectedTestError("LogSpy needs to be annotated with @Rule");
        }
        return appender.list;
    }
}

在您的测试中，您将通过以下方式激活间谍：

@Rule
public LogSpy log = new LogSpy();

调用log.getEvents()（或其他自定义方法）来检查记录的事件。

【讨论】：

为了使其工作，您需要import ch.qos.logback.classic.Logger; 而不是import org.slf4j.LoggerFactory; 否则addAppender() 不可用。我花了一段时间才弄清楚这一点。
对我不起作用。看起来好像规则没有正确应用：在调试时我发现 before() 和 after() 从未达到，因此从未创建/附加附加程序并且 UnexpectedTestError 触发。任何想法我做错了什么？规则是否需要放入某个包中？另外，请将导入部分添加到您的答案中，因为某些对象/接口的名称不明确。

【解决方案8】：

我在测试日志行时遇到问题，例如：LOGGER.error(message, exception)。

http://projects.lidalia.org.uk/slf4j-test/ 中描述的解决方案也尝试对异常进行断言，并且重新创建堆栈跟踪并不容易（在我看来毫无价值）。

我是这样解决的：

import org.junit.Test;
import org.slf4j.Logger;
import uk.org.lidalia.slf4jext.LoggerFactory;
import uk.org.lidalia.slf4jtest.TestLogger;
import uk.org.lidalia.slf4jtest.TestLoggerFactory;

import static org.assertj.core.api.Assertions.assertThat;
import static org.assertj.core.groups.Tuple.tuple;
import static uk.org.lidalia.slf4jext.Level.ERROR;
import static uk.org.lidalia.slf4jext.Level.INFO;


public class Slf4jLoggerTest {

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


    private void methodUnderTestInSomeClassInProductionCode() {
        LOGGER.info("info message");
        LOGGER.error("error message");
        LOGGER.error("error message with exception", new RuntimeException("this part is not tested"));
    }





    private static final TestLogger TEST_LOGGER = TestLoggerFactory.getTestLogger(Slf4jLoggerTest.class);

    @Test
    public void testForMethod() throws Exception {
        // when
        methodUnderTestInSomeClassInProductionCode();

        // then
        assertThat(TEST_LOGGER.getLoggingEvents()).extracting("level", "message").contains(
                tuple(INFO, "info message"),
                tuple(ERROR, "error message"),
                tuple(ERROR, "error message with exception")
        );
    }

}

这还具有不依赖 Hamcrest 匹配器库的优势。

【讨论】：

【解决方案9】：

这是使用 lambdas 的替代方法，它使日志捕获逻辑在测试中可重用（封装其实现）并且不需要@BeforeEach/@AfterEach（在某些建议的解决方案中，附加程序未分离，这可以导致内存泄漏）。

被测代码：

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

public class MyService {

    private static final Logger LOG = LoggerFactory.getLogger(MyService.class);


    public void doSomething(String someInput) {
        ...
        LOG.info("processing request with input {}", someInput);
        ...
    }
}

拦截器助手：

package mypackage.util

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

import java.util.List;

public class LogInterceptor {

    public static List<ILoggingEvent> interceptLogs(Class<?> klass, Runnable runnable) {
        final Logger logger = (Logger) LoggerFactory.getLogger(klass);
        final ListAppender<ILoggingEvent> listAppender = new ListAppender<>();
        listAppender.start();
        logger.addAppender(listAppender);
        try {
            runnable.run();
            return listAppender.list;
        } finally {
            logger.detachAppender(listAppender);
        }
    }
}

测试套件：


import static mypackage.util.LogInterceptor.interceptLogs;

public class MyServiceTest {

  private MyService myService; 
  ...

  @Test
  void doSomethingLogsLineWithTheGivenInput() {
        List<ILoggingEvent> logs = interceptLogs(
                myService.getClass(),
                () -> myService.doSomething("foo")
        );

        assertThat(logs).isNotEmpty();
        ILoggingEvent logEntry = logs.get(0);
        assertThat(logEntry.getFormattedMessage()).isEqualTo("Processing request with input foo");
        assertThat(logEntry.getLevel()).isEqualTo(Level.INFO);
  }

}

【讨论】：