Best Practices on Logging

We list best practices on logging exceptions.

Log once

This is closely related with the Do not log and throw. You should try not to throw the same exception more than once. If you do not follow this rule your log file will be cluttered by outputs of the same exception incidence.

Note that if you are using smartics-exceptions, all exceptions in a root cause chain reference the same ID. Therefore it is possible to correlate two logging statements to have the same cause. So in case an exception is logged in more than one occasion, the correlation of these events is trackable.

Log all in one Place

If there is information to be logged, log it with one call of the logger. If you do not follow this rule and the information is split to more than one call, the information may be disrupted in the log file by log messages written by other threads.

Therefore construct the message in memory and write the message with one log call:

final StringBuilder buffer = new StringBuilder(128);
buffer.add(...);
...
buffer.add(...);
final String message = buffer.toString();
LOG.warn(message);

Use Guards

Use guards to prevents runtime overhead. The message string is not required to be constructed, if - as seen in the following example - the log level is set to WARN:

if (log.isDebugEnabled()) {
  log.debug("No user found for ID '" + id + "' in context '" + context + "'.");
}

This is especially useful, if creating the message requires a resource consuming calculation. Using the guard, the calculation is only performed if the message is really logged:

if (log.isDebugEnabled()) {
  final String message = calcMessageWithAccessingADatabase(...);
  log.debug(message);
}

Many logging frameworks provide means to format logging messages like this:

log.debug("No user found for ID '{}' in context '{}'.", id, context);

In this case it is not necessary to use a guard, since no calculation is conducted to create the message. This allows to reduce the number of lines for a logging action to one, making the code more readable. Use this option if your logging framework supports one. It would not be too difficult, to provide some helpers in your project, using String.format to provide the same effect.

Default Log Level for Libraries

The default log level for libraries should be DEBUG. Use TRACE for even more detailed information.

The application code is the only one to know, if a situation encountered during a library call should be deemed as FATAL, ERROR, WARN, or INFO. So these higher level log levels are reserved for application code.

This implies that the library has to inform the calling code about the situation. The returned value from the library to the caller requires the report information. Upon this information, the caller decides about logging the information or not.

Provide Log Codes

It is reasonable to associate a log statement with a code. This makes it easier for users to track log statements the same way as exception logs.

Here is an example from JBoss 7 (note that they do not use smartics-exceptions, they just use codes):

INFO  [org.jboss.as.remoting] (MSC service thread 1-2) JBAS017100: Listening on ...

To use this with smartics-exceptions add a code and message templates as for any exception. You may want to extend AbstractMessageBean and pass your instance to the logger.

log.info(new StartupMessage(...)

If you are only interested in log codes you may skip message beans and only use the codes. Reports will lack detailed information about the place holders, but the codes will be documented. Using logging with codes with e.g. SLF4J is then done like this:

log.trace("{}: Preparing to access resource {}.", ACCESS_RESOURCE_PREPARE , resourceId);

This way the logging message is not separated into a resource bundle.

The same logging statement with message beans is a little shorter:

log.trace(MSG.log(ACCESS_RESOURCE_PREPARE , resourceId));

Static or Instance Loggers?

Should a logger be declared static

private static final Logger LOG = ...

or as an instance variable?

private final Logger log = ...

In slf4j, the developers explain the advantages of each approach.

In our projects we use instance loggers for libraries that are of common use and static loggers for application code.

Logging to Information Systems

There are use cases where exceptions should be logged to a trouble ticket or other kind of information system. This may be instead of or in addition to messages to the log file or log database.

smartics-exceptions provides no utilities for this task, since this is quite application dependent. The logging may either be integrated into the logging framework in form of a specific logger or may be used dependent on the application framework or technology. Usually interceptors or filters come handy to log exceptions that have been encountered. These components are sitting on the boundary of the application and decide how to log the information before the response is sent to the caller.