Post banner

29 August 2018 by Mark Wehby

Why test logging statements?

Who in their right mind writes unit tests for logging statements? Just kidding, logging done the correct way can do more than provide data and insight into the running application. This data can allow us to see patterns that indicate potential problems with the application. It provides data for real-time answers to business questions, like how many transactions does our system do in an hour. Logging can also be used for AI and Machine learning to try to predict and take action in the future. The data is also useful from a Security standpoint, i.e., why is there a sudden spike in https traffic, did a marketing campaign just kick off, or are we under a DDOS attack? Therefore, testing how the logging code is supposed to work is important. These tests should verify both that the logging event happened when intended and that it contained the correct information.

Migrating from JUnit 4 to JUnit 5

When sitting down to start a new Java project from scratch, I grabbed the latest version of JUnit (5.2.0) and found out that the mechanism I used in the past to enable the unit testing of logging statements no longer worked. The @Rule annotation from JUnit4 is deprecated in favor of the new Extension Model in JUnit 5. Unable to find a solution on how to use the new Extension Model on the internet or Stack Exchange, I coded up the following. Standard disclosure, the code is for illustrative purposes only, no warranty or guarantee implied.

Solution

This following shows how to use JUnit 5’s Extension Model to enable the testing of logging statements. It includes examples and explanations of the Java code needed and a link to a GitHub repository where the full solution exists.

CUT ( Class Under Test )

In order to illustrate how to use the new JUnit 5 Extension model to unit test logging statements, let’s pretend we have the follow CUT.

The first thing to point out is that the code is using the slf4j library to abstract out the logging implementation. This abstraction is usually a good idea, and slf4j is a popular choice. This abstraction allows the application to switch from one logging framework to another with little to no coding changes. The second thing to point out is there are logging statements at two different levels of logging, which is done to help illustrate a feature of the testing solution later on.

Now for the solution!

Logging Stub

The LogTrackerStub implements callback interfaces that JUnit 5 uses in its Extension Model. By implementing the interfaces, it allows the JUnit 5 framework to interact with the LogTrackerStub and prepare and reset the tracker before and after each test method is run. This interaction ensures there is no interference between test method invocations. The LogTrackerStub delegates to the LogTracker for the tracking ability, this separates out the JUnit 5 callback responsibility from the tracking responsibility.

Note the use of the Logback. Logback is a fine logging framework and has a lot to offer. In this case, the selection of Logback for the implementation framework for capturing logging statements is because it provides an out of the box ListAppender. Apache’s Log4j and Log4j2 frameworks could also be used but would require a custom Appender implementation. The selection is for convenience sake and does not need to tie your application’s logging framework implementation to Logback. Just like the use of slf4j in the source code allows for abstraction from the logging framework, use of the LogTracker provides for the same in the test code. If all the test code uses the LogTrackerStub, the test code would have no dependencies on LogBack. The LogTrackerStub and LogTracker would be the only code needed to change if the test code changed its logging framework.

Using the Stub

Finally, here is what using the LogTrackerStub looks like in a unit test.

Using the @RegisterExtension annotation from JUnit 5 is the programmatic way of registering the LogTrackerStub as a JUnit 5 Extension. Note the Extension annotation on the LogTrackerStub field. The Extension annotation documentation notes that fields marked with the annotation cannot be “private” or “null”, see the JUnit 5 documentation for additional information. The Extension is created using the builder pattern, and the INFO level is the default recording level. It is also possible to change the recording level for a given test as illustrated in the “testCUTMethodOne()” test method.

Notes

This solution is not thread-safe. It is not safe to run the tests using the Extension in parallel. There is support in JUnit 5.3.0 RC1 for running tests in parallel. When the support is production ready, the easiest way to ensure thread safety is to add the @Execution(SAME_THREAD) to the test class. There is also a chance that rewriting the Extension or using it differently would be better if using it when tests are running in a parallel fashion.

When writing the plugin, there was an issue with the maven surefire plugin. There is an entry in the pom.xml with a note explaining the issue, but basically, the maven surefire plugin doesn’t work well with JUnit 5. Therefore, the JUnit team created a surefire provider and test engine that uses the JUnit 5 Jupiter API. See the following StackOverflow question.

Final Thoughts

The migration from JUnit 4 to JUnit 5 isn’t too bad. There are still a few wrinkles that need to be ironed out, but those wrinkles have easy workarounds in place or will be addressed directly shortly. The solution provided above allows for easy extension. The code that relies upon JUnit 5 or on Logback is isolated. It would be easy enough to add interfaces and classes to further extend support for different test frameworks or different logging frameworks.


Author image
Mark · Co-Founder & CEO

Mark has over 20 years of experience working in the IT field. In his most recent work, he has developed in Groovy and introduced Continuous Delivery to IT departments of companies ranging from mid-size to Fortune 500. Mark is a director of the CinJUG meetup.