A lot of projects run integration and unit tests, but often miss a little something – logging. When you use logging you often check if the log level is enabled or not before you log. But this means that you introduce a control flow statement that enables or disables some code. So if you miss to enable logging for your tests you let code untested and bugs love untested code, because they can hide there. But it is easy to remove this hiding places for bugs.

Avoid log level checks if possible

If you can avoid log level enabled checks, you avoid control flow statements and this  means that you remove hiding places for bugs. But when can you avoid log level checks?

An application uses a logging API to log information about it’s state. The logging implementation decides either to log the information or discard it depending on it’s configuration. So if assembling information is an expensive operation it would be worse if the logging implementation discards it later. For this situations the logging APIs provide methods to find out if logging is enabled or not, e.g. isDebugEnabled(). As a result of this the trick is to eliminate expensive data assembling operations or move the expensive operation to a later time in execution when you know that the data will be logged. For the latter the logging APIs provide special methods that take parameters.

But there is also another point to mention – clean code. Every log level enabled check introduces a control flow statement and decreases readability. In the next sections I want to show ways how to improve readability and code coverage by avoiding log level enabled checks.

Just log string literals

The simplest form of logging is a logging a string literal. In this case you should always avoid log level checks in matters of clean code.

// instead of
if(logger.isInfoEnabled()){
    logger.info("Some string literal");
}

// just do
logger.info("Some string literal");

This works with a lot of logging APIs, because the logging methods (info, debug, etc.) themself  check if the log level is enabled. But take a look at the javadoc of your logging framework’s methods if they check the level.

Use parameter objects

Most logging frameworks support logging with parameter objects. In this case you can just pass a string literal that contains placeholdes and pass the objects to be formatted as parameters. The advantage is that you delay the log message formatting. The formatting is done by the logging framework’s method later if the framework decides whether to log the message or not.

// instead of
if(log.isInfoEnabled()){
   String message = "User " + user + " logged in successfully on " + date;
   log.info(message);
}

// just do
log.info("User {0} logged in successfully  on {1}", user, date);

Enable all loggers in all of your tests

In the previous sections I showed ways to prevent log level enabled checks in order to remove unnecessary control flow statements and therefore increase code coverage and readability. But there might ever be code that needs log level enabled checks. Always keep in mind that this code should be tested too.

Imagine the following situation. An application in production has a problem and you want to get more information. So you ask operations to increase the log level to debug. Operations increases the log level and all of a sudden the application crashes with exceptions like NullPointerException or maybe even an OutOfMemoryError. This would be a nightmare for a developer, because an application in production has a problem and therefore must be fixed as soon as possible.  Sadly the developer needs more information and he can’t get it because the debug logging produces more problems. I guess you don’t want to come in such a situation, because it means overtime and more coffee than is good for your health.

So remove as much untested code as possible, because this removes hiding places for bugs. Enable all log levels for all loggers in all of your tests. You might think now “But this slows down my tests and produces large log files when I’m testing”. No, if you enable it the right way. Let’s go  back to what we want to achieve. We want to test all of our code even the logging code, but to test it we don’t need the log output. We just want to make sure that when logging is enabled it doesn’t introduce bugs. Therefore we enable all log levels for all loggers, but do NOT log to a file or console. These I/O operations take most of the logging time, slow down the tests and we can omit them.

To make things clear… Here is an example of a log4j configuration that enables all log levels for all loggers and does not log to any file or console.

<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration debug="true" xmlns:log4j='http://jakarta.apache.org/log4j/'>
   
   <appender name="NOOP" class="com.link_intersystems.log4j.NoopAppender"/>
   
   <root>
       <level value="ALL" />
       <appender-ref ref="NOOP" />
   </root>
</log4j:configuration>

to make it work implement a NoopAppender and add it to your test classpath.

public class NoopAppender extends AppenderSkeleton {

	public void close() {
	}

	public boolean requiresLayout() {
		return false;
	}

	protected void append(LoggingEvent event) {
	}
}