What is a good way to pass useful state informatio

Question

I noticed some confusion initially with my question. I'm not asking about how to configure a logger nor how to use a logger properly, but rather how to capture all of the information that would have been logged at a lower logging level than what the current logging level is in the exception message.

I have been noticing two patterns in Java for logging information that may be useful to a developer when an exception occurs.

The following pattern seems very common. Basically, you just have your logger log information in-line as needed, so that when an exception occurs you have the log trace.

try {
    String myValue = someObject.getValue();
    logger.debug("Value: {}", myValue);
    doSomething(myValue);
}
catch (BadThingsHappenException bthe) {
    // consider this a RuntimeException wrapper class
    throw new UnhandledException(bthe);
}

The drawback with the above approach is that if your users require relatively quiet logs and need a high level of reliability to the point where they just can't "try it again in debug mode", the exception message contains insufficient data by itself to be useful to the developer.

The next pattern is one that I have seen that tries to mitigate this problem but seems ugly:

String myValue = null;
try {
    myValue = someObject.getValue();
    doSomething(myValue);
}
catch (BadThingsHappenException bthe) {
    String pattern = "An error occurred when setting value. [value={}]";
    // note that the format method below doesn't barf on nulls
    String detail = MessageFormatter.format(pattern, myValue);
    // consider this a RuntimeException wrapper class
    throw new UnhandledException(detail, bthe);
}

The above pattern seems to somewhat solve the problem, however I'm not sure I like to declare so many variables outside the scope of the the try block. Especially, when I have to deal with very complicated states.

The only other approach I have seen is using a Map to store key value pairs that are then dumped into the exception message. I'm not sure I like that approach either since it seems to create code bloat.

Is there some Java vodoo out there that I am missing? How do you handle your exception state information?

Answer 1

We tend to create our most important application specific runtime exception classes with some special constructors, some constants and a ResourceBundle.

Example snippet:

 public class MyException extends RuntimeException
 {
    private static final long serialVersionUID = 5224152764776895846L;

    private static final ResourceBundle MESSAGES;
    static
    {
        MESSAGES = ResourceBundle.getBundle("....MyExceptionMessages");
    }

    public static final String NO_CODE = "unknown";
    public static final String PROBLEMCODEONE = "problemCodeOne";
    public static final String PROBLEMCODETWO = "problemCodeTwo";
    // ... some more self-descriptive problem code constants

    private String errorCode = NO_CODE;
    private Object[] parameters = null;

    // Define some constructors

    public MyException(String errorCode)
    {
        super();
        this.errorCode = errorCode;
    }

    public MyException(String errorCode, Object[] parameters)   
    {
        this.errorCode = errorCode;
        this.parameters = parameters;
    }

    public MyException(String errorCode, Throwable cause)
    {
        super(cause);
        this.errorCode = errorCode;
    }

    public MyException(String errorCode, Object[] parameters, Throwable cause)
    {
        super(cause);
        this.errorCode = errorCode;
        this.parameters = parameters;
    }   

    @Override
    public String getLocalizedMessage()
    {
        if (NO_CODE.equals(errorCode))
        {
            return super.getLocalizedMessage();
        }

        String msg = MESSAGES.getString(errorCode); 
        if(parameters == null)
        {
            return msg;
        }
        return MessageFormat.format(msg, parameters);
    }
 }

In the properties file we specify the exception descriptions, e.g.:

 problemCodeOne=Simple exception message
 problemCodeTwo=Parameterized exception message for {0} value

Using this approach

• We can use quite readable and understandable throw clauses (throw new MyException(MyException.PROBLEMCODETWO, new Object[] {parameter}, bthe))
• The exception messages are "centralized", can easily maintained and "internationalized"

EDIT: change getMessage to getLocalizedMessage as Elijah suggested.

EDIT2: Forgot to mention: this approach does not support Locale changing "on-the-fly" but it is intentional (it can be implemented if you need it).

Answer 2

One option that no one seems to have mentioned yet is to use a logger that logs to an in memory buffer, and only pushes the information into the actual log target under certain circumstances (e.g., an error level message is logged).

If you're using the JDK 1.4 logging facilities, MemoryHandler does exactly this. I'm not sure if the logging system you're using does this, but I imagine you should be able to implement your own appender/handler/whatever that does something similar.

Also, I just want to point out that in your original example, if your concern is variable scope, you could always define a block to reduce the scope of your variable:

{
    String myValue = null;
    try {
        myValue = someObject.getValue();
        doSomething(myValue);
    }
    catch (BadThingsHappenException bthe) {
        String pattern = "An error occurred when setting value. [value={}]";
        // note that the format method below doesn't barf on nulls
        String detail = MessageFormatter.format(pattern, myValue);
        // consider this a RuntimeException wrapper class
        throw new UnhandledException(detail, bthe);
    }
}

Answer 3

Perhaps I'm missing something, but if the users really require a relatively quiet log file, why don't you just configure your debug logs to go to a separate spot?

If that's insufficient, then capture a fixed amount of the debug logs in RAM. E.g., the last 500 entries. Then, when something ugly happens, dump the debug logs along with the problem report. You don't mention your logging framework, but this would be pretty easy to do in Log4J.

Even better, assuming you have the user's permission, just send an automatic error report rather than logging. I recently helped some folks run down a hard-to-find bug and made the error reporting automatic. We got 50x the number of bug reports, making the problem pretty easy to find.

Answer 4

As for the type of debug information you need, why don't you just always log the value and don't bother so much with a local try/catch. Just use the Log4J config file to point your debug messages to a different log, or use chainsaw so you can remotely follow the log messages. If all that fails maybe you need a new log message type to add to debug()/info()/warn()/error()/fatal() so you have more control over which messages get sent where. This would be the case when defining appenders in the log4j config file is impractical due to the high number of places where this type of debug logging needs to be inserted.

While we're on the subject, you've touched on one of my pet peeves. Constructing a new exception in the catch block is a code smell.

Catch(MyDBException eDB)
{
    throw new UnhandledException("Something bad happened!", eDB);
}

Put the message in the log and then rethrow the exception. Constructing Exceptions is expensive and can easily hide useful debugging information.

First off, inexperienced coders and those who like to cut-n-paste (or begin-mark-bug, end-mark-bug, copy-bug, copy-bug, copy-bug) it can transform easily to this:

Catch(MyDBException eDB)
{
    throw new UnhandledException("Something bad happened!");
}

Now you've lost the original stacktrace. Even in the first case, unless the wrapping Exception handles the wrapped exception properly, you can still lose details of the original exception, the stacktrace being the most likely.

Rethrowing exceptions might be necessary but I've found that it should be handled more generally and as a strategy to communicate between layers, like between your business code and the persistance layer, like so:

Catch(SqlException eDB)
{
    throw new UnhandledAppException("Something bad happened!", eDB);
}

and in this case, the catch block for the UnhandledAppException is much further up the call stack where we can give the user an indication that they either need to retry their action, report a bug, or whatever.

This let our main() code do something like this

catch(UnhandledAppException uae)
{
    \\notify user
    \\log exception
}
catch(Throwable tExcp)
{
    \\for all other unknown failures
    \\log exception

}
finally
{
    \\die gracefully
}

Doing it this way meant that local code could catch the immediate and recoverable exceptions where debug logs could be done and the exception not have to be rethrown. This would be like for DivideByZero or maybe a ParseException of some sort.

As for "throws" clauses, having a layer-based exception strategy meant being able to limit the number of exception types that have to be listed for each method.

Answer 5

If you want to somehow process the details of the error message, you could:

• Use an XML text as the message, so you get a structured way:

  throw new UnhandledException(String.format(
      "<e><m>Unexpected things</m><value>%s</value></e>", value), bthe);
  

• Use your own (and one for every case) exception types to capture variable information into named properties:

  throw new UnhandledValueException("Unexpected value things", value, bthe);
  

Or else you could include it in the raw message, as suggested by others.