Home > Point2 - Technical > An easier way to test logging code

An easier way to test logging code

March 5, 2010

This article describes a simple technique a colleague and I stumbled upon to make unit testing logging easier in Java programs.

Why is it usually hard to unit test logging?

Static state is more or less the enemy of testability. Unfortunately, almost every Java logging example ever published (regardless of logging framework) stores the logging provider as static state:

public class MyClass {
    private static Logger log =
        Logger.getLogger("com.point2.MyClass");
    public void foo() {
        log.info("foo!");
    }
}

In order to verify that calling the method “foo” actually emits a log message, we have to somehow intercept the call to Logger.getLogger(), and:

  1. Register some sort of hook so that we can know when something was logged
  2. Prevent the regular log output from happening. This is especially important when exceptions are logged, as having a lot of test stack traces being emitted as part of a test run is annoying, confusing, and slow.

The technique:

Do away with the static call, and use dependency injection instead.

public class MyClass {
    public MyClass(Logger log) {
        this.log = log;
    }

    private final Logger log;

    public void foo() {
        log.info("foo!");
    }
}

Now any unit test that needs to verify logging behaviour can just inject a mock object. All commonly used java logging frameworks uses classes instead of interfaces, but modern mocking frameworks can mock classes without too much difficulty.

Now, make the static call within your dependency injection framework. Here’s a spring example:

<bean id="log4jLogger" class="org.apache.log4j.Logger"
  factory-method="getLogger">
    <constructor-arg index="0" value="com.point2.MyClass"/>
</bean>

I find that this approach actually adds flexibility to your logging options. For example, if you have a number of classes that should all contribute messages to a single log file, inject the same logging reference into each of them.

<bean id="julLogger" class="java.util.logging.Logger"
  factory-method="getLogger">
    <constructor-arg index="0" value="emailLogFile"/>
</bean>

<bean id="foo">
    <constructor-arg index="0" ref="julLogger"/>
</bean>

<bean id="bar">
    <constructor-arg index="0" ref="julLogger"/>
</bean>

In this case, it now makes sense to name this logger for the log file that it outputs to, and we are free to do so, without having to make sure that the change is caught in a number of classes. In addition, if we every have to refractor either of these classes (for example to move it into a different package), we can do so without fear of changing how our logging output works.

This is a specific example of the general principle that replacing static state with inverted dependencies can make your code more flexible and easier to test.

By Sean Reilly

Advertisements
Categories: Point2 - Technical Tags: ,
  1. March 6, 2010 at 4:02 AM

    This is a good point. It struck me a while ago that production logging should be tested and supported like any other public interface, which means it should have its own domain types. I wrote it up here: http://www.mockobjects.com/2007/04/test-smell-logging-is-also-feature.html

  1. No trackbacks yet.
Comments are closed.
%d bloggers like this: