Testing logging behaviour in four code lines flat

Update: Testing logging without Mockito is also viable.

Adding assertions for logging behaviour to my unit tests have been a long standing item om my ToDo list. This imperfection have been a nagging thorn in my side since it obvious that logging is a critical aspect (no AOP pun intended) of any commercial system of importance. But I thought that it must be hard and boring work to add tests for logging. To be honest I’m no fan of boring work. Recently I finally got around to take a shot at it and found it surprisingly easy to accomplish in a mavenized Spring project with the help of the everyone’s favorite Java mocking library: Mockito.

Originally I though I had to modify all the classes under test to accept a log4j Logger as constructor argument and mock that logger in the unit test. This would have required quite a lot of code rewrite since most classes in the project simply use:

Logger.getLogger(this.getClass())

to get access to a logger instance. Also I don’t like the idea to “pollute” the constructors with additional arguments, most classes had just enough dependencies passed in that way as it were.

Next up was an idea to write a custom log4j Appender and add a log4j.properties to src/test/resources with:

log4j.rootLogger=ERROR,TESTAPPENDER
log4j.appender.TESTAPPENDER=com.my.fantastic.MockedAppender

The main problem with this approach is that MockedAppender instance would be shared by all unit tests, forcing manual (ugly!) resets of its state between test invocations.

Then I discovered that log4j provides an API for dynamic Appender configuration at runtime! What it all boiled down to became surprisingly succinct when some Mockito magic was applied. In fact only four code lines (ignoring imports, and other noise) bought me the capability to make assertions about the logging behavior of the code under test!

import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
public class FooTest {
	private Appender appenderMock;
	@Before
	public void setupAppender() {
		appenderMock = mock(Appender.class);
		Logger.getRootLogger().addAppender(appenderMock);
	}
	@After
	public void removeAppender() {
		Logger.getRootLogger().removeAppender(appenderMock);
	}
	@Test
	public void testMethod()  {
		doStuffThatCausesLogging();
		verify(appenderMock).doAppend((LoggingEvent) anyObject());
	}
}

Using Mockito’s handy ArgumentCaptor class it’s dead simple to make stronger assertions, with regard to for instance the level the message was logged at:

		ArgumentCaptor arguments = ArgumentCaptor.forClass(LoggingEvent.class);
		verify(appenderMock).doAppend(arguments.capture());
		assertThat(arguments.getValue().getLevel(), is(Level.WARN));

Ergo – I have no longer any excuse for settling for anything less than comprehensive unit tests, adding tests for logging is actually quite trivial using modern tools!