Freitag, 3. Juni 2011

Test Logging via JUnit Rule

In most cases it is not necessary to test logging, but in some situations you wont to check in a JUnit test that a log statement will be written, e.g in special error cases. When you use logback as logging framework the test can setup a ListAppender for a Logger and can implement a assert method which checks that the expected log statement is in the ListAppender list. But then the test is logback specific and has dependency on logback! When you use this approache in many JUnit test classes the test source has a hard dependency on logback and when you wont to change the logging framework all tests must also be changed. To remove this hard dependency you can use a JUnit rule, which capsulate the logback framework from the test source. The example here shows how a test and such a JUnit rule can look like.

Here the sample test for verify logging:
import static org.junit.Assert.*;
import static org.hamcrest.Matchers.*;
import java.util.Stack;
import org.junit.Before;
import org.junit.Rule;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
// Sample Logging Test
public class SimpleStackTest {
@Rule public LogStub logStub = new LogStub(){{
record(LogLevel.INFO);
recordLoggingForType(SimpleStack.class);
}};
SimpleStack stack;
@Before
public void setup() {
stack = new SimpleStack();
}
@Test
public void testPush() {
stack.push("Item One");
assertTrue(logStub.containes("Push item Item One into stack."));
assertThat(logStub.size(), is(1));
}
}
//SUT
class SimpleStack {
private static final Logger logger = LoggerFactory
.getLogger(SimpleStack.class);
private Stack<String> stack = new Stack<String>();
public void push(String item) {
final String method = "push() :";
logger.trace("{} Start", method);
stack.push(item);
logger.info("{} Push item {} into stack.",method, item);
logger.trace("{} End", method);
}
}


And here the logback specific rule:
import java.util.List;
import java.util.Vector;
import org.junit.rules.TestWatchman;
import org.junit.runners.model.FrameworkMethod;
import org.slf4j.LoggerFactory;
import ch.qos.logback.classic.Level;
import ch.qos.logback.classic.Logger;
import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.spi.ILoggingEvent;
import ch.qos.logback.core.read.ListAppender;
public class LogStub extends TestWatchman {
public enum LogLevel {
TRACE(Level.TRACE),
DEBUG(Level.DEBUG),
INFO(Level.INFO),
WARN(Level.WARN),
ERROR(Level.ERROR);
Level internalLevel;
private LogLevel(Level level) {
this.internalLevel = level;
}
}
private final ListAppender<ILoggingEvent> listAppender = new ListAppender<ILoggingEvent>();
private final LoggerContext lc = (LoggerContext) LoggerFactory
.getILoggerFactory();
private final Vector<Class> loggingSources = new Vector<Class>();
private LogLevel level = LogLevel.TRACE;
@Override
public void starting(FrameworkMethod method) {
before();
}
@Override
public void finished(FrameworkMethod method) {
after();
}
public void before() {
resetLoggingContext();
for (Class logSource : loggingSources) {
addAppenderToType(logSource);
}
listAppender.start();
}
public void after() {
listAppender.stop();
resetLoggingContext();
}
public void record(LogLevel level) {
this.level = level;
}
public void recordLoggingForObject(Object sut) {
Class type = sut.getClass();
recordLoggingForType(type);
}
public <T> void recordLoggingForType(Class<T> type) {
loggingSources.add(type);
addAppenderToType(type);
}
public boolean containes(String loggingStatement) {
List<ILoggingEvent> list = listAppender.list;
for (ILoggingEvent event : list) {
if (event.getFormattedMessage().contains(loggingStatement)) {
return true;
}
}
return false;
}
public int size() {
return listAppender.list.size();
}
private <T> void addAppenderToType(Class<T> type) {
Logger logger = (Logger) LoggerFactory.getLogger(type);
logger.addAppender(listAppender);
logger.setLevel(level.internalLevel);
}
private void resetLoggingContext() {
lc.reset();
}
}
view raw LogStub.java hosted with ❤ by GitHub