耗时统计工具 stopwatch

计算 方法执行耗时 工具类研究1

平时的写法

long l = System.currentTimeMillis();
......
  
System.out.printf("consumer: %s ms \n",(System.currentTimeMillis() - l));

​ 写多了，总感觉不够灵活。 自己也实现过简单的工具类。前人肯定也有对应的 工具类来 让 重复的事情 变得更简单。再次温习下。

常见的有 spring util中的 StopWatch ， guava 的Stopwatch ，commons-lang3的 StopWatch。

org.springframework.util.StopWatch

• 提供了 每次 start的 任务的信息（name + 耗时），
• 不支持在 stop前获取 当前的耗时时间，返回的是上次 stop 的耗时时间。

public class StopWatchTest {

    @Test
    public void test() {

        StopWatch stopWatch = new StopWatch("id-1");
        stopWatch.start();
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        stopWatch.stop();

        printInfo(stopWatch);

        stopWatch.start("t2");
        try {
            Thread.sleep(2000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        System.out.println("获取执行中额时间。。。。。。");
        //获取的还是上次停止的时间
        System.err.println("【还未stop获取时间】stopWatch.getTotalTimeNanos()=" + stopWatch.getTotalTimeNanos());

        try {
            Thread.sleep(2000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        stopWatch.stop();

        printInfo(stopWatch);
    }

    private void printInfo(StopWatch stopWatch) {

        System.out.println("...........................");
        System.out.println("stopWatch.getId()=" + stopWatch.getId());
        System.err.println("stopWatch.getTotalTimeNanos()=" + stopWatch.getTotalTimeNanos());
        System.out.println("stopWatch.getTotalTimeMillis()=" + stopWatch.getTotalTimeMillis());
        System.out.println("stopWatch.getTotalTimeSeconds()=" + stopWatch.getTotalTimeSeconds());
        System.out.println("stopWatch.getTaskCount()=" + stopWatch.getTaskCount());

        for (StopWatch.TaskInfo taskInfo : stopWatch.getTaskInfo()) {
            System.out.println("taskInfo.getTaskName()=" + taskInfo.getTaskName() + ", taskInfo.getTimeMillis()=" + taskInfo.getTimeMillis());
        }
    }
    
  
  ---------
   ...........................
stopWatch.getId()=id-1
stopWatch.getTotalTimeMillis()=1004
stopWatch.getTotalTimeNanos()=1004721544  //
stopWatch.getTotalTimeSeconds()=1.004721544
stopWatch.getTaskCount()=1
taskInfo.getTaskName()=, taskInfo.getTimeMillis()=1004
    
获取执行中额时间。。。。。。
【还未stop获取时间】stopWatch.getTotalTimeNanos()=1004721544  //获取的是上次 stop的耗时时间
    
...........................
stopWatch.getTotalTimeNanos()=5011436351 //
stopWatch.getId()=id-1
stopWatch.getTotalTimeMillis()=5011
stopWatch.getTotalTimeSeconds()=5.011436351
stopWatch.getTaskCount()=2
taskInfo.getTaskName()=, taskInfo.getTimeMillis()=1004
taskInfo.getTaskName()=t2, taskInfo.getTimeMillis()=4006
    

com.google.common.base.Stopwatch

• 只计算耗时
• 适配 丰富的时间转换

public class StopWatch2Test {

    @Test
    public void test() {

        Stopwatch stopwatch = Stopwatch.createUnstarted();

        stopwatch.start();

        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        stopwatch.stop();

        printInfo(stopwatch);


        stopwatch.start();

        try {
            Thread.sleep(2000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        System.out.println("获取执行中额时间。。。。。。");
        System.err.println("【还未stop获取时间】stopWatch.getTotalTimeNanos()=" + stopwatch.elapsed(TimeUnit.NANOSECONDS));

        try {
            Thread.sleep(2000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }

        stopwatch.stop();

        printInfo(stopwatch);
    }

    private void printInfo(Stopwatch stopwatch) {
        System.out.println("..........................");
        System.err.println("stopwatch.elapsed(TimeUnit.MILLISECONDS)=" + stopwatch.elapsed(TimeUnit.MILLISECONDS));
        System.err.println("stopwatch.elapsed(TimeUnit.NANOSECONDS)=" + stopwatch.elapsed(TimeUnit.NANOSECONDS));
    }
}

----------------
  ..........................
stopwatch.elapsed(TimeUnit.MILLISECONDS)=1003
stopwatch.elapsed(TimeUnit.NANOSECONDS)=1003623225  //
获取执行中额时间。。。。。。
【还未stop获取时间】topwatch.elapsed(TimeUnit.NANOSECONDS)=3004966516  // 进行中的耗时
..........................
stopwatch.elapsed(TimeUnit.NANOSECONDS)=5006415530  //
stopwatch.elapsed(TimeUnit.MILLISECONDS)=5006

org.apache.commons.lang3.time.StopWatch

• 状态流转

• 添加了中间暂停方法。 返回 耗时 会 除去 suspend 的时间
  

<dependency>
  <groupId>org.apache.commons</groupId>
  <artifactId>commons-lang3</artifactId>
  <version>3.12.0</version>
</dependency>

@Test
    public void test() {

        StopWatch stopWatch = StopWatch.createStarted();

        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        System.out.println("运行中返回当前耗时 时间");
        System.out.println("stopWatch.getNanoTime()=" + stopWatch.getNanoTime());

        System.out.println("suspend......");
        stopWatch.suspend();
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        System.out.println("resume......");
        stopWatch.resume();

        System.out.println("运行中返回当前耗时 时间");
        System.out.println("stopWatch.getNanoTime()=" + stopWatch.getNanoTime());
    }
}

-------------------
运行中返回当前耗时 时间
stopWatch.getNanoTime()=1000353792
suspend......
resume......
运行中返回当前耗时 时间
stopWatch.getNanoTime()=1000463164

总结

这3个类总体功能一样，各自做了一些丰富，可以看下源码实现。