How can I unit test Log4j using JMockIt?

Question

When a Logger (Or any static field) is declared in a class using a static method:

public class Foo {
  private static final Logger LOGGER = Logger.getLogger(Foo.getClass);
}

What is the correct way in which I can assert that methods on it are called (for auditing)?

The following will work, but setField appears to be the wrong way to go about it, nullifying the use of the @Tested annotation to allow automatic injection.

@Mocked Logger logger
new Expectations() {
  {
    setField(unitUnderTest, logger);
  }
}

JMockIt seems to provide a solution with @UsingMocksAndStubs(Log4jMocks.class), however this does not allow Expectations on it as it causes calls to getLogger() to return a real, but useless, Logger rather than a mocked instance.

Answer 1

It's simple:

@Test
public void verifyAuditing(@Cascading final Logger logging)
{
    // Call code under test which will create auditing records.

    new Verifications() {{ logging.info("expected audit info"); }};
}

The use of @Cascading causes Logger to be mocked in "cascading" mode, where every method which returns a reference type automatically creates a mocked instance. The initial mocked instance logging represents all such instances.

Answer 2

This question and answer describes what I hoped to do so perfectly, yet I found no joy in my attempt to implement the answer accepted here--tried hard to make it work but maybe my configuration is different in some significant way?? So, in case it will help anyone else, I'll offer this admittedly batsh!t-crazy alternative that does have the advantage of actually working for me (Java6, JMockit 1.7, JUnit 4.8.1, SLF4J 1.5.10).

The general strategy was to implement a slf4j Logger which will delegate to a mock logger. This combination seemed to allow me to get everything wired up right in a way that was totally non-invasive to the system under test. In the system under test, I have:

private static Logger log = org.slf4j.LoggerFactory.getLogger(SUT.class);

And, of course, various usages of log..

In my test class..

private static final TestLogger log = new TestLogger();

@Mocked
private Logger mockLogger;

@Tested
SUT sut = new SUT();

@BeforeClass
public static void replaceLogger() {
    new MockUp<LoggerFactory>() {
        @SuppressWarnings("rawtypes")
        @Mock
        Logger getLogger(Class clazz) {
            return log;
        }
    };
}

@Before
public void setup() {
    // go ahead and prefix this with name of test class, since log is static..
    log.setLogger(mockLogger);
}

@Test
public void ensure_some_behavior_happens() {
    new NonStrictExpectations() {{
        ...
    }};

    sut.someMethodOfInterest();

    new Verifications() {{
        mockLogger.warn("expected logging"); maxTimes = 1;
    }};
}

Ok the crazy part now--eclipse helped quite a bit, but still a major pain to implement Logger. Really made me appreciate the Interface Segregation Principle.

public class TestLogger implements Logger {
    Logger l = null;
    public void setLogger(Logger log) { l = log; }
    public String getName() { return l != null ? l.getName() : ""; }
    public boolean isTraceEnabled() { return l != null ? l.isTraceEnabled() : false; }
    public void trace(String msg) { if (l != null) l.trace(msg); }
    public void trace(String format, Object arg) { if (l != null) l.trace(format, arg); }
    public void trace(String format, Object arg1, Object arg2) { if (l != null) l.trace(format, arg1, arg2); }
    public void trace(String format, Object[] argArray) { if (l != null) l.trace(format, argArray); }
    public void trace(String msg, Throwable t) { if (l != null) l.trace(msg, t); }
    public boolean isTraceEnabled(Marker marker) { return l != null ? l.isTraceEnabled(marker) : false; }
    public void trace(Marker marker, String msg) { if (l != null) l.trace(marker, msg); }
    public void trace(Marker marker, String format, Object arg) { if (l != null) l.trace(marker, format, arg); }
    public void trace(Marker marker, String format, Object arg1, Object arg2) { if (l != null) l.trace(marker, format, arg1, arg2); }
    public void trace(Marker marker, String format, Object[] argArray) { if (l != null) l.trace(marker, format, argArray); }
    public void trace(Marker marker, String msg, Throwable t) { if (l != null) l.trace(marker, msg, t); }
    public boolean isDebugEnabled() { return l != null ? l.isDebugEnabled() : false; }
    public void debug(String msg) { if (l != null) l.debug(msg); }
    public void debug(String format, Object arg) { if (l != null) l.debug(format, arg); }
    public void debug(String format, Object arg1, Object arg2) { if (l != null) l.debug(format, arg1, arg2); }
    public void debug(String format, Object[] argArray) { if (l != null) l.debug(format, argArray); }
    public void debug(String msg, Throwable t) { if (l != null) l.debug(msg, t); }
    public boolean isDebugEnabled(Marker marker) { return l != null ? l.isDebugEnabled(marker) : false; }
    public void debug(Marker marker, String msg) { if (l != null) l.debug(marker, msg); }
    public void debug(Marker marker, String format, Object arg) { if (l != null) l.debug(marker, format, arg); }
    public void debug(Marker marker, String format, Object arg1, Object arg2) { if (l != null) l.debug(marker, format, arg1, arg2); }
    public void debug(Marker marker, String format, Object[] argArray) { if (l != null) l.debug(marker, format, argArray); }
    public void debug(Marker marker, String msg, Throwable t) { if (l != null) l.debug(marker, msg, t); }
    public boolean isInfoEnabled() { return l != null ? l.isInfoEnabled() : false; }
    public void info(String msg) { if (l != null) l.info(msg); }
    public void info(String format, Object arg) { if (l != null) l.info(format, arg); }
    public void info(String format, Object arg1, Object arg2) { if (l != null) l.info(format, arg1, arg2); }
    public void info(String format, Object[] argArray) { if (l != null) l.info(format, argArray); }
    public void info(String msg, Throwable t) { if (l != null) l.info(msg, t); }
    public boolean isInfoEnabled(Marker marker) { return l != null ? l.isInfoEnabled(marker) : false; }
    public void info(Marker marker, String msg) { if (l != null) l.info(marker, msg); }
    public void info(Marker marker, String format, Object arg) { if (l != null) l.info(marker, format, arg); }
    public void info(Marker marker, String format, Object arg1, Object arg2) { if (l != null) l.info(marker, format, arg1, arg2); }
    public void info(Marker marker, String format, Object[] argArray) { if (l != null) l.info(marker, format, argArray); }
    public void info(Marker marker, String msg, Throwable t) { if (l != null) l.info(marker, msg, t); }
    public boolean isWarnEnabled() { return l != null ? l.isWarnEnabled() : false; }
    public void warn(String msg) { if (l != null) l.warn(msg); }
    public void warn(String format, Object arg) { if (l != null) l.warn(format, arg); }
    public void warn(String format, Object[] argArray) { if (l != null) l.warn(format, argArray); }
    public void warn(String format, Object arg1, Object arg2) { if (l != null) l.warn(format, arg1, arg2); }
    public void warn(String msg, Throwable t) { if (l != null) l.warn(msg, t); }
    public boolean isWarnEnabled(Marker marker) { return l != null ? l.isWarnEnabled(marker) : false; }
    public void warn(Marker marker, String msg) { if (l != null) l.warn(marker, msg); }
    public void warn(Marker marker, String format, Object arg) { if (l != null) l.warn(marker, format, arg); }
    public void warn(Marker marker, String format, Object arg1, Object arg2) { if (l != null) l.warn(marker, format, arg1, arg2); }
    public void warn(Marker marker, String format, Object[] argArray) { if (l != null) l.warn(marker, format, argArray); }
    public void warn(Marker marker, String msg, Throwable t) { if (l != null) l.warn(marker, msg, t); }
    public boolean isErrorEnabled() { return l != null ? l.isErrorEnabled() : false; }
    public void error(String msg) { if (l != null) l.error(msg); }
    public void error(String format, Object arg) { if (l != null) l.error(format, arg); }
    public void error(String format, Object arg1, Object arg2) { if (l != null) l.error(format, arg1, arg2); }
    public void error(String format, Object[] argArray) { if (l != null) l.error(format, argArray); }
    public void error(String msg, Throwable t) { if (l != null) l.error(msg, t); }
    public boolean isErrorEnabled(Marker marker) { return l != null ? l.isErrorEnabled(marker) : false; }
    public void error(Marker marker, String msg) { if (l != null) l.error(marker, msg); }
    public void error(Marker marker, String format, Object arg) { if (l != null) l.error(marker, format, arg); }
    public void error(Marker marker, String format, Object arg1, Object arg2) { if (l != null) l.error(marker, format, arg1, arg2); }
    public void error(Marker marker, String format, Object[] argArray) { if (l != null) l.error(marker, format, argArray); }
    public void error(Marker marker, String msg, Throwable t) { if (l != null) l.error(marker, msg, t); }
}

Anyway, I would definitely see if the one of the other solutions works first, but if you should get desperate, maybe give this approach a try.

EDIT: Ok..I'm feeling altogether better about this approach after I turned the TestLogger above into a dynamic proxy implementation. Here's how to go with that..

First, give yourself an interface..

public interface TestLogger extends Logger {
    void setLogger(org.slf4j.Logger wrapped);
}

Then you'll need an invocation handler..

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;
import java.lang.reflect.Proxy;

import org.slf4j.Logger;

public class TestLoggerInvocationHandler implements InvocationHandler {
    private Logger wrapped;

    private TestLoggerInvocationHandler() {
        super();
    }

    @Override
    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
        if ("setLogger".equals(method.getName())) {
            wrapped = (Logger)args[0];
            return null;
        }
        return wrapped != null ? method.invoke(wrapped, args) : null;
    }

    public static TestLogger createTestLogger() {
        return (TestLogger) (Proxy.newProxyInstance(TestLogger.class.getClassLoader(),
                new Class[] { TestLogger.class }, new TestLoggerInvocationHandler()));
    }

}

Just call the static factory method in the test class and you should be good to go--not so crazy after all!