Logging Method Entry/Exit with Spring/AspectJ

The purpose of this blog entry is to show an extremely simple of example of "logging" entry into and exit from methods using the Spring Framework and AspectJ. The example is so simple that I won't actually use log4j or java.util.logging for the actual logging, although they could be easily added.

The first code listing shows the XML file for the Spring context. The majority of this file is devoted to setting up the Spring/AspectJ/AOP configuration. The terms included in the comments of this file that identify aspect-oriented programming (AOP) concepts are defined in Introduction to Aspect-Oriented Programming.


spring-aop-logging-context.xml

<?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:p="http://www.springframework.org/schema/p"
       xmlns:aop="http://www.springframework.org/schema/aop"
       xsi:schemaLocation="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.5.xsd">

   <!-- Normal Spring-exposed bean. -->
   <bean id="exampleBean"
         class="dustin.spring.aopexamples.ExampleBeanClass">
      <constructor-arg value="A Logging Example" />
      <constructor-arg value="1.0" />
   </bean>

   <!-- The Aspect itself. -->
   <bean id="exampleLoggingAspect"
         class="dustin.spring.aopexamples.LoggingAspect" />

   <aop:config>

      <!-- The Pointcut(s). -->
      <aop:pointcut id="loggingPointcut"
                    expression="within(dustin.spring.aopexamples.ExampleBeanClass)" />

      <!-- The Advice(s). -->
      <aop:aspect id="loggingAspect" ref="exampleLoggingAspect">
         <aop:before pointcut-ref="loggingPointcut" method="logEntry" />
         <aop:after pointcut-ref="loggingPointcut" method="logExit" />
         <aop:after-returning pointcut-ref="loggingPointcut"
                              method="logExitAfterReturn" />
      </aop:aspect>

   </aop:config>

</beans>

With the Spring configuration (including AOP support for logging) defined, the main class that instantiates the Spring context based on this XML file is shown next. This class doesn't do much other than instantiating the Spring container and using System.out to output the information returned from an example bean class. However, this is enough to demonstrate how the method entry and exit from each method in that example bean class is logged above and beyond what is obvious in the code.


Main.java

package dustin.spring.aopexamples;

import org.springframework.context.ConfigurableApplicationContext;
import org.springframework.context.support.ClassPathXmlApplicationContext;

/**
 * Demonstrate Spring/AspectJ-based logging.
 * 
 * @author Dustin
 */
public class Main
{
   /**
    * Print out the contents of the provided ExampleBeanClass.
    * 
    * @param example Object whose contents should be printed out.
    */
   public static void printContentsOfExample(final ExampleBeanClass example)
   {
      System.out.println(
         "\n\n=============================================================");
      System.out.println("     Dustin's Software Cogitations and Speculations");
      System.out.println(
         "=============================================================");
      System.out.println( "Name: " + example.getExampleName() );
      System.out.println( "Version: " + example.getExampleVersion() );
      System.out.println( "Name (Version): " + example.provideNameAndVersion() );
      System.out.println(
         "=============================================================\n\n");
   }

   /**
    * Demonstrate logging via Spring AspectJ support.
    * 
    * @param args the command line arguments
    */
   public static void main(String[] args)
   {
      final ConfigurableApplicationContext context =
         new ClassPathXmlApplicationContext(
            "dustin\\spring\\aopexamples\\spring-aop-logging-context.xml");
      final ExampleBeanClass example =
         (ExampleBeanClass) context.getBean("exampleBean");
      printContentsOfExample(example);
      context.close();
   }
}

The next class I'll define here is the Aspect class that contains the code that I am going to want to run on top of (above and beyond) the code that is executed normally. Here is that class.


LoggingAspect.java

package dustin.spring.aopexamples;

import org.aspectj.lang.JoinPoint;

/**
 * Aspect class for the Spring/AspectJ Logging example shown in the blog
 * Dustin's Software Development Cogitations and Speculations.
 * 
 * @author Dustin
 */
public class LoggingAspect
{
   /**
    * Log method entry.
    * 
    * @param joinPoint
    */
   public void logEntry(final JoinPoint joinPoint)
   {
      log("Entering method " + joinPoint.getSignature().getName() + "...");
   }

   /**
    * Log method exit.
    * 
    * @param joinPoint
    */
   public void logExit(final JoinPoint joinPoint)
   {
      log("Exiting method " + joinPoint.getSignature().getName() + ".");
   }

   /**
    * Log method exit after returning.
    * 
    * @param joinPoint
    */
   public void logExitAfterReturn(final JoinPoint joinPoint)
   {
      log(  "Exiting method (after return) "
          + joinPoint.getSignature().getName() + ".");
   }

   /**
    * "Log" the provided String.
    * 
    * @param messageToLog String to be logged.
    */
   public static void log(final String messageToLog)
   {
      System.err.println(messageToLog);
   }
}

We now have Spring context (including logging AOP support) configuration created along with a main class that instantiates that context and a class that will serve as our logging aspect. Last, but certainly not least, we need the actual class whose methods' entry and exit will be intercepted and have the additional code specified in the Aspect applied to them. Here is that example class. Note that it is a POJO with no specific reference to Spring or to AOP or to AspectJ.


ExampleBeanClass.java

package dustin.spring.aopexamples;

/**
 * An example bean class meant to be used with Spring and AspectJ to demonstrate
 * AOP-based logging.  This is used for a blog entry in Dustin's Software
 * Development Cogitations and Speculations.
 * 
 * @author Dustin
 */
public class ExampleBeanClass
{
   /**
    * The name of the example.
    */
   private String exampleName;

   /**
    * The version of the example.
    */
   private String exampleVersion;

   /**
    * No-arguments constructor.
    */
   public ExampleBeanClass() {}

   /**
    * Constructor accepting arguments to set my state.
    * 
    * @param newExampleName Name of this example.
    * @param newExampleVersion Version of this example.
    */
   public ExampleBeanClass(
      final String newExampleName, final String newExampleVersion)
   {
      this.exampleName = newExampleName;
      this.exampleVersion = newExampleVersion;
   }

   /**
    * Provide my example name.
    * 
    * @return My example name.
    */
   public String getExampleName()
   {
      return exampleName;
   }

   /**
    * Set/change my example name.
    * 
    * @param exampleName New name for this example.
    */
   public void setExampleName(String exampleName)
   {
      this.exampleName = exampleName;
   }

   /**
    * Provide my example version.
    * 
    * @return My example version.
    */
   public String getExampleVersion()
   {
      return exampleVersion;
   }

   /**
    * Set/change the example's version.
    * 
    * @param exampleVersion New value for my version.
    */
   public void setExampleVersion(String exampleVersion)
   {
      this.exampleVersion = exampleVersion;
   }

   /**
    * Provide my example name with version in parentheses.
    * 
    * @return My name and version if format "Name (Version)."
    */
   public String provideNameAndVersion()
   {
      return this.exampleName + " (" + this.exampleVersion + ")";
   }
}

The class above, ExampleBeanClass, has no methods for writing output to the standard output stream. The Main class that calls this via Spring does have some standard output calls to output the contents of this class, but we will see additional logged messages when we run the application because the AOP portion of this will add method entry, method exit, and method exit after return log statements for each method invoked on the ExampleBeanClass. It is the Spring XML at the beginning of this blog entry that ties all of these together.

Here is what the output (focus on middle section) looks like when run with the appropriate libraries (CGLIB, Spring Framework, AspectJ, etc.) on the classpath (all available with Spring with Dependencies download).



The order of output of the "normally expected" output statements as compared to the order of the output of the "logging" statements made via Spring's AOP support is interesting to observe. As one might expect, "before" comes before "after" which comes before "after returning", but all are part of the methods' entry and exit and so all come before a third class can print the output of the returned Strings.

As this blog entry has demonstrated, it is very easy to apply aspect-oriented programming techniques to Java applications with Spring and Spring's AOP support.