Thursday 4 May 2017

Testing java slf4j over log4j logging in JUnit using SLF4J Test

Testing logging on failure paths has two problems:

  • It is hard to get the log message text
  • The logger outputs to the test log
The first leads to compromises eg verifying only that a message was logged, the second makes you, the programmer, think an error has occurred when the tests in fact passed.

Code to test


public class Sut { 
    public String perform() {
        getLog().debug("In perform");
        return "Hello world";
    }
}

My clunky PowerMock Solution

My approach was problematic as it required the use of PowerMock which is as powerful as nitroglycerin.

Test Code


@RunWith(PowerMockRunner.class)
@PrepareForTest({LoggerFactory.class})
public class SutTest {

    @Test
    public void testPerform() {
        mockStatic(LoggerFactory.class);
        Logger mockLog = mock(Logger.class);
        when(LoggerFactory.getLogger(any(Class.class))).thenReturn(mockLog);

        assertEquals("Hello world", new Sut().perform());
        verify(mockLog, times(1)).debug(startsWith("In perform"));
    }
}

Elegant SLF4j Test Solution

The slf4j-test project by RobElliot266 provides a logger which stores messages and so can be asserted against.

POM Setup

Add the following to your dependencies


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

To ensure that this logger is used during tests only and that it takes precedence over the production logger in the test class path ensure the test logger is the first logger mentioned in the dependencies block and has a test scope.

As an additional measure you can explicitly exclude the production logger from the test class path:


        <plugin>
            <groupId>org.apache.maven.plugins</groupId>
            <artifactId>maven-surefire-plugin</artifactId>
            <version>2.18.1</version>
            <configuration>
                <classpathDependencyExcludes>
                    <classpathDependencyExcludes>org.slf4j:slf4j-jdk14</classpathDependencyExcludes>
                </classpathDependencyExcludes>
            </configuration>
        </plugin>

Test Code


public class SutTest {
  @Test
  public void testPerform() {
    assertEquals("Hello world", new Sut().perform());
    assertEquals("Testing", logger.getLoggingEvents().get(0).getMessage());
  }
}

Much thanks to RobElliot266 for an neat solution to a problem that has been bugging me for a while.