用Perf4j做全局性能统计

小编辑 发布于 2010/02/09 00:56
阅读 1K+
收藏 10

今天下午听Kevin提到Perf4j,想起昨晚在InfoQ瞟到过这个名词,晚上回家改完系统,等着看数据更新状况,百般无聊,于是决定下载 Perf4j玩玩,聊以解闷

(前言:不知道怎么搞的,codehaus.org在公司访问好好的,回家来就访问不了了,显然是被墙间了,只好翻墙上了 perf4j.codehaus.org下载jar包,又找了半天的HTTP PROXY配到SVN里下载了源码——始筑墙者,其无后乎?)

首先试用了下perf4j直接写代码的方式:

public UserDTO getUserByUsername(String username) {
    StopWatch stopWatch = new Slf4JStopWatch("getUserByUsername", username);
    User user = userService.getUserByUsername(username);
    logger.debug("Supported user {}", user);
    stopWatch.stop();
    return user == null ? null : mapper.map(user, UserDTO.class);
}

其中getUserByUsername是我的方法名,作为tag,username是方法参数作为message。跑了一下,slf4j出结果 了,OK一切正常。

但是这种方法实在是太累赘了,每个方法都得去加代码,而且最后一行的性能还统计不到-_-(除非改代码)

遂改用@Profiled注解方式,方法里改成:

@Profiled
public UserDTO getUserByUsername(String username) {
    User user = userService.getUserByUsername(username);
    logger.debug("Supported user {}", user);
    return user == null ? null : mapper.map(user, UserDTO.class);
}

同时在Spring配置文件里配置上AOP自动代理与perf4j:

<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.springframework.org/schema/aop http://www.springframework.org/schema/aop/spring-aop-2.0.xsd">
    <aop:aspectj-autoproxy/>
    <bean id="timingAspect" class="org.perf4j.slf4j.aop.TimingAspect"/>
</beans>

这回舒服多了,@Profile可以携带多个参数,甚至包含el表达式,不过我感觉默认就挺够用的了,呵呵,具体使用可以参见源码的 Javadoc,里面写的很详细。执行代码,pass

于是着手开始改项目,结果发现。。。要加注释的方法太多了-_-。想起Spring的@Transactional,可惜@Profiled不能加 在类上

身为一个慵懒的程序员,这种Annotation的方式显然还不够适合我,于是删掉Annotation们重新来搞

先在Spring的applicationContext里加一个AOP的bean:

<bean class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
    <property name="beanNames">
        <list>
            <value>*RemoteImpl</value>
        </list>
    </property>
    <property name="interceptorNames">
        <list>
            <value>perf4jInterceptor</value>
        </list>
    </property>
</bean> 

其中*RemoteImpl是我需要统计用的类,类名都是以RemoteImpl结尾;perf4jInterceptor是用于拦截的拦截器 bean,代码如下:

@Service
public class Perf4jInterceptor implements MethodBeforeAdvice, AfterReturningAdvice {

    private Map<String, StopWatch> watches = new HashMap<String, StopWatch>();

    public void before(Method method, Object[] args, Object target) throws Throwable {
        String completeMethodName = getCompleteMethodName(target, method);
       
        // 创建性能日志记录器
        StopWatch stopWatch;
        if (watches.containsKey(completeMethodName)) {
            stopWatch = watches.get(completeMethodName);
            stopWatch.start();
        } else {
            stopWatch = new Slf4JStopWatch(completeMethodName, Arrays.toString(args));
            watches.put(completeMethodName, stopWatch);
        }

    }

    public void afterReturning(Object returnValue, Method method, Object[] args, Object target) throws Throwable {
        String completeMethodName = getCompleteMethodName(target, method);

        // 记录性能
        if (watches.containsKey(completeMethodName)) {
            StopWatch stopWatch = watches.get(completeMethodName);
            stopWatch.stop();
        }      
    }

    /**
     * 根据目标对象与方法获取方法完整名称.
     * @param target 目标对象
     * @param method 方法
     * @return 方法完整名称
     */
    private String getCompleteMethodName(Object target, Method method) {
        String className = "";
        if (target != null) {
            className = target.toString();
            int loc = className.indexOf("@");
            if (loc >= 0) {
                className = className.substring(0, loc);
            }
        }
       
        return className + "." + method.getName();
    }
}

OK,这样项目中所有以RemoteImpl结尾的类的所有方法均被列入了性能记录行列

再次执行代码调用方法进行测试,pass

最后将系统日志文件拷贝出来,执行:

grep perf4j publication.log > a
java -jar perf4j-0.9.10.jar -g g.html a

即可看到统计结果:

Performance Statistics   02:47:00 - 02:47:30
Tag                                                  Avg(ms)         Min         Max     Std Dev       Count
com.baidu.uic.publication.remoting.impl.UserRemoteImpl.getAllUsersByContactWithPage      2098.0          94       14625      4088.8          11
com.baidu.uic.publication.remoting.impl.UserRemoteImpl.getUserByUsername       153.3           0        1297       382.6          10

Performance Statistics   02:47:30 - 02:48:00
Tag                                                  Avg(ms)         Min         Max     Std Dev       Count
com.baidu.uic.publication.remoting.impl.UserRemoteImpl.getAllUsersByContactWithPage      2985.8          63        7406      2979.8          10
com.baidu.uic.publication.remoting.impl.UserRemoteImpl.getUserByUsername         1.6           0          16         4.8          10 

下面是生成的图表:

点击查看原始尺寸

点击查看原始尺寸

OK,这是第一次接触Perf4j,看了下Perf4j的代码,比较简单,不过相比自己实现还是省了不少事儿,更有日志分析和统计图形生成器,用起 来还是比较舒服的,呵呵

加载中
0
c
code_cj
不错,需要考虑下多线程问题.
0
j
jijianban

也算找到原创了,发帖于8年前,那时我在干嘛``,特意登录评论下

OSCHINA
登录后可查看更多优质内容
返回顶部
顶部