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

Is it possible to somehow intercept the logging (SLF4J + logback) and get an InputStream (or something else that is readable) via a JUnit test case...?

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

You can use ListAppender : a whitebox logback appender where log entries are added in a public List field that we could use to make our assertions.

Here is a simple example.

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 class :

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

You can also use Matcher/assertion libraries as AssertJ or Hamcrest.

With AssertJ it would be :

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

You can create a custom appender

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

and configure logback-test.xml to use it. Now we can check logging events from our test:

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

NOTE: Use ILoggingEvent if you do not get any output - see the comment section for the reasoning.

You can use slf4j-test from http://projects.lidalia.org.uk/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();
    }
}

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

---

credits to: @davidxxx's answer. See it for import ch.qos.logback... details: https://stackoverflow.com/a/52229629/601844

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

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

    }

}

NOTE: I'm using assertion rather than returning false as it makes code and (possible) error easier to read, but it won't work if you have multiple verifications. In that case you need to return boolean indicating if the value is as expected.

Although creating a custom logback appender is a good solution, it is only the first step, you will eventually end up developing/reinventing slf4j-test, and if you go a bit further: spf4j-slf4j-test or other frameworks that I don't know of yet.

You will eventually need to worry about how many events you keep in memory, fail unit tests when a error is logged (and not asserted), make debug logs available on test failure, etc...

Disclaimer: I am the author of spf4j-slf4j-test, I wrote this backend to be able to better test spf4j, which is a good place to look at for examples on how to use spf4j-slf4j-test. One of the main advantages I achieved was reducing my build output (which is limited with Travis), while still having all the detail I need when failure happens.

I would recommend a simple, reusable spy implementation that can be included in a test as JUnit rule:

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

In your test, you'd activate the spy in the following way:

@Rule
public LogSpy log = new LogSpy();

Call log.getEvents() (or other, custom methods) to check the logged events.

I had problems when testing logs line like: LOGGER.error(message, exception).

The solution described in http://projects.lidalia.org.uk/slf4j-test/ tries to assert as well on the exception and it is not easy (and in my opinion worthless) to recreate the stacktrace.

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

}

This has as well the advantage to not having depend on Hamcrest matchers library.

This is an alternative using lambdas that makes the log capturing logic reusable among tests (encapsulating its implementation) and doesn't require @BeforeEach/@AfterEach (in some of the proposed solutions the appender is not detached, which can lead to memory leaks).

Code under test:

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

Test suite:

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

}