Spring AOP Tutorial

Application logic can be broken into 2 distinct areas, core business logic and cross cutting concerns. Business logic is code written to satisfy a functional requirement, while a cross cutting concern is ‘utility’ logic that is agnostic to a specific business process but required by many parts of the application. Examples include logging, transaction management, performance monitoring and security. While none of these address a functional requirement, they remain fundamental parts of the application.

Cross cutting concerns present 2 main challenges.

  1. They tend to be ‘scattered’ across the application which can lead to considerable duplicate code. Logging or performance monitoring is a good example.
  2. They become tangled with application business logic and result in code that is difficult to maintain because there is no clear Separation of Concerns.

Aspect Oriented Programming (AOP) aims to address these challenges by providing a means of modularising application logic, so that each module addresses a distinct concern. Take performance monitoring as an example – rather than have performance monitoring logic littered across the application, AOP provides a means of modularising this logic, and applying it to various parts of the application at runtime. This provides a clear Separation of Concerns as performance monitoring logic is no longer tangled with business logic throughout the application.

Key Terms

The detailed inner workings of AOP is well beyond the scope of this post. However, I’ve provided a brief definition of key terms that are referred to throughout this tutorial.

  • Aspect – A self contained module that attempts to address a specific cross cutting concern. In this tutorial  the Aspect will contain performance monitoring functionality.
  • Advice – Logic that is invoked at a specific point in a programs execution.
  • Join Point – A specific point in a programs execution where advice is applied. Note that advice can be applied before and after a Join Point.
  • Pointcut – An expression that identifies Join Points matching certain criteria. For example we can define a Pointcut that identifies all public methods in a package. These specific points in program execution (JoinPoints) have advice applied to them at runtime.

How does it work?

If Advice (performance monitoring logic in this case) is completely separate from the business logic, how is it actually called? AOP takes care of this at runtime by wrapping the target object inside a proxy. The proxy intercepts incoming requests to the target object and calls the performance monitor ‘utility’ logic before it calls the target object. The proxy can also invoke utility logic after the target object has been called. Figure 1.0 below shows the steps involved.

Figure 1.0 – AOP Proxy

Sample Code

This sample code described in this tutorial will demonstrate some of Springs AOP capabilities by showing you how to build a simple performance monitor. Springs AOP support can be set up with either XML configuration or annotations. The XML approach is typically used in older applications running Spring 2.5, whereas newer applications running Spring 3.X typically use annotations. For completeness this tutorial will cover both approaches.

Project Structure

I’ve create 2 separate projects, one using XML configuration and one using annotations. The project structure is identical for both – the only difference is the configuration. To keep things simple both applications will be kicked off via a main method and call a simple Service. We’ll then use AOP to apply performance monitoring to the service call. The structure of both projects is shown below.

Figure 2.0 – Project Structure

I’ll start off by explaining the components that are identical in both the XML and annotation driven approaches. Then I’ll move on to explaining the configuration specific to each approach. Full source code for both projects will be available to download at the bottom of this post.

Service Interface

CalculationService.java is an interface that defines the simple service method shown below. Note that programming to interfaces is regarded as good practice, but has even more significance when using Springs AOP support. In order for Spring to use the dynamic proxy approach described earlier (see figure 1.0), it is expected that the target object (CalculationServiceImpl in this case) implements an interface. Its also possible to use AOP on a class that doesn’t implement an interface. In this case CGLIB is used to proxy the target object.

package com.blog.samples.aop;  
  
/**  
 * Dummy service interface  
 *  
 */  
public interface CalculationService  
{  
     /**  
       * A dummy method  
       *  
       * @param employee_p  
       * @return  
       */  
      public void dummyServiceMethod(); 
}

Service Implementation

CalculationServiceImpl.java implements the service interface defined above. The dummyServiceMethod simply logs a message and calls the randomSleep method to sleep the current thread for a random period of time. This allows us to simulate varying response times from the service method which will useful for testing our performance monitor later.

package com.blog.samples.aop;  

import org.apache.log4j.Logger;  

/**  
 * Dummy service calculates implementation implements dummyServiceMethod.  
 *  
 */  
public class CalculationServiceImpl implements CalculationService  
{  
  private static final Logger logger_c = Logger.getLogger(CalculationServiceImpl.class);  

  /**  
   * dummyServiceMethod simply logs a message and calls randomSleep to  
   * sleep the current thread for a random period of time. This allows us  
   * to simulate varying response times from the service method which is  
   * useful for testing our performance monitor  
   *  
   * @param employee_p  
   * @return  
   */  
  public void dummyServiceMethod()  
  {  
    logger_c.debug("Doing some service stuff here...");  

    /* Sleep thread for random period so as to vary service execution time */  
    randomSleep();  
  }  

  /**  
   * Sleep thread for random period  
   */  
  private void randomSleep()  
  {  
    try  
    {  
      Thread.sleep((long)(Math.random() * 1000));  
    }  
    catch (InterruptedException ie_p)  
    {  
      logger_c.error("Error occurred sleeping thread", ie_p);  
    }  
  }  
}  

Test Harness

RunTest.java uses a main method to load the Spring configuration and invokes the test service 50 times. We call the service 50 times as it helps demonstrate some of the statistics that can be gathered by the performance monitor defined later.

package com.blog.samples.aop;  

import org.apache.log4j.Logger;  
import org.springframework.context.support.ClassPathXmlApplicationContext;  

public class RunTest  
{  
  private static final Logger logger_c = Logger.getLogger(RunTest.class);  

  public static void main (String [] args)  
  {  
    logger_c.debug("loading spring application context");  
    ClassPathXmlApplicationContext applicationContext = new ClassPathXmlApplicationContext("classpath:spring-config.xml"); 

    /* get been from application context */  
    CalculationService calculationService = (CalculationService)applicationContext.getBean("calculationService");  

    /* call service 50 times so that we can see aggregated performance statistics for service call */  
    for(int i=0; i<50; i++)  
    {  
      /* invoke dummy service */  
      calculationService.dummyServiceMethod();  
    }  

    /* close down spring application context */  
    applicationContext.stop();  
  }  
}
  • Line 13 – load Spring configuration from src/main/resources/spring-config.xml
  • Line 16 – load calculation service from bean factory
  • Lines 19 to 23 – invoke calculation service 50 times so that we can gather a variety of metrics using the performance monitor (defined later).

Spring Configuration (XML Approach)

This section will detail the components required to enable AOP using traditional XML configuration. The Calculation Service bean, performance monitor bean and AOP configuration are defined in spring-configuration.xml below.

<?xml version="1.0" encoding="UTF-8"?>  
<beans xmlns="http://www.springframework.org/schema/beans"  
              xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"  
              xmlns:context="http://www.springframework.org/schema/context"  
              xmlns:aop="http://www.springframework.org/schema/aop"  
              xsi:schemaLocation="http://www.springframework.org/schema/context  
                                  http://www.springframework.org/schema/context/spring-context-2.5.xsd  
                                  http://www.springframework.org/schema/beans  
                                  http://www.springframework.org/schema/beans/spring-beans-2.5.xsd  
                                  http://www.springframework.org/schema/aop  
                                  http://www.springframework.org/schema/aop/spring-aop-2.0.xsd">  
   
   
      <!-- Calculation Service bean definition - this is the bean that we want to monitor performance on -->  
      <bean id="calculationService" class="com.blog.samples.aop.CalculationServiceImpl" />  
   
      <!-- ================================================================== -->  
      <!--         A O P C O N F I G B E A N S                        -->  
      <!-- ================================================================== -->  
   
     <!-- Performance Monitor bean definition - this bean contains performance monitoring logic  
          like starting and stopping the monitoring, logging statistics etc -->  
     <bean id="performanceMonitor" class="com.blog.samples.aop.PerformanceMonitor" />  
   
     <!-- AOP configuration -->  
     <aop:config>  
   
       <!-- Name of the Aspect we're defining -->  
       <aop:aspect ref="performanceMonitor">  
   
         <!--  
           the Pointcut expression specifies where the advice (performance monitoring code) will  
           be applied. Pointcut expressions are very flexible and can be as specific or as generic  
           as you like. In this instance we configured the Pointcut expression so that it covers  
           all methods in the com.blog.samples.aop.CalculationService class. However, we could  
           have configured it so that advice is only applied to a single Service method, or even  
           opened it up to all classes within the com.blog.samples.aop package. Obviously this  
           level of flexibility isn't required for our trivial example, but is very useful in  
           large enterprise applications.  
          -->  
         <aop:pointcut  
              id="serviceMethod"  
              expression="execution(* com.blog.samples.aop.CalculationService.*(..))"/>  
   
         <!--  
              <aop:before ... /> is used to specify the advice that should be run before a Pointcut  
              method - invoke the startMonitor method to start timing method execution before the Pointcut  
              pointcut-ref - the point cut reference specifies the point of execution in the code where the  
                             advice should be run. In this case its before any public method in the  
                             Calculation Service.  
         -->  
         <aop:before  
              method="startMonitor"  
              pointcut-ref="serviceMethod"/>  
   
         <!--  
              <aop:after ... /> is used to specify the advice that should be run after a Pointcut  
              method - invoke the stopMonitor method to stop timing method execution after the Pointcut  
              pointcut-ref - the point cut reference specifies the point of execution in the code where the  
                             advice should be run. In this case its after any public method in the  
                             Calculation Service.  
         -->  
         <aop:after  
              method="stopMonitor"  
              pointcut-ref="serviceMethod"/>  
   
         <!--  
              method - invoke the log method to log method execution metrics after the Pointcut  
              pointcut-ref - the point cut reference specifies the point of execution in the code where the  
                             advice should be run. In this case its after any public method in the  
                             Calculation Service.  
         -->  
         <aop:after  
              method="log"  
              pointcut-ref="serviceMethod"/>  
   
         <!--  
              <aop:after-throwing ... /> is used to define the advice to be run after an exception is thrown at a Pointcut.  
              method - invoke the stopMonitor method to stop timing method execution after an exception is thrown at the Pointcut  
              pointcut-ref - the point cut reference specifies the point of execution in the code where the  
                             advice should be run. In this case its after any public method in the  
                             Calculation Service.  
         -->  
         <aop:after-throwing  
              method="stopMonitor"  
              pointcut-ref="serviceMethod"/>  
   
         <!--  
              method - invoke the log method to stop timing method execution after an exception is thrown at the Pointcut  
              pointcut-ref - the point cut reference specifies the point of execution in the code where the  
                             advice should be run. In this case its after any public method in the  
                             Calculation Service.  
         -->  
         <aop:after-throwing  
              method="log"  
              pointcut-ref="serviceMethod"/>  
   
       </aop:aspect>  
     </aop:config>  
    
    <!-- ***************************** -->  
    
  </beans>

Performance Monitor (XML Configuration Approach)

The AOP configuration above uses a PerformanceMonitor class to apply advice at specified Pointcucts. The class is defined below and uses the JAMon API to provide basic performance monitoring functionality to captures and log performance metrics.

package com.blog.samples.aop;  

import java.util.Date;  
import org.aspectj.lang.JoinPoint;  
import org.apache.log4j.Logger;  
import com.jamonapi.Monitor;  
import com.jamonapi.MonitorFactory;  

/**  
 * Performance monitor use the Jamon library to provide basic performance  
 * monitoring and logging functionality.  
 *  
 */  
public class PerformanceMonitor  
{  
  private static final Logger logger_c = Logger.getLogger(PerformanceMonitor.class);  
  private final String MONITOR = "PERFORMANCE_MONITOR";  
  private Monitor monitor_i;  

  /**  
   * Start monitor  
   */  
  public void startMonitor()  
  {  
    monitor_i = MonitorFactory.start(MONITOR);  
  }  

  /**  
   * Stop monitor  
   */  
  public void stopMonitor()  
  {  
    monitor_i.stop();  
  }  

  /**  
   * get last access  
   *  
   * @return Date  
   */  
  public Date getLastAccess()  
  {  
    return monitor_i.getLastAccess();  
  }  

  /**  
   * get call count  
   *  
   * @return int  
   */  
  public int getCallCount()  
  {  
    return (int) monitor_i.getHits();  
  }  

  /**  
   * get average call time  
   *  
   * @return double  
   */  
  public double getAverageCallTime()  
  {  
    return monitor_i.getAvg() / 1000;  
  }  

  /**  
   * get last call time  
   *  
   * @return double  
   */  
  public double getLastCallTime()  
  {  
    return monitor_i.getLastValue() / 1000;  
  }  

  /**  
   * get maximum call time  
   *  
   * @return double  
   */  
  public double getMaximumCallTime()  
  {  
    return monitor_i.getMax() / 1000;  
  }  

  /**  
   * get minimum call time  
   *  
   * @return double  
   */  
  public double getMinimumCallTime()  
  {  
    return monitor_i.getMin() / 1000;  
  }  

  /**  
   * get total call time  
   *  
   * @return double  
   */  
  public double getTotalCallTime()  
  {  
    return monitor_i.getTotal() / 1000;  
  }  

  /**  
   * log statistics  
   *  
   * @param joinPoint_p  
   */  
  public void log(JoinPoint joinPoint_p)  
  {  
    StringBuffer sb = new StringBuffer();  

    sb.append("n");  
    sb.append("*======================================");  
    sb.append("n");  
    sb.append("*    PERFORMANCE STATISTICS    *");  
    sb.append("n");  
    sb.append("*======================================");  
    sb.append("n");  
    sb.append("* Method Name: " + joinPoint_p.getSignature().getName());  
    sb.append("n");  
    sb.append("* Execution Date: ").append(this.getLastAccess());  
    sb.append("n");  
    sb.append("* Last Execution Time: ").append(this.getLastCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Service Calls: ").append(((this.getCallCount())));  
    sb.append("n");  
    sb.append("* Avg Execution Time: ").append(this.getAverageCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Total Execution TIme: ").append(this.getTotalCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Min Execution Time: ").append(this.getMinimumCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Max Execution Time: ").append(this.getMaximumCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("*======================================");  

    logger_c.info(sb.toString());  
  }  
}  
  • Line 23 – Method starts monitor. This is called before the service method is invoked.
  • Line 31 – Method stops monitor. This is called after the service method completes.
  • Line 41 to 101 – Series of utility methods gather various metrics from the Jamon monitor.
  • Line 111 – Method logs performance statistics gathered by monitor. The JoinPoint argument provides access to the target object – in this instance we use the JoinPoint to access the name of the target method being invoked.

Spring Configuration (Annotation Driven)

This section shows how AOP can be configured using annotations. You’ll notice that this approach is less verbose than the XML approach described earlier. Note that Pointcuts are no longer defined using XML, instead Spring will look for beans annotated with @Aspect and register them as aspects.

<beans xmlns="http://www.springframework.org/schema/beans"  
     xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"  
     xmlns:aop="http://www.springframework.org/schema/aop"  
     xsi:schemaLocation="http://www.springframework.org/schema/beans  
                              http://www.springframework.org/schema/beans/spring-beans-3.0.xsd  
                              http://www.springframework.org/schema/aop  
                              http://www.springframework.org/schema/aop/spring-aop-3.0.xsd ">  
  
     <!-- this registers beans annotated with @Aspect -->  
      <aop:aspectj-autoproxy />  
   
      <!-- Calculation Service bean definition - this is the bean that we want to monitor performance on -->  
      <bean id="calculationService" class="com.blog.samples.aop.CalculationServiceImpl" />  
   
      <!-- Performance Monitor bean definition - this bean contains performance monitoring logic  
           for starting and stopping the monitoring, logging statistics etc -->  
      <bean id="performanceMonitor" class="com.blog.samples.aop.PerformanceMonitor" />  
   
</beans> 

Performance Monitor (Annotation Driven)

There are a number of significant differences between the Performance monitor defined below, and the one we defined earlier (using the XML approach). Here AOP is configured using class level meta data in the form of annotations.The @Aspect annotation tells Spring that this class contains advice and should be applied to specified Pointcuts at runtime. The Pointcuts are defined using method level annotations and have the same format as the ones defined earlier.

package com.blog.samples.aop;  

import java.util.Date;  

import org.aspectj.lang.JoinPoint;  
import org.aspectj.lang.annotation.After;  
import org.aspectj.lang.annotation.Aspect;  
import org.aspectj.lang.annotation.Before;  
import org.apache.log4j.Logger;  

import com.jamonapi.Monitor;  
import com.jamonapi.MonitorFactory;  

/*  
 * @Aspect tells the Spring framework that this class contains advice that should  
 * be applied to one or more specified Pointcuts at runtime  
 */  
@Aspect  
public class PerformanceMonitor  
{  
  private static final Logger logger_c = Logger.getLogger(PerformanceMonitor.class);  
  private final String MONITOR = "PERFORMANCE_MONITOR";  
  private Monitor monitor_i;  

  /*  
   * @Before tells the Spring framework that this method should be invoked before the specified Pointcut.  
   * The Pointcut expression here is identical to the one we used in the XML configuration example  
   */  
  @Before("execution(* com.blog.samples.aop.CalculationService.dummyServiceMethod())")  
  public void startMonitor()  
  {  
    monitor_i = MonitorFactory.start(MONITOR);  
  }  

  /*  
   * @After tells the Spring framework that this method should be invoked after the specified Pointcut.  
   * The Pointcut expression here is identical to the one we used in the XML configuration example  
   */  
  @After("execution(* com.blog.samples.aop.CalculationService.dummyServiceMethod())")  
  public void stopMonitor()  
  {  
    monitor_i.stop();  
  }  

  /**  
   * get last access  
   *  
   * @return Date  
   */  
  public Date getLastAccess()  
  {  
    return monitor_i.getLastAccess();  
  }  

  /**  
   * get call count  
   *  
   * @return int  
   */  
  public int getCallCount()  
  {  
    return (int) monitor_i.getHits();  
  }  

  /**  
   * get average call time  
   *  
   * @return double  
   */  
  public double getAverageCallTime()  
  {  
    return monitor_i.getAvg() / 1000;  
  }  

  /**  
   * get last call time  
   *  
   * @return double  
   */  
  public double getLastCallTime()  
  {  
    return monitor_i.getLastValue() / 1000;  
  }  

  /**  
   * get maximum call time  
   *  
   * @return double  
   */  
  public double getMaximumCallTime()  
  {  
    return monitor_i.getMax() / 1000;  
  }  

  /**  
   * get minimum call time  
   *  
   * @return double  
   */  
  public double getMinimumCallTime()  
  {  
    return monitor_i.getMin() / 1000;  
  }  

  /**  
   * get total call time  
   *  
   * @return double  
   */  
  public double getTotalCallTime()  
  {  
    return monitor_i.getTotal() / 1000;  
  }  

  /*  
   * @After tells the Spring framework that this method should be invoked after the specified Pointcut.  
   * The Pointcut expression here is identical to the one we used in the XML configuration example  
   */  
  @After("execution(* com.blog.samples.aop.CalculationService.dummyServiceMethod())")  
  public void log(JoinPoint joinPoint_p)  
  {  
    StringBuffer sb = new StringBuffer();  

    sb.append("n");  
    sb.append("*======================================");  
    sb.append("n");  
    sb.append("*    PERFORMANCE STATISTICS    *");  
    sb.append("n");  
    sb.append("*======================================");  
    sb.append("n");  
    sb.append("* Method Name: " + joinPoint_p.getSignature().getName());  
    sb.append("n");  
    sb.append("* Execution Date: ").append(this.getLastAccess());  
    sb.append("n");  
    sb.append("* Last Execution Time: ").append(this.getLastCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Service Calls: ").append(((this.getCallCount())));  
    sb.append("n");  
    sb.append("* Avg Execution Time: ").append(this.getAverageCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Total Execution TIme: ").append(this.getTotalCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Min Execution Time: ").append(this.getMinimumCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("* Max Execution Time: ").append(this.getMaximumCallTime()).append(" sec");  
    sb.append("n");  
    sb.append("*======================================");  

    logger_c.info(sb.toString());  
  }  
} 

Running the Test Harness

At this point I’ve covered all the various components and explained how AOP can be configured using both XML and annotations. Its time to run the test harness and see the performance monitor at work. Simply kick off the main method in RunTest.java and you should see the Calculation Service invoked 50 times, with performance metrics logged for each call. For brevity the extract below shows the end of the log.

DEBUG: [Apr-16 18:37:12,945] samples.aop.CalculationServiceImpl - Doing some service stuff here...  
INFO : [Apr-16 18:37:13,493] samples.aop.PerformanceMonitor -   
*======================================  
*    PERFORMANCE STATISTICS    *  
*======================================  
* Method Name: dummyServiceMethod  
* Execution Date: Tue Apr 16 18:37:12 BST 2013  
* Last Execution Time: 0.063 sec  
* Service Calls: 49  
 * Avg Execution Time: 0.5139387755102041 sec  
 * Total Execution TIme: 25.183 sec  
 * Min Execution Time: 0.024 sec  
 * Max Execution Time: 0.988 sec  
 *======================================  
 DEBUG: [Apr-16 18:37:13,493] samples.aop.CalculationServiceImpl - Doing some service stuff here...  
 INFO : [Apr-16 18:37:14,176] samples.aop.PerformanceMonitor -   
 *======================================  
 *    PERFORMANCE STATISTICS    *  
 *======================================  
 * Method Name: dummyServiceMethod  
 * Execution Date: Tue Apr 16 18:37:13 BST 2013  
 * Last Execution Time: 0.548 sec  
 * Service Calls: 50  
 * Avg Execution Time: 0.51462 sec  
 * Total Execution TIme: 25.731 sec  
 * Min Execution Time: 0.024 sec  
 * Max Execution Time: 0.988 sec

Various performance statistics have been logged, including minimum, maximum and average execution times. These metrics were logged every time the service method was invoked, and without adding cross cutting monitoring logic to the Calculation Service.

Wrapping Up

This tutorial has demonstrated how AOP can be used to encapsulate a cross cutting concern, apply it to business logic at runtime, and ensure a clear separation of concerns. Although the performance monitor example is trivial, it demonstrates a realistic use case for AOP and could form the basis for a more complete performance monitoring utility. Full source code is available here for the XML and annotation driven approaches, so feel free to download and play around with it. As always, comments or questions are welcome below.