使用Spring AOP进行性能监控

jopen 11年前

如果你正在使用Spring管理/访问资源(Dao/Service),那么你可能也需要添加一些基础的性能监控。在Spring AOP的帮助下这将变成一个简单的任务,不需要任何现有代码的变化,只是一些简单的配置。

第一步,你首先的将spring-aop、aspectj和cglib库导入,如果你使用maven管理你的项目依赖的话,很简单加上如下依赖关系就可以了。
 

01     <dependency>  02         <groupId>org.aspectj</groupId>  03         <artifactId>aspectjweaver</artifactId>  04         <version>1.5.4</version>  05     </dependency>  06     <dependency>  07         <groupId>cglib</groupId>  08         <artifactId>cglib-nodep</artifactId>  09         <version>2.2</version>  10     </dependency>  11     <dependency>  12       <groupId>org.springframework</groupId>  13       <artifactId>spring-aop</artifactId>  14       <version>2.5.6</version>  15     </dependency>


接下来,指明你需要监视的内容,并把AOP配好。通常,仅仅需要在现有的SpringXML配置文件中增加一个横切点。这个配置将会将位于包"com.mycompany.services"下的所有方法的响应时间记录下来。注:这些类必须使用Spring context初始化,否则AOP将不会被执行。
 
1     <bean id="performanceMonitor"  2               class="org.springframework.aop.interceptor.PerformanceMonitorInterceptor" />  3         4     <aop:config>  5         <aop:pointcut id="allServiceMethods" expression="execution(* com.mycompany.services.*.*(..))"/>  6         <aop:advisor pointcut-ref="allServiceMethods" advice-ref="performanceMonitor" order="2"/>  7     </aop:config>


接下来,需要配置好日志系统,例如log4j。
 
1     <logger name="org.springframework.aop.interceptor.PerformanceMonitorInterceptor" additivity="false">  2         <level value="TRACE"/>  3         <appender-ref ref="STDOUT"/>  4     </logger>


ok了,现在我们运行一下程序你会发现下面的日志输出:
 
1     TRACE PerformanceMonitorInterceptor  - StopWatch 'PerfTestService.processRequest': running time (millis) = 1322  2     TRACE PerformanceMonitorInterceptor  - StopWatch 'PerfTestService.processRequest': running time (millis) = 98  3     TRACE PerformanceMonitorInterceptor  - StopWatch 'PerfTestService.processRequest': running time (millis) = 1764


这些是大量的一些原始数据,但不幸的是这些东西对我们几乎没用,每一个方法调用都会有记录,而且缺乏一些其他信息。所以,除非你打算写一些日志分析程序、或者使用第三方软件,否则的话,我想你应该在日志被记录前做出一些处理。

一个简单的办法就是在这之间写一个简单的拦截器类来替代Spring给我们提供的默认的类(PerformanceMonitorInterceptor)。下面的一个例子,这个例子提供了一些有用的信息(最后一个、平均、最大的响应时间),另外当一个方法的响应时间超出指定的时间后给出警告。

默认的,每当十个方法调用的时候,做一次记录,在任何方法响应时间超过1000ms的时候给出警告。

01     public class PerfInterceptor implements MethodInterceptor {  02         03          Logger logger = LoggerFactory.getLogger(PerfInterceptor.class.getName());  04         private static ConcurrentHashMap<String, MethodStats> methodStats = new ConcurrentHashMap<String, MethodStats>();  05         private static long statLogFrequency = 10;  06         private static long methodWarningThreshold = 1000;  07            08         public Object invoke(MethodInvocation method) throws Throwable {  09             long start = System.currentTimeMillis();  10             try {  11                 return method.proceed();  12             }  13             finally {  14                 updateStats(method.getMethod().getName(),(System.currentTimeMillis() - start));  15             }  16         }  17         18         private void updateStats(String methodName, long elapsedTime) {  19             MethodStats stats = methodStats.get(methodName);  20             if(stats == null) {  21                 stats = new MethodStats(methodName);  22                 methodStats.put(methodName,stats);  23             }  24             stats.count++;  25             stats.totalTime += elapsedTime;  26             if(elapsedTime > stats.maxTime) {  27                 stats.maxTime = elapsedTime;  28             }  29                30             if(elapsedTime > methodWarningThreshold) {  31                 logger.warn("method warning: " + methodName + "(), cnt = " + stats.count + ", lastTime = " + elapsedTime + ", maxTime = " + stats.maxTime);  32             }  33                34             if(stats.count % statLogFrequency == 0) {  35                 long avgTime = stats.totalTime / stats.count;  36                 long runningAvg = (stats.totalTime-stats.lastTotalTime) / statLogFrequency;  37                 logger.debug("method: " + methodName + "(), cnt = " + stats.count + ", lastTime = " + elapsedTime + ", avgTime = " + avgTime + ", runningAvg = " + runningAvg + ", maxTime = " + stats.maxTime);  38                    39                 //reset the last total time  40                 stats.lastTotalTime = stats.totalTime;     41             }  42         }  43            44         class MethodStats {  45             public String methodName;  46             public long count;  47             public long totalTime;  48             public long lastTotalTime;  49             public long maxTime;  50                51             public MethodStats(String methodName) {  52                 this.methodName = methodName;  53             }  54         }  55     }


现在,你只需要将你的Spring配置文件中做相关修改,将这个类应用进去,再运行程序,你将会看到如下的统计信息。

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


正如你看到的一样,这些统计数据可以在不修改任何现有的Java代码的情况下,提供有关class/method性能的有价值的反馈,而根据这个日志,你可以很轻松的找出程序中的瓶颈。