使用Spring AOP進行性能監控

若是你正在使用Spring（Spring文檔）管理/訪問資源（Dao/Service），那麼你可能也須要添加一些基礎的性能監控。在Spring AOP的幫助下這將變成一個簡單的任務，不須要任何現有代碼的變化，只是一些簡單的配置。

第一步，你首先的將spring-aop、aspectj和cglib庫導入，若是你使用maven管理你的項目依賴的話，很簡單加上以下依賴關係就能夠了。

<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjweaver</artifactId>
    <version>1.5.4</version>
</dependency>
<dependency>
    <groupId>cglib</groupId>
    <artifactId>cglib-nodep</artifactId>
    <version>2.2</version>
</dependency>
<dependency>
  <groupId>org.springframework</groupId>
  <artifactId>spring-aop</artifactId>
  <version>2.5.6</version>
</dependency>

接下來，指明你須要監視的內容，並把AOP配好。一般，僅僅須要在現有的SpringXML配置文件中增長一個橫切點。這個配置將會將位於包"com.mycompany.services"下的全部方法的響應時間記錄下來。注：這些類必須使用Spring context初始化，不然AOP將不會被執行。

<bean id="performanceMonitor"
          class="org.springframework.aop.interceptor.PerformanceMonitorInterceptor" />

<aop:config>
    <aop:pointcut id="allServiceMethods" expression="execution(* com.mycompany.services.*.*(..))"/>
    <aop:advisor pointcut-ref="allServiceMethods" advice-ref="performanceMonitor" order="2"/>
</aop:config>

接下來，須要配置好日誌系統，例如log4j。

<logger name="org.springframework.aop.interceptor.PerformanceMonitorInterceptor" additivity="false">
    <level value="TRACE"/>
    <appender-ref ref="STDOUT"/>
</logger>

ok了，如今咱們運行一下程序你會發現下面的日誌輸出：

TRACE PerformanceMonitorInterceptor  - StopWatch 'PerfTestService.processRequest': running time (millis) = 1322
TRACE PerformanceMonitorInterceptor  - StopWatch 'PerfTestService.processRequest': running time (millis) = 98
TRACE PerformanceMonitorInterceptor  - StopWatch 'PerfTestService.processRequest': running time (millis) = 1764

這些是大量的一些原始數據，但不幸的是這些東西對咱們幾乎沒用，每個方法調用都會有記錄，並且缺少一些其餘信息。因此，除非你打算寫一些日誌分析程序、或者使用第三方軟件，不然的話，我想你應該在日誌被記錄前作出一些處理。

一個簡單的辦法就是在這之間寫一個簡單的攔截器類來替代Spring給咱們提供的默認的類（PerformanceMonitorInterceptor）。下面的一個例子，這個例子提供了一些有用的信息（最後一個、平均、最大的響應時間），另外當一個方法的響應時間超出指定的時間後給出警告。

默認的，每當十個方法調用的時候，作一次記錄，在任何方法響應時間超過1000ms的時候給出警告。

public class PerfInterceptor implements MethodInterceptor {

     Logger logger = LoggerFactory.getLogger(PerfInterceptor.class.getName());
    private static ConcurrentHashMap<String, MethodStats> methodStats = new ConcurrentHashMap<String, MethodStats>();
    private static long statLogFrequency = 10;
    private static long methodWarningThreshold = 1000;
   
    public Object invoke(MethodInvocation method) throws Throwable {
        long start = System.currentTimeMillis();
        try {
            return method.proceed();
        }
        finally {
            updateStats(method.getMethod().getName(),(System.currentTimeMillis() - start));
        }
    }

    private void updateStats(String methodName, long elapsedTime) {
        MethodStats stats = methodStats.get(methodName);
        if(stats == null) {
            stats = new MethodStats(methodName);
            methodStats.put(methodName,stats);
        }
        stats.count++;
        stats.totalTime += elapsedTime;
        if(elapsedTime > stats.maxTime) {
            stats.maxTime = elapsedTime;
        }
       
        if(elapsedTime > methodWarningThreshold) {
            logger.warn("method warning: " + methodName + "(), cnt = " + stats.count + ", lastTime = " + elapsedTime + ", maxTime = " + stats.maxTime);
        }
       
        if(stats.count % statLogFrequency == 0) {
            long avgTime = stats.totalTime / stats.count;
            long runningAvg = (stats.totalTime-stats.lastTotalTime) / statLogFrequency;
            logger.debug("method: " + methodName + "(), cnt = " + stats.count + ", lastTime = " + elapsedTime + ", avgTime = " + avgTime + ", runningAvg = " + runningAvg + ", maxTime = " + stats.maxTime);
           
            //reset the last total time
            stats.lastTotalTime = stats.totalTime;   
        }
    }
   
    class MethodStats {
        public String methodName;
        public long count;
        public long totalTime;
        public long lastTotalTime;
        public long maxTime;
       
        public MethodStats(String methodName) {
            this.methodName = methodName;
        }
    } 
}

如今，你只須要將你的Spring配置文件中作相關修改，將這個類應用進去，再運行程序，你將會看到以下的統計信息。

WARN  PerfInterceptor - method warning: processRequest(), cnt = 10, lastTime = 1072, maxTime = 1937
TRACE PerfInterceptor - method: processRequest(), cnt = 10, lastTime = 1072, avgTime = 1243, runningAvg = 1243, maxTime = 1937
WARN  PerfInterceptor - method warning: processRequest(), cnt = 20, lastTime = 1466, maxTime = 1937
TRACE PerfInterceptor - method: processRequest(), cnt = 20, lastTime = 1466, avgTime = 1067, runningAvg = 892, maxTime = 1937

正如你看到的同樣，這些統計數據能夠在不修改任何現有的Java代碼的狀況下，提供有關class/method性能的有價值的反饋，而根據這個日誌，你能夠很輕鬆的找出程序中的瓶頸。

 

Oschina.NET原創翻譯/原文連接