Self Logging Exception Pattern

Error handling is an important and vital part of any serious application and usually a fair amount of application code addresses this topic. This is too some extend due to the fact that proper error handling requires to consider two aspects.

When ever an error occurs usually the control flow gets iterrupted and needs to take a different route. In Java this is done by throwing, catching, rethrowing and wrapping exceptions so that the application either aborts the current request to show an error message to the user or to recover from the error automatically.

Additionally those errors need to be logged to allow the support staff to see what is going on in the application and to be able to tell customers why their actions did not give the expected result and most importantly to find bugs.

This often leads to code blocks like the following:

UserTransaction transaction = null;
EntityManager em = null;
try {
  transaction = (UserTransaction) new 
      InitialContext().lookup("java:comp/UserTransaction");
  transaction.begin();
  em = emf.createEntityManager();
  em.merge(this.be);
  transaction.commit();
} catch (IllegalStateException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (RollbackException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (IllegalArgumentException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (TransactionRequiredException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (PersistenceException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (NamingException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (NotSupportedException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (SystemException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (SecurityException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (javax.transaction.RollbackException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (HeuristicMixedException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} catch (HeuristicRollbackException ex) {
  logger.error("Persist failed", ex);
  throw new ApplicationException("Persist failed", ex);
} finally {
  em.close();
}

Quite anoying, isn't it? Now there are certain possibilities to try to reduce this boiler plate. The first attempt that is still employed far too often is to just catch Exception. This pattern is higly discouraged because it swallows exceptions resulting from coding errors like the very common NullPointerException. Another way to make the code a little bit cleaner is to wrap the log statement and exception generation into a convinience method that might also be parameterized with a message to be used as log ouput and the exceptons detail message:

private void bail(String msg, Throwable ex){
  logger.error(msg, ex);
  throw new ApplicationException(msg, ex);
}

...
} catch (SystemException ex) {
  this.bail("Error message 1", ex);
} catch (SecurityException ex) {
  this.bail("Error message 2", ex);
} catch (javax.transaction.RollbackException ex) {
  this.bail("Error message 1", ex);
} catch (HeuristicMixedException ex) {
  this.bail("Error message 1", ex);
...

But what if you do not only want to control the exception text to be displayed but also the kind of exception to be thrown. One could swap the error message for an enum and then decided within the bail method which exception should be thrown or to avoid this additional boiler plate add the exception class to the enum and then generate the exception by using reflection.

But all these approaches still rely on the programmer to make sure that where ever he handles the original excpetion he has to do both, log the error and throw the exception. Even if this is wrapped in a utility class that might be used throughout the application. Don't get me wrong, this approach is usually pretty fine and works rather well, at least as long as all developers involved in the project are aware of this necessity and can be trusted not to forget it. But often enough even the most reliable developers are in a hurry or the project staff changes or...

So I thought it would be nice to have mechanism that makes sure that when ever an application sepcific exception is thrown the corresponding error will be logged. That is why I came up with this idea:

public class ApplicationException extends RuntimeException {

  private static final long serialVersionUID = -4599465800805791368L;
  private static final Logger logger = Logger.getLogger(ApplicationException.class);

  private MessageCode code;

  private List<Object> params;

  public ApplicationException (MessageCode code) {
    this(code, null, null);
  }

  public ApplicationException (MessageCode code, List<Object> params) {
    this(code, null, params);
  }

  public ApplicationException (MessageCode code, Throwable cause) {
    this(code, cause, null);
  }

  public ApplicationException (MessageCode code, Throwable cause, List<Object> params) {
    super(getResolvedMessage(code.getMsg(), params), cause);
    this.code = code;
    this.params = params;
    this.log();
  }

  private void log() {
    StackTraceElement ste = this.getStackTrace()[0];
    if (logger.isEnabledFor(this.code.getLevel())) {
      logger.log(this.code.getLevel(), "ApplicationException thrown at "
        + ste.getClassName()
        + "."
        + ste.getMethodName()
        + ":"
        + ste.getLineNumber()
        + " with message '"
        + getResolvedMessage(this.code.getMsg(),this.params) 
        + "'");
    }
  }

  public String getKey() {
    return this.code.getKey();
  }

  private static String getResolvedMessage(String msg, List<Object> params) {
    if (null != params) {
      for (int i = 0; i < params.size(); i++) {
        if (null != params.get(i)) {
          msg = msg.replaceAll("\\{" + i + "\\}", params.get(i).toString());
        }
      }
    }
    return msg;
  }
}


public enum MessageCode {

  // General
  CODING_ERROR("Error.CodingError", "This is very likely a bug"),

  // Persistence
  PERSISTANCE_SAVE_FAILED("Error.Persistance.SaveFailed", "Error during entity persitance."),

  // User
  USERNAME_ALREADY_TAKEN("Info.User.NameAlreadyTaken", "Username '{0}' already taken", Level.INFO), 
  INVALID_PASSWORD("Info.User.LoginFailed", "Login failed due to an invalid password for user '{0}'", Level.INFO);

  private String msg;

  private String key;

  private Level level;

  private MessageCode(String key, String msg) {
    this(key, msg, Level.ERROR);
  }

  private MessageCode(String key, String msg, Level level) {
    this.key = key;
    this.msg = msg;
    this.level = level;
  }

  public String getKey() {
    return this.key;
  }

  public Level getLevel() {
    return this.level;
  }

  public String getMsg() {
    return this.msg;
  }
}

Here the MessageCode class takes several arguments, a key that defines the property key to be used when displaying an error message to the user, a string containing information for developers that will be used as log statement and an optional level defining the log level for the message. The latter is useful since not everything that causes request abortion is an error like a user providing an invalid password.

The exception class wraps that MessageCode and creates a log statement within it's constructor. Of course this has a draw back, most logging frameworks like e.g. log4j allow to automatically augment the log message with the class name and line number where the message was logged. With the log statement being created within the exception that piece of informaton is lost. To get around this limitation I am using the exeptions own stacktrace by accessing it's first element that contains the class name and line number where the exception constructor was invoked.

That way it is possible to log an error and abort request execution with one statement in your application code and by incooperating this capability into the exception class itself you can create your application specific exception hierarchy that inherits this behavior.

So far I am only using this pattern in my private projects but I am thinking of also introducing it to my customers' projects.

As always I would be very interessted in what you guys think of this approach especially if you see any problems with it or have suggestions for improvements.