備注學(xué)院

有時(shí)候我們要跟蹤方法的執(zhí)行時(shí)間，來(lái)觀察系統(tǒng)的性能、時(shí)間分布。特別是要找出那些十分耗時(shí)的操作。如果是在每個(gè)方法中起始和結(jié)束位置記下時(shí)間相減，那是不太現(xiàn)實(shí)的，對(duì)代碼的侵入性太過(guò)份，而且在產(chǎn)品環(huán)境中又得屏閉那部份代碼。

幸好現(xiàn)在有了 AOP，通過(guò)配置方式再加上外部輔助代碼就能達(dá)到我們的要求，正式上線時(shí)只需要簡(jiǎn)單改個(gè)配置項(xiàng)拆卸下來(lái)即可。

下面介紹三種方式來(lái)打印每個(gè)方法的執(zhí)行時(shí)間，分別是：

1. Spring 2.0 用 AspectJ 實(shí)現(xiàn) AOP
2. Spring 通用的方法攔截
3. 直接用 AspectJ 實(shí)現(xiàn)

1. Spring 2.0 用 AspectJ 實(shí)現(xiàn) AOP

這個(gè)實(shí)例由五個(gè)文件構(gòu)成，兩個(gè)配置文件和三個(gè)類文件。需要在項(xiàng)目中引用 Spring 2.0 以上版本的相關(guān)包，還要日志包。

1) log4j.properties  放在 src 目錄下

log4j.rootLogger=DEBUG,stdout log4j.appender.stdout=org.apache.log4j.ConsoleAppender log4j.appender.stdout.layout=org.apache.log4j.PatternLayout log4j.appender.stdout.layout.ConversionPattern=%d [%5p] %c{1}.%M(%L) %n%m%n
2) applicationContext.xml   放在 src 目錄下

<beans xmlns="http://www.springframework.org/schema/beans" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" 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.0.xsd http://www.spridngframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-2.0.xsd"> <aop:config> <!-- Spring 2.0 可以用 AspectJ 的語(yǔ)法定義 Pointcut，這里攔截 service 包中的所有方法 --> <aop:advisor id="methodTimeLog" advice-ref="methodTimeAdvice" pointcut="execution(* *..service..*(..))"/> </aop:config> <bean id="methodTimeAdvice" class="com.unmi.util.MethodTimeAdvice"/> <bean id="helloService" class="com.unmi.service.HelloService"/> </beans>
3) MethodTimeAdvice.java 記錄時(shí)間的類

package com.unmi.util; 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; /** * 記錄方法的執(zhí)行時(shí)間 * @author Unmi */ public class MethodTimeAdvice implements MethodInterceptor { protected final Log log = LogFactory.getLog(MethodTimeAdvice.class); /** * 攔截要執(zhí)行的目標(biāo)方法 */ public Object invoke(MethodInvocation invocation) throws Throwable { //用 commons-lang 提供的 StopWatch 計(jì)時(shí)，Spring 也提供了一個(gè) StopWatch StopWatch clock = new StopWatch(); clock.start(); //計(jì)時(shí)開始 Object result = invocation.proceed(); clock.stop(); //計(jì)時(shí)結(jié)束 //方法參數(shù)類型，轉(zhuǎn)換成簡(jiǎn)單類型 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.debug("Takes:" + clock.getTime() + " ms [" + invocation.getThis().getClass().getName() + "." + invocation.getMethod().getName() + "("+StringUtils.join(simpleParams,",")+")] "); return result; } }
4) HelloService.java 被攔截的業(yè)務(wù)類

package com.unmi.service; /** * @author Unmi */ public class HelloService { public void sayHello(int id,String name){ try { Thread.sleep(512); } catch (InterruptedException e) { e.printStackTrace(); } System.out.println("Hello "+name+"("+id+")"); } }
5) Main.java 主程序類

package com.unmi; import org.springframework.beans.factory.BeanFactory; import org.springframework.context.support.ClassPathXmlApplicationContext; import com.unmi.service.HelloService; /** * 測(cè)試主類 * @author Unmi */ public class Main { /** * @param args */ public static void main(String[] args) { BeanFactory factory =new ClassPathXmlApplicationContext("applicationContext.xml"); HelloService helloService = (HelloService)factory.getBean("helloService"); helloService.sayHello(1,"Unmi"); } }
執(zhí)行 Main 后輸出的結(jié)果是：

 Hello Unmi(1)
2008-01-18 13:41:25,593 [DEBUG] MethodTimeAdvice.invoke(34)
Takes:516 ms [com.unmi.service.HelloService.sayHello(int,String)]

 

如果不需要這個(gè)功能，只要在 applicationContext.xml 中把 id="methodTimeLog" 和 id="methodTimeAdvice" 配置項(xiàng)注釋掉就行了。

2. Spring 通用的方法攔截

Spring 1.x 因?yàn)椴荒苡?AspectJ 來(lái)對(duì)方法進(jìn)行攔截，要用到 ProxyFactoryBean 使用 AOP，具體操作方法只需要更換以上例子中的 applicationContext.xml 文件就行，內(nèi)容如下：

<?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE beans PUBLIC "-//SPRING//DTD BEAN//EN" "http://www.springframework.org/dtd/spring-beans.dtd"> <beans> <bean id="methodTimeAdvice" class="com.unmi.util.MethodTimeAdvice"/> <bean id="helloServiceTarget" class="com.unmi.service.HelloService"/> <bean id="methodTimeAdvisor" class="org.springframework.aop.support.RegexpMethodPointcutAdvisor"> <property name="advice"> <ref bean="methodTimeAdvice"/> </property> <!--對(duì)指定類的任何方法有效--> <property name="patterns"> <value>.*.*</value> </property> </bean> <bean id="helloService" class="org.springframework.aop.framework.ProxyFactoryBean"> <property name="interceptorNames"> <list> <value>methodTimeAdvisor</value> </list> </property> <property name="target"> <ref bean="helloServiceTarget"/> </property> </bean> </beans>

上面的配置方式需為每個(gè)應(yīng)用方法執(zhí)行時(shí)間記錄的 Bean 在外層包一個(gè) ProxyFactoryBean，原來(lái)的 Bean 設(shè)為一個(gè) Target 實(shí)在時(shí)麻煩了。

下面用一種應(yīng)用自動(dòng)代理的配置方式，指定 BeanNameAutoProxyCreator 的 beanNames 匹配模式即可，如果寫成 <value>*Service,*Manager</value>，逗號(hào)分隔開，以 Service 或 Manager 結(jié)層類的方法都被攔截，這樣方便許多。

<?xml version="1.0" encoding="UTF-8"?> <!DOCTYPE beans PUBLIC "-//SPRING//DTD BEAN//EN" "http://www.springframework.org/dtd/spring-beans.dtd"> <beans> <bean id="methodTimeAdvice" class="com.unmi.util.MethodTimeAdvice" /> <bean id="helloService" class="com.unmi.service.HelloService" /> <bean id="methodTimeAdvisor" class="org.springframework.aop.support.RegexpMethodPointcutAdvisor"> <property name="advice"> <ref bean="methodTimeAdvice" /> </property> <!--對(duì)指定類的任何方法有效--> <property name="patterns"> <value>.*.*</value> </property> </bean> <!-- 根據(jù) Bean 的名字自動(dòng)實(shí)現(xiàn)代理攔截 --> <bean class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator"> <property name="interceptorNames"> <list> <value>methodTimeAdvisor</value> </list> </property> <property name="beanNames"> <list> <!-- 添加到其中的 Bean 自動(dòng)就被代理攔截了 --> <value>*Service</value> </list> </property> </bean> </beans>

3. 直接用 AspectJ 實(shí)現(xiàn)

AspectJ 提供了一套語(yǔ)法來(lái)定義切面，Spring 2.0 開始引入了 AspectJ 的部分功能，但如果要用上 AspectJ 更多強(qiáng)大完善的功能，諸如實(shí)例構(gòu)造時(shí)，屬性被訪問時(shí)，動(dòng)態(tài)改變類定義，滋生新的屬性、方法，更強(qiáng)基于流程的控制時(shí)，恐怕非得顯式的使用 AspectJ。當(dāng)然，首先你得去 http://www.eclipse.org/aspectj/ 下載到 AspectJ 或者 AspectJ 的 Eclipse 插件。本人強(qiáng)烈建議使用 AspectJ 的 Eclipse 插件，請(qǐng)下載相應(yīng) Eclipse 版本的 AspectJ 插件，Eclipse 3.3 要搭配 AJDT: The AspectJ Development Tools 1.5。不要插件的話就得命令行下 ajc 編譯你的方面，不容易習(xí)慣的。 

AJDT 安裝成功后，你可以新建 AspectJ 項(xiàng)目，或者把前面項(xiàng)目轉(zhuǎn)換成 AspectJ 項(xiàng)目。從項(xiàng)目的上下文菜單中可以看到 AspectJ Tools -> Convert to Aspectj Project。然后在包 com.unmi.util 中新建一個(gè)方面，包 com.unmi.util 的上下文菜單中 New -> Aspect，輸入名字 MethodTimeAdviceRecipe，然后 Finish，這時(shí)就會(huì)在包 com.unmi.util 中產(chǎn)生一個(gè)文件 MethodTimeAdviceRecipe.aj，內(nèi)容如下：

MethodTimeAdviceRecipe.aj (那么 MethodTimeAdvice.java 就派不上用場(chǎng)了，可刪去)

package com.unmi.util; import org.apache.commons.lang.time.StopWatch; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; /** * 記錄方法的執(zhí)行時(shí)間 * @author Unmi */ public aspect MethodTimeAdviceRecipe { protected final Log log = LogFactory.getLog(MethodTimeAdvice.class); //攔截所有以 Service 結(jié)尾類的方法 pointcut callServicePointCut() : call(* *..*Service.*(..)) && !within(MethodTimeAdviceRecipe +); /** * 在方連接點(diǎn)(業(yè)務(wù)類方法)周圍執(zhí)行的通知 */ Object around() : callServicePointCut(){ //用 commons-lang 提供的 StopWatch 計(jì)時(shí)，Spring 也提供了一個(gè) StopWatch StopWatch clock = new StopWatch(); clock.start(); //計(jì)時(shí)開始 Object result = proceed(); clock.stop(); //計(jì)時(shí)結(jié)束 //顯示出方法原型及耗時(shí) log.debug("Takes: " + clock.getTime() + " ms ["+thisJoinPoint.getSignature()+"("+ thisJoinPoint.getSourceLocation().getLine()+")]"); return result; } }
再就是因?yàn)闊o(wú)需用到 Spring 了，不需要 IOC 了，相應(yīng)的 Main.java 的內(nèi)容如下：

Main.java (以前如何創(chuàng)建 HelloService，現(xiàn)在還是怎么做)

package com.unmi; import com.unmi.service.HelloService; /** * 測(cè)試主類 * @author Unmi */ public class Main { /** * @param args */ public static void main(String[] args) { HelloService helloService = new HelloService(); helloService.sayHello(1,"Unmi"); } }
OK，現(xiàn)在就可以在 Eclipse 中開始運(yùn)行 Main 類了，對(duì) methodTimeAdviceRecipe.aj 的編譯工作由插件 AJDT 自動(dòng)幫你作了(實(shí)質(zhì)是相匹配的類中插入了代碼)。運(yùn)行 Main 的結(jié)果如下：

Hello Unmi(1)
2008-01-21 13:48:16,171 [DEBUG] MethodTimeAdvice.sayHello_aroundBody1$advice(130)
Takes: 515 ms [void com.unmi.service.HelloService.sayHello(int, String)(16)]

用 AspectJ 可以很靈活的定義方面，局限就是對(duì)方面的改變須重新編譯相關(guān)類，而非配置方式。

參考：一個(gè)用Spring AOP實(shí)現(xiàn)異常處理和記錄程序執(zhí)行時(shí)間的實(shí)例

 

FORM:http://m.tkk7.com/Unmi/archive/2008/01/18/165849.html