Quick Start Guide to Enterprise AOP with Aspectwerkz 2.0
Pages: 1, 2, 3

Problems with the Sample Application Implementation

I have hinted at a few of the issues with the implementation of the blog application, but I would like to highlight them again and explain why they are a problem:

  1. Verbosity
    For our logger and profiler to work properly, we must include the enter/exit code in every method. In some cases you need to change your code style to allow an exit to be called before returning from a method. For example, if you want the profiler to properly time your method, you must call exit before throwing an exception or returning from the method. This is a burden on developers and causes the code to become bloated.

  2. Inability to easily refactor code
    Refactoring code to become more natural is a best practice, and anything that makes refactoring more difficult can cause developers to avoid it entirely. Changing method names is a regular occurrence that leaves the statically declared enter/exit method names incorrect. At best, this will require a manual update; at worst, the incorrect names will be accidentally left in the code and cause confusion during debugging.

  3. Inability to enforce proper usage without code reviews
    Apart from conducting regular code reviews, there is no way to ensure that everyone on the team is following the project's logging guidelines. If these are not consistently followed, the profiling and trace information loses its value.

  4. Tight coupling of logging and profiling concerns
    Having the profiling concern baked into the logging code makes it very difficult to profile only certain code paths. For example, it is desirable to profile all ServletRequests and to log an error if any request takes more than five seconds. Other tasks such as initializing the Application servlet should be allowed to take more than five seconds without triggering an error, but we would still like to log it for informational purposes. If an error is generated during initialization, it is likely that the logging code will be commented out or the maximum elapse time will be increased to 10 seconds. (Unfortunately, this is a true story from one of my non-AOP projects where initialization took eight seconds.)

Points 1, 2, and 3 can be a real burden for developers. Developers have enough to worry about without the added concern of logging and profiling. Of course, developers will define templates for auto-completion of enter/exit method calls, but they must remember to do this consistently and fix errors caused by refactoring.

To illustrate how much of a burden this type of implementation can be, consider how much time per class you will spend implementing logging over the lifetime of a project. At a recent conference, Adrian Coyler, a core committer to AspectJ, speculated on the amount of development time that is invested in implementing logging consistently on a medium- to large-sized project. He estimated that a developer spends 15 minutes per class implementing logging over the course of a project. (Even when using code completion, one must consider the impact of refactoring.) On a relatively small project with 500 classes, an astonishing 3.5 weeks of the project schedule is spent implementing logging! Let's fix this by introducing some aspects to handle it for us.

Refactoring to Use AOP

Before using AOP we need to decide which framework we want to use. There are several competing AOP frameworks in existence today, and in my opinion, AspectWerkz and AspectJ are the most compelling, based on their functionality and overall popularity. For this article I will demonstrate how to leverage the AspectWerkz framework, using the new 2.0 release.

Having to choose between AspectJ and AspectWerkz was a tough decision. Thankfully, AspectJ and AspectWerkz recently agreed to join forces and collaborate on the release of AspectJ 5. The current AspectWerkz 2.0 release will be the final release, and all new development will be done in the AspectJ branch. Consolidation in the AOP space is ultimately a good thing for developers, as the current variety of platforms can make it intimidating for new users. Furthermore, having two strong development teams and communities consolidated into a single, stronger unit will help push forward the boundaries of AOP.

Before we dive into applying aspects to our code base, we need to make some decisions on how we want to use AspectWerkz.

Annotations versus XML

AspectWerkz gives you two options when it comes to defining your pointcuts: annotations within your Java class files, or using XML defined in an external file named aop.xml. Defining your pointcuts directly in code using annotations is very nice, but if you are not using JDK 5 you will be forced to include an additional build step to generate the aop.xml file. When using JDK 5, I prefer to define the aspects in XML and use annotations for the pointcuts. This way the pointcuts are coupled with the code, while the aspects may easily be changed (or removed) simply by editing aop.xml. I wanted this article to be immediately applicable to the widest audience possible, so JDK 5 is assumed not to be readily available.

Since I have a real distaste for requiring compile-time steps during development, I elected to define everything directly in aop.xml. This decision forces us to define rather complex pointcuts using the aop.xml notation, but in my opinion this is better than slowing down the development cycle. This article will use aop.xml definitions exclusively.

Online versus offline weaving

A great deal of AspectWerkz's flexibility comes from its ability to run in both online and offline modes. In the online mode AspectWerkz weaves your classes dynamically at runtime. With the offline mode, an additional compilation step is required to weave your classes during the build phase. This flexibility provides developers with the ability to pick the best mode for a specific task.

For example, during development time, online mode is a great choice. It doesn't require a compilation or weaving step during the development cycle. Also, since it is development time, you have full control over the JVM runtime and therefore don't mind customizing the JVM startup, which is required by online weaving.

When needed, you can switch to offline mode. There are two main reasons why you would want to do this. First, pre-weaved classes are very performant; they perform similar to "normal" classes that contain the same functionality. Second, there is no need to change the JVM settings. This is important for hosted environments or when dealing with conservative administrators. The downside to offline mode is that you can only apply your aspects to code you package yourself. This means that you cannot have your aspects applied to any third-party libraries that you may be using (unless you repackage them).

I use online mode during the development phase and then switch to offline mode for deployments. This allows me to avoid an extra build step, and since it's development, I am not worried about performance or changing the JVM settings. For this article, offline weaving was used on the packaged WAR file so that readers don't need to customize their JVM to test the application.

To weave your classes offline using AspectWerkz, integrate the following target into your ant script:

<target name="weave">

  <property name="AW_LIB" 

      value="c:/opt/aspectwerkz-2.0/lib"/>

  <taskdef name="awc" 

    classname="org.codehaus.aspectwerkz.compiler.AspectWerkzCTask">

    <classpath>

      <pathelement 

          path="${AW_LIB}/aspectwerkz-2.0.jar"/>

      <pathelement 

          path="${AW_LIB}/aspectwerkz-core-2.0.jar"/>

      <pathelement 

          path="${AW_LIB}/aspectwerkz-extensions-2.0.jar"/>

    </classpath>

  </taskdef>

                

  <awc verbose="true"

      targetdir="web\WEB-INF\classes">

    <classpath>

      <fileset dir="lib"/>

    </classpath>

  </awc>

</target>

Applying a Logging Aspect to the Sample Application

We have all seen the simple tracing aspect that epitomized AOP in the early days. It simply wrapped all method calls with a call to System.out.println() before and after each method invocation. Of course, this is completely useless for a production environment. We want to use Log4J for its many benefits.

As shown in the previous sample code, to log with Log4J you need to instantiate the logger with a category name. The usual convention is to use the fully qualified class as the category name as follows:

private static final Log log = Log.getLog(EntryHibernateDao.class);

We want an aspect that has the same characteristics as the above definition, namely:

  1. The Log is instantiated once and only once per class.
  2. Each class has its own Log that uses the fully qualified class name as the category.

To achieve the above requirements, we need to do more than just apply our logging aspect to our pointcuts. We must "inject" the log definition into our classes using a mixin. Mixins provide a way of adding additional functionality to a set of classes and are especially useful for situations where boilerplate code is required to be implemented in multiple classes. Using a mixin, we can instruct AspectWerkz to modify our classes to add behavior to the classes. In this case, we will have AspectWerkz modify our classes to implement a Loggable interface that will be used to return a Log instance that meets the above requirements. The following code defines the Loggable interface and its implementation:

public interface Loggable {

    Log getLog();

}



public class LoggableImpl implements Loggable {

    private final Log log;

    public LoggableImpl(Class targetClass) {

        log = Log.getLog(targetClass);

    }



    public Log getLog() { return log; }

}

We now want to instruct AspectWerkz to modify our classes to implement the Loggable interface; to do this we add the following XML definition to aop.xml:

<mixin class="com.handyware.aop.LoggableImpl" 

  deployment-model="perClass"

  bind-to="within(com.tss..*) 

            AND avoidTrace"/> 

This mixin is instructing AspectWerkz to add a LoggableImpl field to each class in our system that we want to log. To see what this does, we can decompile the generated class. The following code is what the weaved EntryHibernateDao class contains:

public class EntryHibernateDao 

         extends HibernateDaoSupport

         implements Loggable, IEntryDao

{

   private static final LoggableImpl aw$MIXIN_0; 

   public Log getLog() {

     return aw$MIXIN_0.getLog();

   }

   static {

     aw$clazz = Class.forName(

       "com.tss.blog.service.EntryHibernateDao");

     aw$MIXIN_0 = (LoggableImpl)Mixins.mixinOf(

       "com.tss.blog.aop.LoggableImpl", 

       aw$clazz);

   }

    

   ....

}

As you can see, AspectWerkz has modified the original class to include a LoggableImpl static field and has initialized it to a Log instance that is specific to the class. Now that we have a getLog() method in each of our classes, defining the Log4J logging aspect is very straightforward:

public class LoggingIdiom {

    public Object traceWithParams(

                 JoinPoint jp, Loggable loggable)

                 throws Throwable {

        loggable.getLog().enter(enterTrace(jp));

        Object result = jp.proceed();

        loggable.getLog().exit(exitTrace(jp, result));

        return result;

    }

}

And to weave this aspect into our code, we add the following to our aop.xml definition:

<aspect class="com.tss.aop.LoggingIdiom">

  <pointcut name="p2" 

      expression="execution(* com.tss..*.*(..))

                        AND avoidTrace" />

  <advice name="traceWithParams(JoinPoint jp, 

                 com.tss.aop.Loggable loggable)" 

               type="around" 

               bind-to="p2 AND target(loggable)" />

</aspect>

You'll notice in the logging aspect definition above that we defined an avoidTrace pointcut that allowed us to exclude those classes that we didn't want to log. The pointcut model is very powerful as it allows you to be very selective in how your aspects are applied.

For example, Hibernate uses a dynamic subclassing technique and by default, the logging aspect will be applied to these new classes, which you likely don't want. We can exclude these from our logs to simplify them. To do this, we simply exclude all point cuts that are related to Hibernate. Other examples include JavaBean accessors and the logging aspect itself—otherwise we could get in an infinite loop logging the logger!

Pages: 1, 2, 3

Next Page »