What is the best way to unit-test SLF4J log messages?

Question

I'm using slf4j and I want to unit test my code to make sure that warn/error log messages are generated under certain conditions. I'd rather these be strict unit tests, so I'd prefer not to have to pull up logging configuration from a file in order to test that the log messages are generated. The mocking framework I'm using is Mockito.

Anhanhalt

Since SLF4J is just a "facade" for other logging implementations, you cannot unit test it just by itself, you also have to specify the implementation you're using. – Burnout

@Burnout - Not true. I could add a setter to my class to pass in the logger from the test, then pass in a mocked out Logger instance and verify that the appropriate log calls were made. I was just hoping to get a more elegant solution than adding a set method just for testing and making my Logger instance non-final. – Anhanhalt

As an aside, the generally excellent "Growing Object Oriented Software" book has a chapter on unit testing of logging. It's not entirely convincing, but it's certainly well-thought-out, and worth a read (amazon.co.uk/Growing-Object-Oriented-Software-Guided-Signature/…) – Medicinal

Hi, I found the following article mincong.io/2020/02/02/logback-test-logging-event very helpful as an answer to your question – Eldreeda

Answer 1

I think you could solve your problem with a custom appender. Create a test appender which implements the org.apache.log4j.Appender, and set your appender in the log4j.properties and load it when you execute test cases.

If you call back to the test harness from that appender you can check the logged messages

Hurlburt

It would be greatly appreciated if you can offer some code samples. – Gambado

but it seems that this example doesn't work for slf4j! – Billmyre

Answer 2

Create a test rule:

    import ch.qos.logback.classic.Logger;
    import ch.qos.logback.classic.spi.ILoggingEvent;
    import ch.qos.logback.core.read.ListAppender;
    import org.junit.rules.TestRule;
    import org.junit.runner.Description;
    import org.junit.runners.model.Statement;
    import org.slf4j.LoggerFactory;
    
    import java.util.List;
    import java.util.stream.Collectors;
    
    public class LoggerRule implements TestRule {
    
      private final ListAppender<ILoggingEvent> listAppender = new ListAppender<>();
      private final Logger logger = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);
    
      @Override
      public Statement apply(Statement base, Description description) {
        return new Statement() {
          @Override
          public void evaluate() throws Throwable {
            setup();
            base.evaluate();
            teardown();
          }
        };
      }
    
      private void setup() {
        logger.addAppender(listAppender);
        listAppender.start();
      }
    
      private void teardown() {
        listAppender.stop();
        listAppender.list.clear();
        logger.detachAppender(listAppender);
      }
    
      public List<String> getMessages() {
        return listAppender.list.stream().map(e -> e.getMessage()).collect(Collectors.toList());
      }
    
      public List<String> getFormattedMessages() {
        return listAppender.list.stream().map(e -> e.getFormattedMessage()).collect(Collectors.toList());
      }
    
    }

Then use it:

    @Rule
    public final LoggerRule loggerRule = new LoggerRule();
    
    @Test
    public void yourTest() {
        // ...
        assertThat(loggerRule.getFormattedMessages().size()).isEqualTo(2);
    }

----- JUnit 5 with Extension Oct 2021 -----

LogCapture:

import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.filter.LevelFilter;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.classic.spi.LoggingEvent;
import ch.qos.logback.core.filter.Filter;
import ch.qos.logback.core.read.ListAppender;
import ch.qos.logback.core.spi.FilterReply;

import java.util.List;
import java.util.stream.Collectors;

public class LogCapture {

  private ListAppender<ILoggingEvent> listAppender = new ListAppender<>();

  LogCapture() {
  }

  public String getFirstFormattedMessage() {
    return getFormattedMessageAt(0);
  }

  public String getLastFormattedMessage() {
    return getFormattedMessageAt(listAppender.list.size() - 1);
  }

  public String getFormattedMessageAt(int index) {
    return getLoggingEventAt(index).getFormattedMessage();
  }

  public LoggingEvent getLoggingEvent() {
    return getLoggingEventAt(0);
  }

  public LoggingEvent getLoggingEventAt(int index) {
    return (LoggingEvent) listAppender.list.get(index);
  }

  public List<LoggingEvent> getLoggingEvents() {
    return listAppender.list.stream().map(e -> (LoggingEvent) e).collect(Collectors.toList());
  }

  public void setLogFilter(Level logLevel) {
    listAppender.clearAllFilters();
    listAppender.addFilter(buildLevelFilter(logLevel));
  }

  public void clear() {
    listAppender.list.clear();
  }

  void start() {
    setLogFilter(Level.INFO);
    listAppender.start();
  }

  void stop() {
    if (listAppender == null) {
      return;
    }

    listAppender.stop();
    listAppender.list.clear();
    listAppender = null;
  }

  ListAppender<ILoggingEvent> getListAppender() {
    return listAppender;
  }

  private Filter<ILoggingEvent> buildLevelFilter(Level logLevel) {
    LevelFilter levelFilter = new LevelFilter();
    levelFilter.setLevel(logLevel);
    levelFilter.setOnMismatch(FilterReply.DENY);
    levelFilter.start();

    return levelFilter;
  }

}

LogCaptureExtension:

import ch.qos.logback.classic.Logger;
import org.junit.jupiter.api.extension.AfterTestExecutionCallback;
import org.junit.jupiter.api.extension.ExtensionContext;
import org.junit.jupiter.api.extension.ParameterContext;
import org.junit.jupiter.api.extension.ParameterResolver;
import org.slf4j.LoggerFactory;

public class LogCaptureExtension implements ParameterResolver, AfterTestExecutionCallback {

  private Logger logger = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);

  private LogCapture logCapture;

  @Override
  public boolean supportsParameter(ParameterContext parameterContext, ExtensionContext extensionContext) {
    return parameterContext.getParameter().getType() == LogCapture.class;
  }

  @Override
  public Object resolveParameter(ParameterContext parameterContext, ExtensionContext extensionContext) {
    logCapture = new LogCapture();

    setup();

    return logCapture;
  }

  @Override
  public void afterTestExecution(ExtensionContext context) {
    teardown();
  }

  private void setup() {
    logger.addAppender(logCapture.getListAppender());
    logCapture.start();
  }

  private void teardown() {
    if (logCapture == null || logger == null) {
      return;
    }

    logger.detachAndStopAllAppenders();
    logCapture.stop();
  }

}

then use it:

@ExtendWith(LogCaptureExtension.class)
public class SomeTest {

  @Test
  public void sometest(LogCapture logCapture)  {
    // do test here

    assertThat(logCapture.getLoggingEvents()).isEmpty();
  }

  // ...
}

Dzoba

this is a clever solution! – Coterminous

This is a very cool generic solution. I ran into dependency hell having to exclude logback-classic in hundred different places with the slf4j-test approach, but this solves it elegantly without having to resort to reflection or changing the production code. – Froh

Any JUnit5 equivalent ? – Haroldharolda

Useful and working solution! Thank you for sharing this! – Bespectacled

Is there any reason, why you cast ILoggingEvent to LoggingEvent? For my usage, I don't need the setters from LoggingEvent. The getters suits perfectly for me. – Cyclostome

Could you please add the corresponding imports? While juggling with loggers and libraries, it doesn't help to not know where Logger or Level is supposed to come from, for example – Pinelli

@EricDuminil my need as well, so added them now – Georgiannegeorgic

Answer 3

For testing slf4j without relying on a specific implementation (such as log4j), you can provide your own slf4j logging implementation as described in this SLF4J FAQ. Your implementation can record the messages that were logged and then be interrogated by your unit tests for validation.

The slf4j-test package does exactly this. It's an in-memory slf4j logging implementation that provides methods for retrieving logged messages.

Energumen

Complete example using lidalia's slf4j-test package can be found here: github.com/jaegertracing/jaeger-client-java/pull/378/files. Admittedly, their documentation is quite wonderful as well. – Merimerida

This no longer works with slf4j-api version 1.8 or higher because: "Planning for the advent of Jigsaw (Java 9), slf4j-api version 1.8.x and later use the ServiceLoader mechanism. Earlier versions of SLF4J relied on the static binder mechanism which is no longer honored by slf4j-api." (see slf4j.org/codes.html). – Attaint

Answer 4

For JUnit 5, create an extension that implements the solution provided by andrew-feng above in Create a test rule:

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;
import org.junit.jupiter.api.extension.AfterEachCallback;
import org.junit.jupiter.api.extension.BeforeEachCallback;
import org.junit.jupiter.api.extension.ExtensionContext;
import org.slf4j.LoggerFactory;

import java.util.List;
import java.util.stream.Collectors;

public class LoggerExtension implements BeforeEachCallback, AfterEachCallback {

    private final ListAppender<ILoggingEvent> listAppender = new ListAppender<>();
    private final Logger logger = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME);

    @Override
    public void afterEach(ExtensionContext extensionContext) throws Exception {
        listAppender.stop();
        listAppender.list.clear();
        logger.detachAppender(listAppender);
    }

    @Override
    public void beforeEach(ExtensionContext extensionContext) throws Exception {
        logger.addAppender(listAppender);
        listAppender.start();
    }

    public List<String> getMessages() {
        return listAppender.list.stream().map(e -> e.getMessage()).collect(Collectors.toList());
    }

    public List<String> getFormattedMessages() {
        return listAppender.list.stream().map(e -> e.getFormattedMessage()).collect(Collectors.toList());
    }
}

Then use it:

class SomeTestClass {
    
    @RegisterExtension
    public LoggerExtension loggerExtension = new LoggerExtension();
            
    @Test
    public void yourTest() {
        // ...
        assertThat(loggerExtension.getFormattedMessages().size()).isEqualTo(2);
    }
}

Sculpt

Or you can just use the following statements at the start of the test: Logger logger = (Logger) LoggerFactory.getLogger(Logger.ROOT_LOGGER_NAME); ListAppender<ILoggingEvent> listAppender = new ListAppender<>(); logger.addAppender(listAppender); listAppender.start(); And then at the end of the test assert: List<ILoggingEvent> logsList = listAppender.list; assertEquals(...,logsList.get(1)) – Splenectomy

Answer 5

A better test implementation of SLF4J that works really well in an environment with concurrent test execution is https://github.com/portingle/slf4jtesting

I've chimed in on a few discussion on slf4j log testing and the limitations of existing test approaches when it comes to concurrent test execution.

I decided to put my words into code and that git repo is the result.

Legator

Hopefully soon a third answer will appear from someone who has an even better test implementation of SLF4j.... ;) – Polyhistor

Imo, this is not a good utility. It only works if the Logger is created within the constructor. But who does that? The Logger is normally a constant: private static final Logger LOGGER = LoggerFactory.getLogger(Example.class). The utility can't handle constant loggers and therefore normal use cases. – Dela

You can "solve"t this with an overloaded constructor (next comment will be java example code) – Serif

package com.me.hello; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import javax.inject.Inject; public final class MyThing { public static final String ERROR_MSG_LOGGER_IS_NULL = "Logger is null"; private Logger logger; @Inject public MyThing() { this(LoggerFactory.getLogger(MyThing.class)); } public MyThing(final Logger lgr) { if (null == lgr) { throw new IllegalArgumentException(ERROR_MSG_LOGGER_IS_NULL); } this.logger = lgr; } } – Serif

That's a really common pattern for these kinds of things, not just loggers but really anywhere that you want a final but don't want to be forced to use constructor injection for everything. It's a pattern I use as often as needed. – Philis

Answer 6

Instead of mocking SLF4J you could place the important logging calls you need to test inside their own methods which you can mock more easily.

If you really want to mock SLF4J, I would bet you could create your own provider for it that would allow you to supply a mock logger from the SLF4J side instead of injecting one in your service objects.

Pierrette

Answer 7

Using slf4j-test can remove lot of workarounds discussed above

pom.xml

 <dependency>
       <groupId>uk.org.lidalia</groupId>
       <artifactId>slf4j-test</artifactId>
       <version>1.2.0</version>
 </dependency>

Sample class

@Slf4j
public class SampleClass {

    public void logDetails(){
        log.info("Logging");
    }
}

TestClass

import org.junit.Test;
import uk.org.lidalia.slf4jtest.TestLogger;
import uk.org.lidalia.slf4jtest.TestLoggerFactory;

import static java.util.Arrays.asList;
import static org.hamcrest.Matchers.is;
import static org.junit.Assert.assertThat;
import static uk.org.lidalia.slf4jtest.LoggingEvent.info;

public class SampleClassTest {

    TestLogger logger = TestLoggerFactory.getTestLogger(SampleClass.class);

    @Test
    public void testLogging(){
        SampleClass sampleClass = new SampleClass();
        //Invoke slf4j logger
        sampleClass.logDetails();

        assertThat(logger.getLoggingEvents(), is(asList(info("Logging"))));

    }

}

Refer http://projects.lidalia.org.uk/slf4j-test/ for more details

Fibrinogen

To make it work , user should add below line : ``` ImmutableList<LoggingEvent> loggingEvents = logger.getLoggingEvents(); ImmutableList<Object> arguments = loggingEvents.get(0).getArguments(); String actual = MessageFormatter.arrayFormat(loggingEvents.get(0).getMessage(), arguments.toArray()).getMessage(); ``` – Lambrequin

Answer 8

This solution has been mentioned already before in this groovy answer as well as in this comment, but as I don't see it as an answer itself, adding it here as a community wiki answer.

So JUnit5 solution using logback listappender:

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

import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.slf4j.LoggerFactory;

public class LoggingTest {
  private final ClassToTest sut = new ClassToTest();

  private ListAppender<ILoggingEvent> listAppender;

  @BeforeEach
  void init() {
    final var log = (Logger) LoggerFactory.getLogger(ClassToTest.class);

    listAppender = new ListAppender<>();
    listAppender.start();

    log.addAppender(listAppender);
  }

  @Test
  public void testLogging() {
    sut.doSomethingThatLogs()
    String message = listAppender.list.get(0).getFormattedMessage();
    assertThat(message).contains("this message should be logged");
  }
}

Georgiannegeorgic

Answer 9

Similar to @Zsolt, you can mock log4j Appender and set it on the Logger, then verify calls to Appender.doAppend(). This allows you to test without having to modify the real code.

Cocainism

Answer 10

You can try another library to support easy mocking slf4j loggers - slf4j-mock, your code cen be look as:

import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.InjectMocks;
import org.mockito.Mock;
import org.mockito.Mockito;
import org.mockito.junit.MockitoJUnitRunner;
import org.slf4j.Logger;

@RunWith(MockitoJUnitRunner.class)
public class JUnit4ExampleTest {

    private static final String INFO_TEST_MESSAGE = "info log test message from JUnit4";

    @Mock
    Logger logger;

    @InjectMocks
    Example sut;

    @Test
    public void logInfoShouldBeLogged() {

        // when
        sut.methodWithLogInfo(INFO_TEST_MESSAGE);

        // then
        Mockito.verify(logger).info(INFO_TEST_MESSAGE);
        Mockito.verifyNoMoreInteractions(logger);
    }
}

As you see you don't need any special steps, in test code. You need only add dependency to library in your project.

More examples and instructions at:

https://www.simplify4u.org/slf4j-mock/

Amerind

SLF4J: Actual binding is of type [ch.qos.logback.classic.util.ContextSelectorStaticBinder] java.lang.ClassCastException: ch.qos.logback.classic.Logger cannot be cast to org.simplify4u.slf4jmock.ProxyMock – Illfavored

Answer 11

This is my implementation (Java 11+, Junit 5, using Lombok's @Slf4j in the ClassWithALogger), my requirements being for the logger to be reset between tests.

// because the specific imports matter:
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 static org.assertj.core.api.Assertions.assertThat;

private ListAppender<ILoggingEvent> listAppender;
private final Logger staticLogger = (Logger) LoggerFactory.getLogger(ClassWithALogger.class);

@BeforeEach
public void init() {
    listAppender = new ListAppender<>();
    listAppender.start();
    staticLogger.addAppender(listAppender);
}

@AfterEach
public void tearDown() {
    staticLogger.detachAppender(listAppender);
    listAppender.stop();
}

@Test
void myTest() {
    // given
    // when
    // then
    Set<String> messages = listAppender.list.stream()
            .map(ILoggingEvent::getFormattedMessage)
            .collect(Collectors.toSet());
    assertThat(messages).contains("the message I expect to be logged");
}

Shaniqua

Answer 12

I have a new answer that I will post at the top in this post (My "old" answer is still at the bottom of this post) (At the time of writing my "old" answer was a "0", so no harm, no foul! )

Newer answer:

Here is the Gradle Package:

  testImplementation 'com.portingle:slf4jtesting:1.2.0'

Maven Link:

https://mvnrepository.com/artifact/com.portingle/slf4jtesting

Germane Code:

(below imports and private method would go in MyTestClass(.java))

import static org.junit.Assert.assertNotNull;

import slf4jtest.LogLevel;
import slf4jtest.Settings;
import slf4jtest.TestLogger;
import slf4jtest.TestLoggerFactory;



@Test
public void myFirstTest() {


    org.slf4j.Logger unitTestLogger = this.getUnitTestLogger();
    ISomethingToTestObject testItem = new SomethingToTestObject (unitTestLogger);
    SomeReturnObject obj = testItem.myMethod("arg1");
    assertNotNull(wrapper);

    /* now here you would find items in the unitTestLogger */

    assertContains(unitTestLogger, LogLevel.DebugLevel, "myMethod was started");

}

// render nicer errors
private void assertContains(TestLogger unitTestLogger, LogLevel logLev, String expected) throws Error {
    if (!unitTestLogger.contains(logLev, expected)) {
        throw new AssertionError("expected '" + expected + "' but got '" + unitTestLogger.lines() + "'");
    }
}

// render nicer errors
private void assertNotContains(TestLogger unitTestLogger, LogLevel logLev, String expected) throws Error {
    if (unitTestLogger.contains(logLev, expected)) {
        throw new AssertionError("expected absence of '" + expected + "' but got '" + unitTestLogger.lines() + "'");
    }
}



    private TestLogger getUnitTestLogger() {
        TestLoggerFactory loggerFactory = Settings.instance()
                .enableAll() // necessary as by default only ErrorLevel is enabled
                .buildLogging();

        TestLogger returnItem = loggerFactory.getLogger(MyTestClasss.class.getName());
        assertNotNull(returnItem);
        return returnItem;
    }

============================= OLD ANSWER BELOW .. DO NOT USE================

Below is my previous answer. I changed my below code ... to use the above package after I discovered it (the above package).

So here is my method.

First, I allow the logger to be injected.  But I provide a default as well:

```java
package com.mycompany.myproject;

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

public class MyCoolClass { //implements IMyCoolClass {

    private static final String PROCESS_STARTED = "Process started. (key='%1$s')";

    private final Logger logger;

    public MyCoolClass() {
        this(LoggerFactory.getLogger(MyCoolClass.class));
    }

    public MyCoolClass(Logger lgr) {
        this.logger = lgr;
    }
        
    public doSomething(int key)
    {
        logger.info(String.format(PROCESS_STARTED, key));
        /*now go do something */
    }
}

Then I wrote a very basic in memory logger


```java
import org.slf4j.Marker;

import java.util.ArrayList;
import java.util.Collection;

public class InMemoryUnitTestLogger implements org.slf4j.Logger {

    public Collection<String> informations = new ArrayList<String>();
    public Collection<String> errors = new ArrayList<String>();
    public Collection<String> traces = new ArrayList<String>();
    public Collection<String> debugs = new ArrayList<>();
    public Collection<String> warns = new ArrayList<>();

    public Collection<String> getInformations() {
        return informations;
    }

    public Collection<String> getErrors() {
        return errors;
    }

    public Collection<String> getTraces() {
        return traces;
    }

    public Collection<String> getDebugs() {
        return debugs;
    }

    public Collection<String> getWarns() {
        return warns;
    }


    @Override
    public String getName() {
        return "FakeLoggerName";
    }

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

    @Override
    public boolean isTraceEnabled(Marker marker) {
        return false;
    }

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

    @Override
    public boolean isDebugEnabled(Marker marker) {
        return false;
    }

    @Override
    public boolean isWarnEnabled(Marker marker) {
        return false;
    }

    @Override
    public boolean isInfoEnabled(Marker marker) {
        return false;
    }

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

    @Override
    public boolean isErrorEnabled(Marker marker) {
        return false;
    }

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

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

    @Override
    public void trace(String s) {
        this.internalTrace(s);
    }

    @Override
    public void trace(String s, Object o) {
        this.internalTrace(s);
    }

    @Override
    public void trace(String s, Object o, Object o1) {
        this.internalTrace(s);
    }

    @Override
    public void trace(String s, Object... objects) {
        this.internalTrace(s);
    }

    @Override
    public void trace(String s, Throwable throwable) {
        this.internalTrace(s);
    }


    @Override
    public void trace(Marker marker, String s) {
        this.internalTrace(s);
    }

    @Override
    public void trace(Marker marker, String s, Object o) {
        this.internalTrace(s);
    }

    @Override
    public void trace(Marker marker, String s, Object o, Object o1) {
        this.internalTrace(s);
    }

    @Override
    public void trace(Marker marker, String s, Object... objects) {
        this.internalTrace(s);
    }

    @Override
    public void trace(Marker marker, String s, Throwable throwable) {
        this.internalTrace(s);
    }

    @Override
    public void debug(String s) {
        this.internalDebug(s);
    }

    @Override
    public void debug(String s, Object o) {
        this.internalDebug(s);
    }

    @Override
    public void debug(String s, Object o, Object o1) {
        this.internalDebug(s);
    }

    @Override
    public void debug(String s, Object... objects) {
        this.internalDebug(s);
    }

    @Override
    public void debug(String s, Throwable throwable) {
        this.internalDebug(s);
    }

    @Override
    public void debug(Marker marker, String s) {
        this.internalDebug(s);
    }

    @Override
    public void debug(Marker marker, String s, Object o) {
        this.internalDebug(s);
    }

    @Override
    public void debug(Marker marker, String s, Object o, Object o1) {
        this.internalDebug(s);
    }

    @Override
    public void debug(Marker marker, String s, Object... objects) {
        this.internalDebug(s);
    }

    @Override
    public void debug(Marker marker, String s, Throwable throwable) {
        this.internalDebug(s);
    }

    public void info(String s) {
        this.internalInfo(s);
    }

    @Override
    public void info(String s, Object o) {
        this.internalInfo(s);
    }

    @Override
    public void info(String s, Object o, Object o1) {
        this.internalInfo(s);
    }

    @Override
    public void info(String s, Object... objects) {
        this.internalInfo(s);
    }

    @Override
    public void info(String s, Throwable throwable) {
        this.internalInfo(s);
    }

    @Override
    public void info(Marker marker, String s) {
        this.internalInfo(s);
    }

    @Override
    public void info(Marker marker, String s, Object o) {
        this.internalInfo(s);
    }

    @Override
    public void info(Marker marker, String s, Object o, Object o1) {
        this.internalInfo(s);
    }

    @Override
    public void info(Marker marker, String s, Object... objects) {
        this.internalInfo(s);
    }

    @Override
    public void info(Marker marker, String s, Throwable throwable) {
        this.internalInfo(s);
    }

    public void error(String s) {
        this.internalError(s);
    }

    @Override
    public void error(String s, Object o) {
        this.internalError(s);
    }

    @Override
    public void error(String s, Object o, Object o1) {
        this.internalError(s);
    }

    @Override
    public void error(String s, Object... objects) {
        this.internalError(s);
    }

    @Override
    public void error(String s, Throwable throwable) {
        this.internalError(s);
    }

    @Override
    public void error(Marker marker, String s) {
        this.internalError(s);
    }

    @Override
    public void error(Marker marker, String s, Object o) {
        this.internalError(s);
    }

    @Override
    public void error(Marker marker, String s, Object o, Object o1) {
        this.internalError(s);
    }

    @Override
    public void error(Marker marker, String s, Object... objects) {
        this.internalError(s);
    }

    @Override
    public void error(Marker marker, String s, Throwable throwable) {
        this.internalError(s);
    }

    public void warn(String s) {
        this.internalWarn(s);
    }

    @Override
    public void warn(String s, Object o) {
        this.internalWarn(s);
    }

    @Override
    public void warn(String s, Object... objects) {
        this.internalWarn(s);
    }

    @Override
    public void warn(String s, Object o, Object o1) {
        this.internalWarn(s);
    }

    @Override
    public void warn(String s, Throwable throwable) {
        this.internalWarn(s);
    }

    @Override
    public void warn(Marker marker, String s) {
        this.internalWarn(s);
    }

    @Override
    public void warn(Marker marker, String s, Object o) {
        this.internalWarn(s);
    }

    @Override
    public void warn(Marker marker, String s, Object o, Object o1) {
        this.internalWarn(s);
    }

    @Override
    public void warn(Marker marker, String s, Object... objects) {
        this.internalWarn(s);
    }

    @Override
    public void warn(Marker marker, String s, Throwable throwable) {
        this.internalWarn(s);
    }

    private void internalDebug(String s) {
        System.out.println(s);
        this.debugs.add(s);
    }

    private void internalInfo(String msg) {
        System.out.println(msg);
        this.informations.add(msg);
    }

    private void internalTrace(String msg) {
        //??System.out.println(msg);
        this.traces.add(msg);
    }


    private void internalWarn(String msg) {
        System.err.println(msg);
        this.warns.add(msg);
    }

    private void internalError(String msg) {
        System.err.println(msg);
        this.errors.add(msg);
    }

Then in my unit tests, I can do one of two things:

private ByteArrayOutputStream setupSimpleLog(Logger lgr) {
    ByteArrayOutputStream pipeOut = new ByteArrayOutputStream();
    PrintStream pipeIn = new PrintStream(pipeOut);
    System.setErr(pipeIn);
    return pipeOut;
}

private Logger getSimpleLog() {
    Logger lgr = new InMemoryUnitTestLogger();
    return lgr;
}


private void myTest() {


    Logger lgr = getSimpleLog();
    ByteArrayOutputStream pipeOut = this.setupSimpleLog(lgr);

    MyCoolClass testClass = new MyCoolClass(lgr);
    int myValue = 333;
    testClass.doSomething(myValue);

    String findMessage = String.format(MyCoolClass.PROCESS_STARTED, myValue);
    String output = new String(pipeOut.toByteArray());
    assertTrue(output.contains(findMessage));
}

or similar to the above, but do a cast on the custom Logger

private void myTest() {


    Logger lgr = getSimpleLog();
    MyCoolClass testClass = new MyCoolClass(lgr);
    int myValue = 333;
    testClass.doSomething(myValue);

    String findMessage = String.format(MyCoolClass.PROCESS_STARTED, myValue);
    InMemoryUnitTestLogger castLogger = (InMemoryUnitTestLogger)lgr;
    /* now check the exact subcollection for the message) */
    assertTrue(castLogger.getInfos().contains(findMessage));
}

Take the code with a grain of salt, the ideas are there. I didn't compile the code.

Serif

Answer 13

Just use plain Mockito and some reflection logic to mock it:

// Mock the Logger
Logger mock = Mockito.mock(Logger.class);
// Set the Logger to the class you want to test. 
// Since this is often a private static field you have to 
// hack a little bit: (Solution taken from https://mcmap.net/q/24707/-change-private-static-final-field-using-java-reflection)
setFinalStatic(ClassBeeingTested.class.getDeclaredField("log"), mock);

with setFinalStatic method beeing

public static void setFinalStatic(Field field, Object newValue) throws Exception {
    field.setAccessible(true);

    Field modifiersField = Field.class.getDeclaredField("modifiers");
    modifiersField.setAccessible(true);
    modifiersField.setInt(field, field.getModifiers() & ~Modifier.FINAL);

    field.set(null, newValue);
 }    

Then just execute the to be tested code and verify - e.g. the following verifies that the Logger.warn method was called twice:

    ArgumentCaptor<String> argumentCaptor = ArgumentCaptor.forClass(String.class);
    Mockito.verify(mock,Mockito.atLeastOnce()).warn(argumentCaptor.capture());
    List<String> allValues = argumentCaptor.getAllValues();
    assertEquals(2, allValues.size());
    assertEquals("myFirstExpectedMessage", allValues.get(0));
    assertEquals("mySecondExpectedMessage", allValues.get(1));

Please note that setting the final fields via reflection does not work in all cases. I was for example not able to get it working if multiple testcases were trying to modify it.

Leroi

This will not work anymore in Java 12. Been there, done that … it's exactly the pattern above that i'm on a quest to replace which brought me here. – Evelinaeveline

Answer 14

I needed to get this to work without using ch.qos.logback because that was conflicting with the usage of log4j2 in my main classes.

Hat tip to https://codingcraftsman.wordpress.com/2015/04/28/log4j2-mocking-with-mockito-and-junit/ for showing how to do it.

The thing that made a difference for me was casting the logger in the mocks to the logger from org.apache.logging.log4j.core.Logger, I was able to add an appender to it and it didn't break the rest of my code.

Pasting his code here for answer completeness.

import java.io.IOException;
  
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.Logger;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.ArgumentCaptor;
import org.mockito.Captor;
import org.mockito.Mock;
import org.mockito.runners.MockitoJUnitRunner;
  
import static org.junit.Assert.*;
import static org.mockito.Mockito.*;

@RunWith(MockitoJUnitRunner.class)
public class ExceptionLoggerTest {
  @Mock
  private Appender mockAppender;
  
  private List<LogEvent> capturedEvents = new ArrayList<>();
  
  private Logger logger;
  
  @Before
  public void setup() {
    // prepare the appender so Log4j likes it
    when(mockAppender.getName()).thenReturn("MockAppender");
    when(mockAppender.isStarted()).thenReturn(true);
    when(mockAppender.isStopped()).thenReturn(false);
  
    // when append is called, convert the event to 
    // immutable and add it to the event list
    doAnswer(answerVoid((LogEvent event) -> 
                  capturedEvents.add(event.toImmutable()))
      .when(mockAppender).append(any());
  
    logger = (Logger)LogManager.getLogger(ExceptionLogger.class);
    logger.addAppender(mockAppender);
    logger.setLevel(Level.INFO);
  }
  
  @After /** as before */
  
  @Test
  public void loggingIsCaptured() {
    logger.error("What an error");
    verifyErrorMessages("What an error");
  }
  
  // inspecting messages involves just using the list of captured events
  private void verifyErrorMessages(String ... messages) {
    assertThat(capturedEvents.size(), is(messages.length));
  
    int i=0;
    for(LogEvent loggingEvent:capturedEvents) {
      assertEquals(messages[i++], 
        loggingEvent.getMessage().getFormattedMessage());
    }
  }
}

Loar

Answer 15

I've created a library to help unit tests to assert that certain messages are/not logged at various log levels.

https://github.com/nalbion/test-appender

...
import io.github.nalbion.TestAppender;
import org.junit.jupiter.api.Test;

class MyTest {
    private final TestAppender testAppender = new TestAppender(true);

    @BeforeEach
    void setup() {
        testAppender.start();
    }

    @Test
    void myTest() {
        // When
        new MyApplication().doSomething();

        // Then
        // Check all logs match a multi-line string
        testAppender.assertLogs("""
                Hello World!
                My application calls log.info() twice.""");

        // Check that only some lines are logged at WARN
        testAppender.assertLogs(Level.WARN, "My application calls log.info() twice.");

        // Check that at least one of the lines matches a Predicate
        testAppender.assertAnyLogs(
                TestAppender.atLogLevel(Level.INFO)
                        .and(e -> e.getFormattedMessage().matches("Hello .*!"))
        );

        testAppender.assertNoLogs(e -> e.getFormattedMessage().matches("Password: .*!"));
    }

    @Test
    void dynamicValues() {
        // When
        logger.info("The time is {}", new SimpleDateFormat("HH:mm").format(new Date()));
        
        // Then
        // Handle dynamic values - date/time, random values
        testAppender.assertLogs(line -> line.replaceFirst("\\b\\d{1,2}:\\d{2}\\b", "hh:mm"),
                "The time is hh:mm");     
    }
}

Carlyle

Answer 16

I have created LogCaptor specifically for this use case, which should do the trick of easily capturing logs without the need for mocking for example. It can capture logs generated by SLF4J, Log4J2, Java Util Logging, JBoss Logging, Google Flogger and with Lombok annotations. See below for an example code snippet with the unit test:

Example situation:

public class FooService {

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

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

}

Example unit test with usage of 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!");
    }
}

I wasn't quite sure if I should post this here, because it could also be seen as a way to promote "my library" but I thought it could be helpful for developers who have the same challenges.

Renown

Answer 17

I know it's been a while since this question was posted but I just came across a similar issue and my solution may help. Along the lines of the solution proposed by @Zsolt, we use an appender, more specifically Logback's ListAppender. Showing the code and configurations here (Groovy code but can be easily ported to Java):

Groovy class for log access:

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

class LogAccess {

    final static String DEFAULT_PACKAGE_DOMAIN = Logger.ROOT_LOGGER_NAME
    final static String DEFAULT_APPENDER_NAME = 'LIST'
    final List<LoggingEvent> list

    LogAccess(String packageDomain = DEFAULT_PACKAGE_DOMAIN, String appenderName = DEFAULT_APPENDER_NAME) {
        Logger logger = (Logger) LoggerFactory.getLogger(packageDomain)
        ListAppender<LoggingEvent> appender = logger.getAppender(appenderName) as ListAppender<LoggingEvent>
        if (appender == null) {
            throw new IllegalStateException("'$DEFAULT_APPENDER_NAME' appender not found. Did you forget to add 'logback.xml' to the resources folder?")
        }
        this.list = appender.list
        this.clear()
    }

    void clear() {
        list.clear()
    }

    boolean contains(String logMessage) {
        return list.reverse().any { it.getFormattedMessage() == logMessage }
    }

    @Override
    String toString() {
        list.collect { it. getFormattedMessage() }
    }
}

Sample logback.xml config:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- These 2 'includes' tags ensure regular springboot console logging works as usual -->
    <!-- See https://docs.spring.io/spring-boot/docs/current/reference/html/howto.html#howto-configure-logback-for-logging -->
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml" />
    <appender name="LIST" class="ch.qos.logback.core.read.ListAppender"/>
    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="LIST" />
    </root>
</configuration>

Test:

LogAccess log = new LogAccess()
def expectedLogEntry = 'Expected Log Entry'
assert !log.contains(expectedLogEntry)
methodUnderTest()
assert log.contains(expectedLogEntry)

I use this in a SpringBoot project with Groovy+Spock, though I can't see why this wouldn't work in any Java project with Logback.

Sealy

Answer 18

I tried using slf4j-test, but found, when running the test in eclipse, that I had several implementations of slf4j on the classpath, blocking slf4j-test. Their documentation (https://www.slf4j.org/codes.html#multiple_bindings) suggests some maven config that would sort out the test classpath when running tests via maven, but this didn't help me when running tests via eclipse.

In the end I implemented my own LogAppender (backed by a StringBuffer), attached that to my slf4j logger (provided by logback), and was able to write my test.

@Before
public void setUp() {
...
    ch.qos.logback.classic.Logger logger = (ch.qos.logback.classic.Logger) (LoggerFactory
        .getLogger(AdviserDashboardExceptionHandler.class));
    appender = new StringBufferAppender();
    logger.addAppender(appender);
  }

  @After
  public void clearLogger() {
    appender.clear();
  }

  @Test
  public void loggingTest() {
...
    assertThat(appender.getOutput(), containsString("some expected text"));
  }

Brunn

Answer 19

slf4j use three stream, System.out, System.err, and file

in this code i test only System.err printStream use: it possible for System.out too..

class PersonRepositoryImplTest {
  private PersonRepository personRepository;

  private PrintStream systemErr;
  private ByteArrayOutputStream testErr;

  @BeforeEach
  void setUp() {
    systemErr = System.err;
    testErr = new ByteArrayOutputStream();
    System.setErr(new PrintStream(testErr));
  }

  @AfterEach
  void tearDown() {
    System.setErr(systemErr);
  }

  @Test
  void delete() {
    personRepository.delete(1L);

    String logMessages = testErr.toString();
    System.setErr(systemErr);
    System.err.print(logMessages);
    Assertions.assertTrue(logMessages.contains("Person id=1 not found."));
 }
}

Contempt