How to intercept SLF4J (with logback) logging via a JUnit test?

有没有可能以某种方式拦截日志记录(SLF4J + logback) ,并通过 JUnit 测试用例获得 InputStream(或其他可读的内容) ... ?

115776 次浏览

您可以创建一个自定义的 appender

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-请参阅注释部分的推理。

可以使用 http://projects.lidalia.org.uk/slf4j-test/中的 slf4j-test。 It replaces the entire logback slf4j implementation by it's own slf4j api implementation for tests and provides an api to assert against logging events.

example:

<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();
}
}

我在测试日志行时遇到了一些问题,比如: Error (消息,异常)

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

I resolved in this way:

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 匹配者库。

The Slf4j API doesn't provide such a way but Logback provides a simple solution.

您可以使用 ListAppender: 一个白盒 logback appender,其中将日志条目添加到 public List字段中,我们可以使用该字段来进行断言。

这里有一个简单的例子。

Foo class :

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/断言库用作 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));

尽管创建一个自定义 logback appender 是一个很好的解决方案,但这只是第一步,您最终将开发/重新发明 Slf4j 测试,如果您更进一步的话: Spf4j-slf4j-test或其他我还不知道的框架。

您最终将需要考虑在内存中保留多少事件、在记录错误(而不是断言)时单元测试失败、在测试失败时使调试日志可用等等。.

免责声明: 我是 spf4j-slf4j-test 的作者,我编写这个后端是为了能够更好地测试 Spf4j,这是一个很好的地方来查看如何使用 spf4j-slf4j-test 的例子。我获得的主要优势之一是减少了我的构建输出(这是有限的与特拉维斯) ,同时仍然有所有的细节,我需要当失败发生时。

A simple solution could be to mock the appender with Mockito (for example)

MyClass.java

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

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,指示该值是否与预期的一样。

我推荐一个简单的、可重用的间谍实现,它可以作为 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()(或其他自定义方法)来检查记录的事件。

和 JUnit5一起

private ListAppender<ILoggingEvent> logWatcher;


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

注意: MyClass.class-应该是您的 Prod 类,您希望从

use: (AssertJ example)

@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");
}

毁灭:

为了获得更好的性能,建议分离:

@AfterEach
void teardown() {
((Logger) LoggerFactory.getLogger(MyClass.class)).detachAndStopAllAppenders();
}

进口:

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

感谢:@davidxxx 的回答

这是使用 lambdas 的一种替代方法,它使得日志捕获逻辑在测试中可重用(封装其实现) ,并且不需要 @BeforeEach/@AfterEach(在一些提议的解决方案中,appender 没有分离,这可能导致内存泄漏)。

测试中的密码:

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);
...
}
}


Interceptor helper:

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);
}


}