Development Aspects

Tracing using aspects

(The code for this example is in InstallDir/examples/tracing.)

Writing a class that provides tracing functionality is easy: a couple of functions, a boolean flag for turning tracing on and off, a choice for an output stream, maybe some code for formatting the output -- these are all elements that Trace classes have been known to have. Trace classes may be highly sophisticated, too, if the task of tracing the execution of a program demands it.

But developing the support for tracing is just one part of the effort of inserting tracing into a program, and, most likely, not the biggest part. The other part of the effort is calling the tracing functions at appropriate times. In large systems, this interaction with the tracing support can be overwhelming. Plus, tracing is one of those things that slows the system down, so these calls should often be pulled out of the system before the product is shipped. For these reasons, it is not unusual for developers to write ad-hoc scripting programs that rewrite the source code by inserting/deleting trace calls before and after the method bodies.

AspectJ can be used for some of these tracing concerns in a less ad-hoc way. Tracing can be seen as a concern that crosscuts the entire system and as such is amenable to encapsulation in an aspect. In addition, it is fairly independent of what the system is doing. Therefore tracing is one of those kind of system aspects that can potentially be plugged in and unplugged without any side-effects in the basic functionality of the system.

An Example Application

Throughout this example we will use a simple application that contains only four classes. The application is about shapes. The TwoDShape class is the root of the shape hierarchy:

public abstract class TwoDShape {
    protected double x, y;
    protected TwoDShape(double x, double y) {
        this.x = x; this.y = y;
    }
    public double getX() { return x; }
    public double getY() { return y; }
    public double distance(TwoDShape s) {
        double dx = Math.abs(s.getX() - x);
        double dy = Math.abs(s.getY() - y);
        return Math.sqrt(dx*dx + dy*dy);
    }
    public abstract double perimeter();
    public abstract double area();
    public String toString() {
        return (" @ (" + String.valueOf(x) + ", " + String.valueOf(y) + ") ");
    }
}

TwoDShape has two subclasses, Circle and Square:

public class Circle extends TwoDShape {
    protected double r;
    public Circle(double x, double y, double r) {
        super(x, y); this.r = r;
    }
    public Circle(double x, double y) { this(  x,   y, 1.0); }
    public Circle(double r)           { this(0.0, 0.0,   r); }
    public Circle()                   { this(0.0, 0.0, 1.0); }
    public double perimeter() {
        return 2 * Math.PI * r;
    }
    public double area() {
        return Math.PI * r*r;
    }
    public String toString() {
        return ("Circle radius = " + String.valueOf(r) + super.toString());
    }
}
public class Square extends TwoDShape {
    protected double s;    // side
    public Square(double x, double y, double s) {
        super(x, y); this.s = s;
    }
    public Square(double x, double y) { this(  x,   y, 1.0); }
    public Square(double s)           { this(0.0, 0.0,   s); }
    public Square()                   { this(0.0, 0.0, 1.0); }
    public double perimeter() {
        return 4 * s;
    }
    public double area() {
        return s*s;
    }
    public String toString() {
        return ("Square side = " + String.valueOf(s) + super.toString());
    }
}

To run this application, compile the classes. You can do it with or without ajc, the AspectJ compiler. If you've installed AspectJ, go to the directory InstallDir/examples and type:

ajc -argfile tracing/notrace.lst

To run the program, type

java tracing.ExampleMain

(we don't need anything special on the classpath since this is pure Java code). You should see the following output:

c1.perimeter() = 12.566370614359172
c1.area() = 12.566370614359172
s1.perimeter() = 4.0
s1.area() = 1.0
c2.distance(c1) = 4.242640687119285
s1.distance(c1) = 2.23606797749979
s1.toString(): Square side = 1.0 @ (1.0, 2.0)

Tracing—Version 1

In a first attempt to insert tracing in this application, we will start by writing a Trace class that is exactly what we would write if we didn't have aspects. The implementation is in version1/Trace.java. Its public interface is:

public class Trace {
    public static int TRACELEVEL = 0;
    public static void initStream(PrintStream s) {...}
    public static void traceEntry(String str) {...}
    public static void traceExit(String str) {...}
}

If we didn't have AspectJ, we would have to insert calls to traceEntry and traceExit in all methods and constructors we wanted to trace, and to initialize TRACELEVEL and the stream. If we wanted to trace all the methods and constructors in our example, that would amount to around 40 calls, and we would hope we had not forgotten any method. But we can do that more consistently and reliably with the following aspect (found in version1/TraceMyClasses.java):

aspect TraceMyClasses {
    pointcut myClass(): within(TwoDShape) || within(Circle) || within(Square);
    pointcut myConstructor(): myClass() && execution(new(..));
    pointcut myMethod(): myClass() && execution(* *(..));

    before (): myConstructor() {
        Trace.traceEntry("" + thisJoinPointStaticPart.getSignature());
    }
    after(): myConstructor() {
        Trace.traceExit("" + thisJoinPointStaticPart.getSignature());
    }

    before (): myMethod() {
        Trace.traceEntry("" + thisJoinPointStaticPart.getSignature());
    }
    after(): myMethod() {
        Trace.traceExit("" + thisJoinPointStaticPart.getSignature());
    }
}

This aspect performs the tracing calls at appropriate times. According to this aspect, tracing is performed at the entrance and exit of every method and constructor defined within the shape hierarchy.

What is printed at before and after each of the traced join points is the signature of the method executing. Since the signature is static information, we can get it through thisJoinPointStaticPart.

To run this version of tracing, go to the directory InstallDir/examples and type:

  ajc -argfile tracing/tracev1.lst

Running the main method of tracing.version1.TraceMyClasses should produce the output:

  --> tracing.TwoDShape(double, double)
  <-- tracing.TwoDShape(double, double)
  --> tracing.Circle(double, double, double)
  <-- tracing.Circle(double, double, double)
  --> tracing.TwoDShape(double, double)
  <-- tracing.TwoDShape(double, double)
  --> tracing.Circle(double, double, double)
  <-- tracing.Circle(double, double, double)
  --> tracing.Circle(double)
  <-- tracing.Circle(double)
  --> tracing.TwoDShape(double, double)
  <-- tracing.TwoDShape(double, double)
  --> tracing.Square(double, double, double)
  <-- tracing.Square(double, double, double)
  --> tracing.Square(double, double)
  <-- tracing.Square(double, double)
  --> double tracing.Circle.perimeter()
  <-- double tracing.Circle.perimeter()
c1.perimeter() = 12.566370614359172
  --> double tracing.Circle.area()
  <-- double tracing.Circle.area()
c1.area() = 12.566370614359172
  --> double tracing.Square.perimeter()
  <-- double tracing.Square.perimeter()
s1.perimeter() = 4.0
  --> double tracing.Square.area()
  <-- double tracing.Square.area()
s1.area() = 1.0
  --> double tracing.TwoDShape.distance(TwoDShape)
    --> double tracing.TwoDShape.getX()
    <-- double tracing.TwoDShape.getX()
    --> double tracing.TwoDShape.getY()
    <-- double tracing.TwoDShape.getY()
  <-- double tracing.TwoDShape.distance(TwoDShape)
c2.distance(c1) = 4.242640687119285
  --> double tracing.TwoDShape.distance(TwoDShape)
    --> double tracing.TwoDShape.getX()
    <-- double tracing.TwoDShape.getX()
    --> double tracing.TwoDShape.getY()
    <-- double tracing.TwoDShape.getY()
  <-- double tracing.TwoDShape.distance(TwoDShape)
s1.distance(c1) = 2.23606797749979
  --> String tracing.Square.toString()
    --> String tracing.TwoDShape.toString()
    <-- String tracing.TwoDShape.toString()
  <-- String tracing.Square.toString()
s1.toString(): Square side = 1.0 @ (1.0, 2.0)

When TraceMyClasses.java is not provided to ajc, the aspect does not have any affect on the system and the tracing is unplugged.

Tracing—Version 2

Another way to accomplish the same thing would be to write a reusable tracing aspect that can be used not only for these application classes, but for any class. One way to do this is to merge the tracing functionality of Trace—version1 with the crosscutting support of TraceMyClasses—version1. We end up with a Trace aspect (found in version2/Trace.java) with the following public interface

abstract aspect Trace {

    public static int TRACELEVEL = 2;
    public static void initStream(PrintStream s) {...}
    protected static void traceEntry(String str) {...}
    protected static void traceExit(String str) {...}
    abstract pointcut myClass();
}

In order to use it, we need to define our own subclass that knows about our application classes, in version2/TraceMyClasses.java:

public aspect TraceMyClasses extends Trace {
    pointcut myClass(): within(TwoDShape) || within(Circle) || within(Square);

    public static void main(String[] args) {
        Trace.TRACELEVEL = 2;
        Trace.initStream(System.err);
        ExampleMain.main(args);
    }
}

Notice that we've simply made the pointcut classes, that was an abstract pointcut in the super-aspect, concrete. To run this version of tracing, go to the directory examples and type:

  ajc -argfile tracing/tracev2.lst

The file tracev2.lst lists the application classes as well as this version of the files Trace.java and TraceMyClasses.java. Running the main method of tracing.version2.TraceMyClasses should output exactly the same trace information as that from version 1.

The entire implementation of the new Trace class is:

abstract aspect Trace {

    // implementation part

    public static int TRACELEVEL = 2;
    protected static PrintStream stream = System.err;
    protected static int callDepth = 0;

    public static void initStream(PrintStream s) {
        stream = s;
    }
    protected static void traceEntry(String str) {
        if (TRACELEVEL == 0) return;
        if (TRACELEVEL == 2) callDepth++;
        printEntering(str);
    }
    protected static void traceExit(String str) {
        if (TRACELEVEL == 0) return;
        printExiting(str);
        if (TRACELEVEL == 2) callDepth--;
    }
    private static void printEntering(String str) {
        printIndent();
        stream.println("--> " + str);
    }
    private static void printExiting(String str) {
        printIndent();
        stream.println("<-- " + str);
    }
    private static void printIndent() {
        for (int i = 0; i < callDepth; i++)
            stream.print("  ");
    }

    // protocol part

    abstract pointcut myClass();

    pointcut myConstructor(): myClass() && execution(new(..));
    pointcut myMethod(): myClass() && execution(* *(..));

    before(): myConstructor() {
        traceEntry("" + thisJoinPointStaticPart.getSignature());
    }
    after(): myConstructor() {
        traceExit("" + thisJoinPointStaticPart.getSignature());
    }

    before(): myMethod() {
        traceEntry("" + thisJoinPointStaticPart.getSignature());
    }
    after(): myMethod() {
        traceExit("" + thisJoinPointStaticPart.getSignature());
    }
}

This version differs from version 1 in several subtle ways. The first thing to notice is that this Trace class merges the functional part of tracing with the crosscutting of the tracing calls. That is, in version 1, there was a sharp separation between the tracing support (the class Trace) and the crosscutting usage of it (by the class TraceMyClasses). In this version those two things are merged. That's why the description of this class explicitly says that "Trace messages are printed before and after constructors and methods are," which is what we wanted in the first place. That is, the placement of the calls, in this version, is established by the aspect class itself, leaving less opportunity for misplacing calls.

A consequence of this is that there is no need for providing traceEntry and traceExit as public operations of this class. You can see that they were classified as protected. They are supposed to be internal implementation details of the advice.

The key piece of this aspect is the abstract pointcut classes that serves as the base for the definition of the pointcuts constructors and methods. Even though classes is abstract, and therefore no concrete classes are mentioned, we can put advice on it, as well as on the pointcuts that are based on it. The idea is "we don't know exactly what the pointcut will be, but when we do, here's what we want to do with it." In some ways, abstract pointcuts are similar to abstract methods. Abstract methods don't provide the implementation, but you know that the concrete subclasses will, so you can invoke those methods.