Stack Trace Beautification

Introduction

Consider the following code snippet showing a "main" method:

    public static void main(String[] args) {
        int status = 0;
        sLog.info("Started");
        try {
            Integer.parseInt("");
        } catch (Throwable exc) {
            status = 1;
            sLog.warn("Error", exc);
        } finally {
            System.exit(status);
        }
    }

This code is guaranteed to throw a "NumberFormatException" at the line "Integer.parseInt("")". The stack trace of this exception looks like this:

This stack trace gives us some basic information that allows us to figure out where the exception was thrown from (Line 18 of the class "com.subhajit.stacktrace.log4j.Test"'s  "main" method). Now consider the following stack trace thrown by this same code snippet:

This stack trace shows the line of source code that caused the exception in the context of the surrounding source code. Having this context captured in the source code is useful for several reasons:

 1. Developers inspecting the stack trace save the step of correlating line numbers with the source code: the source code surrounding the offending line is available in the stack trace itself.

2. Often, with older releases, line numbers of code in the latest release under development might not match the corresponding line numbers in the older release. Developers faced with a bare stack trace must a) figure out what version of the build caused the stack trace to be thrown, b) Check out the older version from a source code repository and then c) figure out the offending code. Again, having the offending line of source code in the context of its immediate surroundings helps to save time in these situations.

In this article, I show how to accomplish this "stack trace beautification", and provide several techinuqes to integrate this functionality in your code (such as a log4j layout and an aspect based load time weaving launch configuration).

The Basic problem

The basic problems to be solved are the capture and the formatting of exception stack traces as exceptions are thrown in a running system. We will look at the problem of capturing exceptions later: first, we look at what we must do to generate beautified stack traces from exceptions we have already caught.

Beautifying stack traces

The source code provided with this article contains a class named "com.subhajit.stacktrace.base.SourceCodeBeautifier"  that performs stack trace beautification. This class depends upon a system property named "src" that provides a comma-separated list of source code locations (eg. "/src,%JAVA_HOME%/src.zip,...). This class examines the StackTraceElement[] of the exception, and, for every class it finds that has source code available, it picks out a bunch of lines of source code before and after the offending line. Then, it indents and formats these lines of source code properly, drawing an "arrow" shape to point at the offending line within this bunch of lines. For classes which do not have source code available, it appends an ordinary message showing the file and line number (if available), just as it would appear in a "normal" stack trace. Finally, it returns the properly formatted stack trace to the caller. See the overrides of the "printStackTrace" methods of this class for details.

A convenience class ("com.subhajit.stacktrace.base.ThrowableHolder2") is provided that can be used as follows:

new ThrowableHolder2(exc).printStackTrace() prints the beautified stack trace of the exception "exc" to System.err

new ThrowableHolder2(exc).printStackTrace(PrintStream ps) prints out the beautified stack trace to the given PrintStream, while new ThrowableHolder2(exc).printStackTrace(PrintWriter pw) prints out beautified stack trace information to the provided PrintWriter.

Capturing exceptions

It is little use having a stack trace beautification scheme unless it is easily integrated into your existing build and release practices. Also, I daresay that the less invasive this integration is (meaning, the less things you have to change to accomodate this scheme), the more readily would you consider using it. Accordingly, I provide two techniques to integrate this scheme into your own projects.

Capturing exceptions using log4j

The first technique assumes that you use log4j for logging, and you already have code and configuration that logs all interesting exceptions. In other words, your project already has a "log4j.properties" file that describes how you log messages, and your project already uses this file to configure log4j logging.

The "com.subhajit.stacktrace.log4j.CustomLayout"  class extends the log4j PatternLayout class to provide beautified stack traces. The following snippet of a log4j properties file shows how to use the CustomLayout class:

To have the CustomLayout beautify stack traces, don't forget to define the system property "src" to point to a comma separated list of source code locations (which could be directories or zip files containing source code). On my computer, I use the following command line to run the "stack-trace-log4j.jar" test program:

AspectJ based capture

Using the log4j based scheme above requires changes to your application classpath (to include stack-trace-log4j.jar) and log4j configuration. Using the AspectJ based capture described below, no changes are required to your application components. Capture is accomplished simply by modifying your application launch configuration.

Using the scheme described here does not requires that you have minimal to no understanding of AspectJ (http://www.eclipse.org/aspectj/). All you do is create a "launcher" script that launches your program. The "com.subhajit.stacktrace.aspectj.admin.CommandGenerator"  class generates launcher scripts given the following information:

1. An output directory where the generated launch scripts are saved, along with some supporting files.


2. A comma separated list of source code locations (directories or zip files).


3. A comma separated list of classpath elements (JAR files and directories containing CLASS files) required by your application to run.


4. The name of the "main class" of your application (the class containing the "main" method).

Running the command generator using the following command line:

results in the creation of a directory named "temp" (specified by the "-dir" argument), containing the following files:

The two launch files generated, named "launch.cmd" and "launch.sh", serve to launch your application on Windows and Solaris/Linux, respectively. The Windows version of this file looks like this (the indented lines at the end of the file are actually part of the line starting with "java -cp ":

In the launch script above:

1. ASPECTPATH is the location of the stack-trace-agent.jar file.


2. SRCPATH is a comma separated list of directories and zip files containing source files.


3. APPCLASSPATH is a list of application classpath elements, such as JAR files and directories containing CLASS files.
   

This launch script uses AspectJ's "load time weaving" functionality via its "WeavingURLClassLoader". I could not make this work using the new "agentlib" load time weaving mechanism.

Source code

The source code provided with this article contains several Eclipse projects:

stack-trace-base	Contains base classes to format stack traces with embedded source code snippets.
stack-trace	Contains the AspectJ based exception capture mechanism.
stack-trace-admin	Contains tools (such as CommandGenerator) to generate AspectJ based launchers utilizing load time weaving to capture exceptions.
stack-trace-log4j	Contains a log4j Layout (CustomLayout) and a sample log4j.properties file showing how to update your log4j configuration to format stack traces.

Source code for this article is available for download.

Conclusion

Capturing and logging exception stack traces containing source code snippets helps developers rapidly identify (or hypothesize about) problems. This article presents a simple mechanism to accomplish the inclusion of source code snippets in exception stack traces.