Saturday, July 16, 2011

Some tips for application logging in Java

Some tips for application logging in Java

In this blog post I want to share some of my thoughts about application logging in Java. Hopefully, you'd find them useful!

1. Consistent use of logging levels

Have a good understanding of the available log levels, and make sure you use them consistently throughout the application. Especially, if you're using the old JDK 1.4 Logger framework. What is the difference between FINER and FINEST?

Below is an abstract list of common log levels and a description of when to use them. This list is based on the Log4J log levels, but can be mapped to other logging frameworks.

FATAL
Unrecoverable errors. Leads to termination of the process (or a crash). Example: the application is in a corrupt state, and has no clue how to restore state.

ERROR
Errors that are not recoverable, but application can continue running. Example: an user request could not be executed, because some inputs are missing or invalid.

WARN
Undesirable or unexpected situations, but not necessarily "wrong". Example: the application expects a value in the cache, but could not find it. The application attempts to get the value in another way. Or a network connection is broken. The application tries to recover by reconnecting.

INFO
Important but normal run time events useful for monitoring. Example: a business process is finished.

DEBUG
Detailed information useful for debugging the system. Example: the content of a variable is printed in strategic locations of the application.

TRACE
Detailed control flow information. Example: a method is called message.

Below is a mapping of log levels of different logging frameworks. Levels that have the same level of severities are placed on the same row.









Carbon Severity EnumCommons LogLog4JJDK 1.4 LoggerLogKit
FATALFATALFATALSEVEREFATAL_ERROR
ERRORERRORERRORSEVEREERROR
WARNWARNWARNWARNINGWARN
INFOINFOINFOINFOINFO
DEBUGDEBUGDEBUGFINEDEBUG
DEBUGDEBUGDEBUGFINERDEBUG
TRACETRACEDEBUGFINESTDEBUG


2. Proper error logging

Error logging should not be done at the location where an exception is thrown, but at the location where the exception is handled to prevent double logging.

public void doSomething() throws ACheckedException {
if (someErrorCondition) {
String errorMessage = "Hey, some error occurred.";
logger.error(errorMessage);
throw new ACheckedException(errorMessage);
}
}

public void callerMethod() {
try {
doSomething();
} catch (ACheckedException exception) {
logger.error(exception.getMessage());
doSomethingElse();
}
}

The code above will log the same error twice. The log statement in the first method can be removed. Exceptions should "bubble up" to the method of the class that can handle the error, and then be logged. In most cases this class will play the controller role in a MVC style application.

3. Prevent unnecessary string concatenations

SLF4J is considered by many the best Java application logging framework. It's a logging facade that masks existing logging frameworks, which can be determined at deployment time. A great feature is that SLF4J allows you to avoid unnecessary string concatenation, which is really expensive.

logger.error("The error '" + errorMessage +
"' occurred in the " +
component.getName() + " component.");

Of course, you can use logging guards like this:

if (logger.isEnabledFor(Level.ERROR) {
logger.error("The error '" + errorMessage +
"' occurred in the " +
component.getName() + " component.");
}

But this will clutter your code, and degrades code readability.

The SLF4J way looks like this:

log.error("The error '{}' occurred in the {} component.",
errorMessage, component.getName());

As you can see, the use of SLF4J makes the logging statement more readable, and SLF4J will not compile the log message when the message will not be logged (i.e. not running in a high enough log level).

4. Use complete logging messages

Read logs, and check that the information in the log messages is complete, and can be used to reverse engineer back to the original state of the system.

01/02/2011 ERROR The user has a missing property.

The log message above could be improved by adding: the identifier for the user, and the name of the property, so it's easier to understand (and recreate) the situation that caused the log message. Another improvement is to add a message that gives information about what will happen next.

If you also have tips or views about application logging in Java, please don't hesitate to share them in the comments!

1 comment:

  1. Great article , you have indeed covered topic in details with code examples and explanation. I have also blogged some of my experience as 10 tips on logging in Java Thanks

    ReplyDelete