java中记录方法调用时间，结果按照方法的层级树状的输出

​    ​    ​在java中，最常用的埋点时间的方法就是在方法运行前搞个常量记录当前时间，然后再方法结束的时候，搞个常量记录当前时间，然后两个的时间差就是方法的消耗时间。

    ​    ​这种处理问题不大，但是有时候我们想达到这样的效果，就是把树状的结构也搞出来。这样有层次，排查性能问题会非常方便。

 

1 2 3

0 [0ms] - rootMethod `---0 [0ms] - first     `---0 [0ms] - second

    ​    ​于是借助webx框架（已经开源http://openwebx.org/）中的Profiler类，结合AOP，做了一个简单的例子，代码已经搞到自己的github上了，这样可以直接搞代码用了。

    ​    ​github地址：https://github.com/iamzhongyong/treeProfiler

 

类名的基本介绍：

1、Profiler类的作用，方法的开始时间和结束时间埋点；

2、Entry类的左右，作为开始时间和结束时间的实体类，同时有个List类型的subEntries，这样就能描述树状的结构了；

3、ThreadLocal类，线程级别的内存缓存，统计的entry放置在这里，但是在线程结束之后，要记得清理掉；

4、ProfilerAspect，AOP的增强类；

 

如何使用：

1、添加AOP的配置，把ProfilerAspect作为一个普通的bean注入到容器中即可；

2、然后在需要统计时间的地方，可以使方法上，也可以是类上面，添加注解@ProfileAnno；

3、之后就可以在日志中看树状的统计信息了，在ProfilerSwith中有相应的开关，外部系统可以自行实现；

 

 

 

评论

6 楼 莫语snow 2014-04-12  

5 楼 莫语snow 2014-04-12  

最近做实验碰到了类似的情况，需要给出Call Graph.

下载了源码，运行ProfilerAopTest时，只能给第一个方法（A()）埋时间点，方法A调用的A1和方法A1调用的A11都失效。后来发现这是Spring AOP，跟踪“嵌套调用方法”（nested method）时常出现的问题。
在stackoverflow上找到了解决方法，不使用this对象调用方法就好用了。
http://stackoverflow.com/questions/5780757/spring-aop-logging-and-nested-methods

4 楼 iamzhongyong 2013-12-23  

kongxuan 写道

当你俺在支付宝的时候，用过这玩意。。

呵呵，目前看好多profiler的东西，都是参照宝宝的这个类搞的。看我这个类，膜拜宝宝呵呵

3 楼 iamzhongyong 2013-12-23  

liubey 写道

必须要依赖webx？

不用依赖webx，profiler这个类是来自webx的，我把这个类单独搞出来了，然后在我的github上搞了一份，因为非原创，所以提一下webx

2 楼 kongxuan 2013-12-22  

当你俺在支付宝的时候，用过这玩意。。

1 楼 liubey 2013-12-22  

必须要依赖webx？