AOP监控方法的运行时间

之前写过AOP，现在项目需要监控方法的运行时间。这里采用spring aop来统计各个阶段的用时，其中计时器工具为StopWatch。

使用配置文件：
在spring的xml配置文件中：

<!-- 日志时间打印 -->
<aop:config>  
    <!-- Spring 2.0 可以用 AspectJ 的语法定义 Pointcut，这里拦截 service 包中的所有方法 -->  
    <aop:advisor id="methodTimeLog" advice-ref="methodTimeAdvice" pointcut="execution(* com.tmg.perfomance.service.impl.*.*(..))"/>  
</aop:config>
<!-- 默认使用JDK动态代理，对于Schema风格配置切面使用如下方式来指定使用CGLIB代理。
<aop:config proxy-target-class="true">  
</aop:config>     -->

<bean id="methodTimeAdvice" class="com.tmg.perfomance.log.MethodTimeAdvice"/>  

使用AOP时，xml里面别忘了以下配置：

配置完了，接下来实现拦截器：
继承MethodInterceptor接口，使用commons-lang提供的StopWatch

import org.aopalliance.intercept.MethodInterceptor;  
import org.aopalliance.intercept.MethodInvocation;  
import org.apache.commons.lang.StringUtils;  
import org.apache.commons.lang.time.StopWatch;  
import org.apache.commons.logging.Log;  
import org.apache.commons.logging.LogFactory;  
public class MethodTimeAdvice implements MethodInterceptor {  
    protected final Log log = LogFactory.getLog(MethodTimeAdvice.class);     
        
    /**   
     * 拦截要执行的目标方法   
     */    
    public Object invoke(MethodInvocation invocation) throws Throwable {     
        //用 commons-lang 提供的 StopWatch 计时，Spring 也提供了一个 StopWatch     
        StopWatch clock = new StopWatch();     
        clock.start(); //计时开始     
        Object result = invocation.proceed();     
        clock.stop();  //计时结束     
             
        //方法参数类型，转换成简单类型     
        Class[] params = invocation.getMethod().getParameterTypes();     
        String[] simpleParams = new String[params.length];     
        for (int i = 0; i < params.length; i++) {     
            simpleParams[i] = params[i].getSimpleName();     
        }     
             
        log.info("Takes:" + clock.getTime() + " ms ["    
                + invocation.getThis().getClass().getName() + "."    
                + invocation.getMethod().getName() + "("+StringUtils.join(simpleParams,",")+")] ");     
        return result;     
    }     
}  

使用注解：
在spring的xml配置文件中：

<?xml version="1.0" encoding="UTF-8"?>
<beans:beans xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:mvc="http://www.springframework.org/schema/mvc" xmlns:beans="http://www.springframework.org/schema/beans"
    xmlns:context="http://www.springframework.org/schema/context" xmlns:tx="http://www.springframework.org/schema/tx"
    xmlns:aop="http://www.springframework.org/schema/aop"
    xsi:schemaLocation="
        http://www.springframework.org/schema/mvc http://www.springframework.org/schema/mvc/spring-mvc-3.2.xsd
        http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.2.xsd
        http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.2.xsd
        http://www.springframework.org/schema/tx http://www.springframework.org/schema/tx/spring-tx-3.2.xsd
        http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-3.2.xsd">

    <aop:aspectj-autoproxy proxy-target-class="true" />
    <beans:bean id="methodTimeAdvice"
        class="com.tmg.perfomance.log.MethodTimeAdvice">
    </beans:bean>
</beans:beans>

切点：

import java.util.concurrent.ConcurrentHashMap;
import org.apache.commons.lang3.time.StopWatch;
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Pointcut;

@Aspect
public class MethodTimeAdvice{

    protected final Log log = LogFactory.getLog(MethodTimeAdvice.class);

    @Pointcut("execution(* com.tmg.perfomance.service.impl.*.*(..))")
    private void serviceMethod() {
    }

    @Around("serviceMethod()")
    public Object logMethodRunningTime(ProceedingJoinPoint pjp) throws Throwable {
        // start stopwatch
        StopWatch watch = new StopWatch();
        watch.start();
        Object retVal = pjp.proceed();
        // stop stopwatch
        watch.stop();
        Long time = watch.getTime();
        String methodName = pjp.getSignature().getName();

        log.info(methodName +" cost : "+ clock.getTime() + " ms")
        return retVal;
    }
}

测试：

@RunWith(SpringJUnit4ClassRunner.class)
@ContextConfiguration({"/spring/app*.xml","/spring/service/app*.xml"}) //加载配置文件  
public class BaseJunit4Test  {

    @Autowired
    private YourService yourService; //自动注入

    // 测试你需要的方法
    @Test
    public void testYourMethod() {
        yourService.xxxx()
        ...
    }
    
    // 测试方法运行完毕后，做你需要的后续处理
    //@After
    //public void testMethodActive() {
    //  ...
    //}
}

其他：

• 环绕通知加入多个point
  用||连接多个point

    <aop:config>  
        <!-- 配置多个切点，&& || ! -->  
        <aop:pointcut id="pc" expression="execution(public * com.wtas.*.service.*.*(..)) || execution(public * com.wtas.*.*.service.*.*(..)) || execution(public * com.wtas.*.*.*.service.*.*(..))" />  
        <aop:advisor pointcut-ref="pc" advice-ref="userTxAdvice" />  
    </aop:config>  
  

其中，&&,||,可以写成and，or。

• 监听时间工具StopWatch每次只能启动一个，一定要关闭后才能启动下一个。
  controller开始后执行其他逻辑，然后调用service，这时候service启动定时会失败，因为controller的计时器还没关，因此需要先关掉controller的计时器。这导致controller只计了调用service之前的时间，service返回值之后，controller再进行其他处理的时间并没有被统计。

---

参考：
http://www.cnblogs.com/liuyitian/p/4101531.html
http://blog.csdn.net/qiutongyeluo/article/details/52468081