Use JMockit to Unit test logging output

A very simple method of unit testing output logging is presented using a state-based mocking approach and JMockit toolkit.

Context
Java language. Logging frameworks such as Log4j, commons-logging, java.util.logging, and SLF4J. Application logs.

Introduction
Unit test logging output? Isn’t that going overboard? Most likely. However, there can be some reasons why in certain parts of a code base you’d better:

  1. Audit requirements
  2. Use of Structured Logging.
  3. Logging adheres to standards such as Common Event Expression (CEE) language. (Note, CEE has been cancelled.)
  4. Ability to maintain a system
  5. Log maintenance tools get correct data
  6. Reduce technical debt
  7. SIEM

Solution
In listing 1, a simple class uses the java.util.Logger to log. We want to make sure this class will always log this in the future, i.e., a regression test. In order to qualify as a unit test, the system under test (SUT) should be isolated. Thus, parsing an actual logging output file would not be optimal.

Listing 1

" java.util.logging.Level;
" java.util.logging.Logger;

/**  Example class that logs. */
public class Service {
	Logger logger = Logger.getLogger(this.getClass().getName());
	
	public void serve(){		
		logger.log(Level.INFO,"Hello world!");
	}
}

In listing 2 we use JMockit to mock the java.util.Logger. This should also work for other logging frameworks. JMockit has two approaches for applying mock techniques: Behavior-based and state-based.

We apply state-based below (just cause that is the one I’m starting to get the hang of). The Arrange, Act, Assert (AAA) pattern is still used, but the Assert step is in the mock object. We apply a simple ‘equals’ test. Of course, based on what we expect in the log message, a regex may be more useful.

Listing 2

import static org.hamcrest.CoreMatchers.*;
import static org.junit.Assert.*;

import java.util.logging.Level;
import java.util.logging.Logger;

import mockit.Mock;
import mockit.MockUp;
import mockit.Mockit;

import org.junit.After;
import org.junit.Before;
import org.junit.Test;

/**
 * JUnit test for Service class.
 * @author jbetancourt
 */
public class ServiceTest {
	private Service service;

	@Before
	public void setUp() throws Exception {
		service = new Service();
	}
	
	@After
	public void tearDown() throws Exception {
		Mockit.tearDownMocks();
	}

	@Test
	public final void we_are_logging_correctly() {	
           // Arrange
           mockLogger();

           // Act
           service.serve();	
	}

	private void mockLogger() {

		new MockUp<Logger>() {
			@SuppressWarnings("unused")
			@Mock
			public void log(Level level, String msg) {
				assertThat("Hello world!", is(equalTo(msg)));
				assertThat(level, is(equalTo(Level.INFO)));
			}
		};
	}
}

Extensions
The above technique just tests that the log parameters are correct. This doesn’t check that the log output to file itself is correct. That is a different concern. Since the actual output logging is controlled by various configuration options, a unit test may not make sense. Would that be a functional test?

Of course, just checking that the message sent to the logger may not be enough. In this case a possible approach is to hook into the logging library to capture the final log output. In the java.util.logging API, one can add a new stream Handler to the Logger instance being used.

In listing 3 below a simple attempt is made to use a stream handler to capture the actual logger output used by java.util.logging.

Listing 3


public class ServiceTest{
  Logger logger = Logger.getLogger(ServiceTest.class.getName());
  private OutputStream logOut;
  private StreamHandler testLogHandler;

  @Before
  public void setUp() throws Exception {
     setUpLogHandler(logger);
  }

  /** */
  @Test
  public final void exception_log_has_all_info(){
    logger.log(Level.WARNING, "Hello world!");
    testLogHandler.flush();
    String captured = logOut.toString();
    Assert.assertTrue(captured.contains("Hello world!");
 }

 /** 
   Add stream handler to logger.  
   Will take more effort then this, e.g., may not have parent handler.
   */
  protected void setUpLogHandler(Logger logger) {
    logOut = new ByteArrayOutputStream();
    Handler[] handlers = logger.getParent().getHandlers();
    testLogHandler = new StreamHandler(logOut, handlers[0].getFormatter());
    logger.addHandler(testLogHandler);
  }
}

Software
* JUnit: 4.*
* JMockit: 0.999.11
* JDK: 1.6*
* Eclipse: IDE 1.7
* Git: 1.76.msysgit.0

Summary
Shown was a little technique that may come in handy one day. Though presented in the context of logging, it is really a simple application of state-based mock use.

Further reading


Carlos Santana/Mahavishnu John McLaughlin – The Life Divine

Similar Posts:

Creative Commons License
This work is licensed under a Creative Commons Attribution-NonCommercial-NoDerivs 3.0 Unported License.

2 thoughts on “Use JMockit to Unit test logging output”

    1. Since this is a unit test the mock lasts for the current test only. The current code is written in this ‘context’ only.

Leave a Reply

Your email address will not be published. Required fields are marked *