使用Spring3.0的AOP结合log4j实现接口方法执行时间记录

项目使用RPC提供的内部服务，需要监控每个接口方法的调用情况以及响应时间，如果接口方法开始和结束时都计时并将两个时间相减得到响应时间，势必对代码的入侵太大。使用AOP刚好能很优雅的解决这个问题！

?

1.log4j的配置log4j.xml。这里使用xml风格的配置

<appender name="info-out" value="/data/logs/hiluo-service/info.log" /><param name="DatePattern" value="'.'yyyy-MM-dd'.log'" /><layout value="%d{yyyy.MM.dd HH:mm:ss} [%C{1}:%M] %m%n" /></layout><filter value="info" /><param name="LevelMin" value="info" /><param name="AcceptOnMatch" value="true" /></filter></appender> 

log4j的配置参见：http://stonexmx.blog.163.com/blog/static/1221585872009716112428738/

PatternLayout输出格式参见：http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/PatternLayout.html

value="%d{yyyy.MM.dd HH:mm:ss} [%C{1}:%M] %m%n"，%C{1}-类名，如果使用%C将输出类的全路径名，%M-方法名

输出类似以下内容：

?

?

2.MethodTimeAdvice.java 用来记录时间

?

package yourpackage.utils;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.slf4j.Logger;import org.slf4j.LoggerFactory;public class MethodTimeAdvice implements MethodInterceptor {private static final Logger Log = LoggerFactory.getLogger(MethodTimeAdvice.class);@Overridepublic Object invoke(MethodInvocation invocation) throws Throwable {// 用 commons-lang 提供的 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();}Object[] args = invocation.getArguments();Log.info("Takes:" + clock.getTime() + " ms ["+ invocation.getThis().getClass().getName() + "."+ invocation.getMethod().getName() + "("+ StringUtils.join(simpleParams, ",") + ")("+ StringUtils.join(args, ",") + ")] ");return result;}}

?

3.applicationContext.xml

?

<?xml version="1.0" encoding="UTF-8"?><beans xmlns="http://www.springframework.org/schema/beans"xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:p="http://www.springframework.org/schema/p"xmlns:context="http://www.springframework.org/schema/context"xmlns:aop="http://www.springframework.org/schema/aop"xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-3.0.xsd            http://www.springframework.org/schema/context http://www.springframework.org/schema/context/spring-context-3.0.xsd            http://www.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-3.0.xsd"default-lazy-init="true">        <aop:aspectj-autoproxy /><bean id="methodTimeAdvice" /><aop:config><!-- 用 AspectJ 的语法定义 Pointcut，这里拦截 service 包中的所有方法 --><aop:advisor id="methodTimeLog" advice-ref="methodTimeAdvice"pointcut="execution(* yourpackage.service.impl..*.*(..))" /></aop:config>        <bean id="yourservice" 的配置语法
?
6.最后在info.log里面可以看到如上图的输出，最后再用shell统计即可。
?
参考：
http://jportal.iteye.com/blog/945725
?
http://www.java63.com/spring/configure_implement_aop.html
?
因为对spring的aop不是很熟，在实现上有细节问题，在此记录下！