AOP@Work: Performance monitoring with AspectJ, Part 1

Summary:  Say goodbye to scattered and tangled monitoring code, as Ron Bodkin shows you how to combine AspectJ and JMX for a flexible, modular approach to performance monitoring. In this first of two parts, Ron uses source code and ideas from the Glassbox Inspector open source project to help you build a monitoring system that provides correlated information to identify specific problems, but with low enough overhead to be used in production environments.

View more content in this series

Date:  13 Sep 2005
Level:  Intermediate

Activity:  37310 views
Comments:  

Modern Java™ applications are typically complex, multithreaded, distributed systems that use many third-party components. On such systems, it is hard to detect (let alone isolate) the root causes of performance or reliability problems, especially in production. Traditional tools such as profilers can be useful for cases where a problem is easy to reproduce, but the overhead imposed by such tools makes them unrealistic to use in production or even load-test environments.

A common alternative strategy for monitoring and troubleshooting application performance and failures is to instrument performance-critical code with calls to record usage, timing, and errors. However, this approach requires scattering duplicate code in many places with much trial and error to determine what code needs to be measured. This approach is also difficult to maintain as the system changes and is hard to drill into. This makes application code challenging to add or modify later, precisely when performance requirements are better known. In short, system monitoring is a classic crosscutting concern and therefore suffers from any implementation that is not modular.

As you will learn in this two-part article, aspect-oriented programming (AOP) is a natural fit for solving the problems of system monitoring. AOP lets you define pointcuts that match the many join points where you want to monitor performance. You can then write advice that updates performance statistics, which can be invoked automatically whenever you enter or exit one of the join points.

In this half of the article, I'll show you how to use AspectJ and JMX to create a flexible, aspect-oriented monitoring infrastructure. The monitoring infrastructure I'll use is the core of the open source Glassbox Inspector monitoring framework (see Resources). It provides correlated information that helps you identify specific problems but with low enough overhead to be used in production environments. It lets you capture statistics such as total counts, total time, and worst-case performance for requests, and it will also let you drill down into that information for database calls within a request. And it does all of this within a modest-sized code base!

In this article and the next one, I'll build up from a simple Glassbox Inspector implementation and add functionality as I go along. Figure 1 should give you an idea of the system that will be the end result of this incremental development process. Note that the system is designed to monitor multiple Web applications simultaneously and provide correlated statistical results.

Figure 2 is an overview of the architecture of the monitoring system. The aspects interact with one or more applications inside a container to capture performance data, which they surface using the JMX Remote standard. From an architectural standpoint, Glassbox Inspector is similar to many performance monitoring systems, although it is distinguished by having well-defined modules that implement the key monitoring functions.

Java Management Extensions (JMX) is a standard API for managing Java applications by viewing attributes of managed objects. The JMX Remote standard extends JMX to allow external client processes to manage an application. JMX management is a standard feature in Java Enterprise containers. Several mature third-party JMX libraries and tools exist, and JMX support has been integrated into the core Java runtime with Java 5. Sun Microsystems's Java 5 VM includes the JConsole JMX client.

You should download the current versions of AspectJ, JMX, and JMX Remote, as well as the source packet for this article (see Resources for the technologies and Download for the code) before continuing. If you are using a Java 5 VM, then it has JMX integrated into it. Note that the source packet includes the complete, final code for the 1.0 alpha release of the open source Glassbox Inspector performance monitoring infrastructure.

The basic system

I'll start with a basic aspect-oriented performance monitoring system. This system captures the time and counts for different servlets processing incoming Web requests. Listing 1 shows a simple aspect that would capture this performance information:

/**
 * Monitors performance timing and execution counts for 
 * <code>HttpServlet</code> operations
 */
public aspect HttpServletMonitor {
 
  /** Execution of any Servlet request methods. */
  public pointcut monitoredOperation(Object operation) : 
    execution(void HttpServlet.do*(..)) && this(operation);
 
  /** Advice that records statistics for each monitored operation. */
  void around(Object operation) : monitoredOperation(operation) {
      long start = getTime();
 
      proceed(operation);
 
      PerfStats stats = lookupStats(operation);
      stats.recordExecution(getTime(), start);
  }
 
  /**
   * Find the appropriate statistics collector object for this
   * operation.
   * 
   * @param operation
   *            the instance of the operation being monitored
   */
  protected PerfStats lookupStats(Object operation) {
      Class keyClass = operation.getClass();
      synchronized(operations) {
          stats = (PerfStats)operations.get(keyClass);
          if (stats == null) {                
              stats = perfStatsFactory.
                createTopLevelOperationStats(HttpServlet.class, 
                       keyClass);
              operations.put(keyClass, stats);
          }
      }
      return stats;        
  }
 
  /**
   * Helper method to collect time in milliseconds. Could plug in
   * nanotimer.
   */
  public long getTime() {
      return System.currentTimeMillis();
  }
 
  public void setPerfStatsFactory(PerfStatsFactory 
    perfStatsFactory) {
      this.perfStatsFactory = perfStatsFactory;
  }
 
  public PerfStatsFactory getPerfStatsFactory() {
      return perfStatsFactory;
  }
 
  /** Track top-level operations. */ 
  private Map/*<Class,PerfStats>*/ operations  = 
    new WeakIdentityHashMap();
  private PerfStatsFactory perfStatsFactory;
}
 
/**
 * Holds summary performance statistics for a 
 * given topic of interest
 * (e.g., a subclass of Servlet).
 */ 
public interface PerfStats {
  /**
   * Record that a single execution occurred.
   * 
   * @param start time in milliseconds
   * @param end time in milliseconds
   */
  void recordExecution(long start, long end);
 
  /**
   * Reset these statistics back to zero. Useful to track statistics
   * during an interval.
   */
  void reset();
 
  /**
   * @return total accumulated time in milliseconds from all
   *         executions (since last reset).
   */
  int getAccumulatedTime();
 
  /**
   * @return the largest time for any single execution, in
   *         milliseconds (since last reset).
   */
  int getMaxTime();
 
  /** 
   * @return the number of executions recorded (since last reset). 
   */
  int getCount();
}
 
/**
 * Implementation of the
 * 
 * @link PerfStats interface.
 */
public class PerfStatsImpl implements PerfStats {
  private int accumulatedTime=0L;
  private int maxTime=0L;
  private int count=0;
 
  public void recordExecution(long start, long end) {
      int time = (int)(getTime()-start);
      accumulatedTime += time;
      maxTime = Math.max(time, maxTime);
      count++;
  }
 
  public void reset() {
      accumulatedTime=0L;
      maxTime=0L;
      count=0;
  }
 
  int getAccumulatedTime() { return accumulatedTime; }
  int getMaxTime() { return maxTime; }
  int getCount() { return count; }
}
 
public interface PerfStatsFactory {
    PerfStats 
      createTopLevelOperationStats(Object type, Object key);
}
 

As you can see, this first version is fairly basic. HttpServletMonitor defines a pointcut called monitoredOperation that matches the execution of any method on the HttpServlet interface whose name starts with do. These are typically doGet() and doPost(), but it also captures the less-often-used HTTP request options by matching doHead(), doDelete(), doOptions(), doPut(), and doTrace().

Whenever one of these operations executes, the system executes an around advice to monitor performance. The advice starts a stop watch, and then it lets the original request proceed. After this, it stops the stop watch and looks up a performance-statistics object that corresponds to the given operation. It then records that the operation was serviced in the elapsed time by invoking recordExecution() from the interface PerfStats. This simply updates the total time, the maximum time (if appropriate), and a count of executions of the given operation. Naturally, you could extend this approach to calculate additional statistics and to store individual data points where issues might arise.

I've used a hash map in the aspect to store the accumulated statistics for each type of operation handler, which is used during lookup. In this version, the operation handlers are all subclasses of HttpServlet, so the class of the servlet is used as the key. I've also used the term operation for Web requests, thus distinguishing them from the many other kinds of requests an application might make (e.g., database requests). In the second part of this article, I'll extend this approach to address the more common case of tracking operations based on the class or method used in a controller, such as an Apache Struts action class or a Spring multiaction controller method.

Back to top

Exposing performance data

Once you've captured performance data, you have a wide variety of options for how to make it available. The easiest way is to write the information to a log file periodically. You could also load the information into a database for analysis. Rather than add the latency, complexity, and overhead of summarizing, logging, and processing information, it is often better to provide direct access to live system performance data. I'll show you how to do this in this next section.

I want a standard protocol that existing management tools can display and track, so I'll use the JMX API to share performance statistics. Using JMX means that each of the performance-statistics instances will be exposed as a management bean, thus yielding detailed performance data. Standard JMX clients like Sun Microsystems's JConsole will also be able to show the information. See Resources to learn more about JMX.

Figure 3 is a screenshot of the JConsole showing data from the Glassbox Inspector monitoring the performance of the Duke's Bookstore sample application (see Resources). Listing 2 shows the code that implements this feature.

Traditionally, supporting JMX involves implementing patterns with boilerplate code. In this case, I'll combine JMX with AspectJ, which enables me to write the management logic separately.

/** Reusable aspect that automatically registers
 *  beans for management
 */
public aspect JmxManagement {

    /** Defines classes to be managed and 
     *  defines basic management operation
     */
    public interface ManagedBean {
        /** Define a JMX operation name for this bean. 
         *  Not to be confused with a Web request operation.
         */
        String getOperationName();
        /** Returns the underlying JMX MBean that 
         *  provides management
         *  information for this bean (POJO).
         */
        Object getMBean();
    } 

    /** After constructing an instance of 
     *  <code>ManagedBean</code>, register it
     */
    after() returning (ManagedBean bean): 
      call(ManagedBean+.new(..)) {
        String keyName = bean.getOperationName();
        ObjectName objectName = 
          new 
            ObjectName("glassbox.inspector:" + keyName);

        Object mBean = bean.getMBean();
        if (mBean != null) {
            server.registerMBean(mBean, objectName);
        }
    }

    /** 
     * Utility method to encode a JMX key name, 
     *  escaping illegal characters.
     * @param jmxName unescaped string buffer of form 
     * JMX keyname=key 
     * @param attrPos position of key in String
     */ 
    public static StringBuffer 
      jmxEncode(StringBuffer jmxName, int attrPos) {
        for (int i=attrPos; i<jmxName.length(); i++) {
            if (jmxName.charAt(i)==',' ) {
                jmxName.setCharAt(i, ';');
            } else if (jmxName.charAt(i)=='?' 
                || jmxName.charAt(i)=='*' || 
                jmxName.charAt(i)=='\\' ) {
                jmxName.insert(i, '\\');
                i++;
            } else if (jmxName.charAt(i)=='\n') {
                jmxName.insert(i, '\\');
                i++;
                jmxName.setCharAt(i, 'n');
            }
        }
        return jmxName;
    }

    /** Defines the MBeanServer with which beans
     *   are auto-registered.
     */
    private MBeanServer server;

    public void setMBeanServer(MBeanServer server) {
        this.server = server;
    }

    public MBeanServer getMBeanServer() {
        return server;
    }
}

You can see that this first aspect is reusable. With it, I can automatically register an object instance for any class that implements an interface, ManagedBean, using an after advice. This is similar to the AspectJ Marker Interface idiom (see Resources) in that it defines the classes whose instances should be exposed through JMX. However, unlike a true marker interface, this one also defines two methods.

The aspect provides a setter to define which MBean server should be used for managing objects. This is an example of using the Inversion of Control (IOC) pattern for configuration and is a natural fit with aspects. In the full listing of the final code, you'll see I've used a simple helper aspect to configure the system. In a larger system, I would use an IOC container like the Spring framework to configure classes and aspects. See Resources for more about IOC and the Spring framework and for a good introduction to using Spring to configure aspects.

/** Applies JMX management to performance statistics beans. */
public aspect StatsJmxManagement {
    /** Management interface for performance statistics. 
     *  A subset of @link PerfStats
     */
    public interface PerfStatsMBean extends ManagedBean {
        int getAccumulatedTime();
        int getMaxTime();
        int getCount();
        void reset();
    }
    
    /** 
     * Make the @link PerfStats interface 
     * implement @link PerfStatsMBean, 
     * so all instances can be managed 
     */
    declare parents: PerfStats implements PerfStatsMBean;

    /** Creates a JMX MBean to represent this PerfStats instance. *