Software Journal

By the time we get to step 5 of Mapricot (our eight step process for handling errors in production systems), we have already identified the error, addressed it, and now we are on the prowl for improving other parts of code, such as logging, the “I” phase of Mapricot.

In the analysis phase, something always catches the eye: tons of “unknown” exceptions, or other exceptions with inadequate details in the log. The most interesting, as well as common, mistake is some code that is absorbing an exception, and logging some generic message, such as the following masterpiece:

try {
// functionality
} catch (Exception e) {
log (“Exception in the functionality!”);
// No details of the exception e, and generic statement
}
This is a classic mistake, where the log statement is generic, and is actually losing out on all the details of the exception. Obviously, this code should be replaced by something as:

try {
// functionality
} catch (Exception e) {
log (“Exception in saving: ” + e, e); // Log both the message, and the exception trace
// throw e; // Rethrow the exception if suitable.
}

Another classic mistake is where the code throws a NEW exception, that is not a wrapper on the old exception.

try {
// functionality
} catch (Exception e) {
throw new Exception (“Exception in functionality”); // bad code – lost the original exception!
}

More appropriate is to do:
try {
// functionality
} catch (Exception e) {
throw new Exception (“Exception in functionality”, e); // Wrap the exception
// or
throw e; // Rethrow the original exception
}

A similar problem comes with SQLException, since that does not have a constructor that takes the inner exception as an argument. In that case, the initCause method can be used:

method throws SQLException {
try {
// try block
} catch (Exception e) {
SQLException sqle = new SQLException(e.toString()); sqle.initCause(e); throw sqle;
// those 3 statements on one line, so that line numbers in debug stmts are consistent
}

Now that we have established patterns of the problem code, we can scan the entire application and find the instances of problem code. Regular expression searches come in quite handy for this.

A second broad category of code instances where “I” phase is helpful is where supposedly significant logging is already in place, but yet we are not able to identify what is causing the error to happen. So, the idea is that while we will not be able to resolve the error in the upcoming build, at least we will improve the logging, and then reexamine the error, and fix in the next build after that. Following is an example of this:

if (matchingInvoiceCount == 0) {
throw new IllegalArgumentException (“Strange, no matching invoice found, for reference # ” + refNumber);
// The logging is fine, and we are struggling to identify why does the invoice not exist
}

One possible improvement that we may then be able to make is:
if (matchingInvoiceCount == 0) {
throw new IllegalArgumentException (“Strange, no matching invoice found, for reference # ” +
refNumber + “, modelPK: ” + invoiceModel.getPK() +
“, model XML: ” + invoiceModel.getXML());
// “Improved” logging – see if the model has a PK, and see if the XML shows any
// reasons why the save could have failed earlier.
// Perhaps we will identify the cause of the error in next release logs
}

All in all, the “I” phase of MAPRICOT should be taken as a way to piggyback some changes about errors that are in general happening, but we are not getting enough information about those errors. The problems that we are able to apply the “I” phase on, will likely be problems that we may be able to apply the prioritization phase in the next build.