我的StopWatch

 

项目中一个功能很耗时，头儿让我看看是什么原因造成的，看能不能有什么调优。 

 

分析原因时得用数据支持吧， 也就是说看都有哪些因素造成了耗时，各贡献值具体是多少。顺着这个思路想起来和apache中common框架中的一个工具类org.apache.commons.lang.time StopWatch。 

 

它很好的模拟了秒表，通过它的split方法和getSplitTime方法，可以很好地看出各分步骤对性能下降的贡献值来。 

 

演示代码如下：

 

org.apache.commons.lang.time.StopWatch stWatch = new org.apache.commons.lang.time.StopWatch();

 

stWatch.start();

 

step1();

 

stWatch.split();

 

System.out.println("Time consumed by step1: "+stWatch.getSplitTime());

 

step2();

 

stWatch.split();

 

System.out.println("Time consumed by step1 and step2: "+stWatch.getSplitTime());

 

stWatch.stop();

 

 

显示结果： 

Time consumed by step1: 31

Time consumed by step1 and step2: 2031

 

还行，这毕竟比手动地写System.currentTimeMillis() – startTime来实现面向对象些。 

 

但有些不足，从结果可以看出，每次getSplitTime得到的值都是当前所有步骤的总和，而不是当前这个步骤的耗时值，以上面代码为例，它没有直接地得出step1和step2两个步骤的各自耗。有些遗憾啊。 

 

改！

 

于是原来基础上加了两个方法(加了方法的源码见附件)： splitAndSaveTime和getSplitTimeByStep。这样的演示代码如下：

 

   

    MyStopWatch stWatch = new MyStopWatch();

 

    stWatch.start();

 

    step1();

 

    stWatch.splitAndSaveTime();

 

    System.out.println("Time consumed by step1: "+stWatch.getSplitTimeByStep());

 

    step2();

 

    stWatch.splitAndSaveTime();

 

    System.out.println("Time consumed by   step2: "+stWatch.getSplitTimeByStep());

 

   stWatch.stop();

 

 

输出结果顺眼多了：

Time consumed by step1: 63

Time consumed by step2: 2000

 

 

记在这里备查，分享，交流。

 

评论

3 楼 mercyblitz 2010-03-22  

AOP就完事了

2 楼 rmn190 2009-12-23  

多谢提醒。 刚看完Perj4J， 再一次地感到了编程的魅力。

这个框架跟AOP的结合，跟自己想改造Log4J的想法不谋而合了。 自己动手又慢了。

谢谢！

1 楼 kiki 2009-12-23  

建议看下prof4j