h1

Testing log statements

September 25, 2009

Of late, this blog has become an almost exclusive chess blog. Let me redress that balance, at least for one post.

Unit testing your log statements is unusual, but not unheard of. There might be many reasons for this – you might have a separate process monitoring your log files and taking action on certain log messages…or, you might be handling an event which you choose to ignore except to log its invocation and you want to test that you are logging properly. Whatever the reason, there isn’t any easy way (at least in Java) to test your log statements.

One way of testing is to read from the log file and ensure the log statement gets written out. But we don’t ideally want to be reading from log files in our unit tests. Here’s what you could do, if you were using log4j:

First, have a class called VectorAppender.java:

import java.util.Vector;

import org.apache.log4j.AppenderSkeleton;
import org.apache.log4j.spi.LoggingEvent;

public class VectorAppender extends AppenderSkeleton {
 private static Vector <String>messages = new Vector<String>();
 public static final boolean VECTORAPPENDER_SYSOUT = false;

 @Override
 protected void append(LoggingEvent arg0) {
  if (VectorAppender.VECTORAPPENDER_SYSOUT)
   System.out.println(arg0.getLoggerName() + "  - " + arg0.getRenderedMessage());
  messages.add(arg0.getLoggerName() + "  - " + arg0.getRenderedMessage());
 }
 
 public void close() {}
 
 public boolean requiresLayout() {
  return false;
 }

 public static void clear() {
  messages = new Vector<String>();
 }
 
 public static Vector<String> getMessages() {
  return messages;
 }
}

Then, we invoke initLogging() in the setup to our unit test:

public static void initLogging() {
 Properties p = new Properties();
 p.put("log4j.rootCategory", "DEBUG, stdout, LOGFILE");
 p.put("log4j.appender.LOGFILE", VectorAppender.class.getName());
 p.put("log4j.appender.stdout.Threshold", "DEBUG");
 p.put("log4j.appender.stdout", "org.apache.log4j.ConsoleAppender");
 p.put("log4j.appender.stdout.layout", "org.apache.log4j.PatternLayout");
 p.put("log4j.appender.stdout.layout.ConversionPattern", "%d %-5p [%C{1}.%M() %L] - %m%n");
 org.apache.log4j.PropertyConfigurator.configure(p);

 VectorAppender.clear();
}

Now, VectorAppender.getMessages() gives you everything that’s been logged and you can assert to your heart’s content!

Advertisements

One comment

  1. Here’s my latest version of the same thing!

    class TestAppender extends AppenderSkeleton {

    private List errorLines;
    private List debugLines;

    public TestAppender() {
    this.errorLines = new Vector();
    this.debugLines = new Vector();
    }

    public List getErrorLines(){
    return this.errorLines;
    }

    public List getDebugLines(){
    return this.debugLines;
    }

    @Override
    protected void append(LoggingEvent arg0) {
    if (arg0.getLevel().equals(Level.ERROR))
    this.errorLines.add(arg0.getMessage().toString());
    if (arg0.getLevel().equals(Level.DEBUG))
    this.debugLines.add(arg0.getMessage().toString());
    }

    @Override
    public void close() {
    }

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

    @Test
    public void testIt() {
    Logger logger = Logger.getLogger(CommandRunner.class);
    logger.removeAllAppenders();
    TestAppender testAppender = new TestAppender();
    logger.addAppender(testAppender);
    }



Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

%d bloggers like this: