stopwatch 统计耗时工具

在日常开发中，经常需要看方法各部分的耗时，通常的做法如下：

long start = System.currentTimeMillis();

//业务代码

long end =  System.currentTimeMillis();

System.out.println("耗时:" + (System.currentTimeMillis() - start) + "ms");

如果要计算多个就要不停重复写，比较繁琐，所以我们就可以使用StopWatch工具类。

常见的有 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("test1");
        stopWatch.start();
        try {
            Thread.sleep(1000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
        stopWatch.stop();

        printInfo(stopWatch);

        stopWatch.start("test2");
        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()=test1
stopWatch.getTotalTimeNanos()=999667500
毫秒：stopWatch.getTotalTimeMillis()=999
秒：stopWatch.getTotalTimeSeconds()=0.9996675
任务总数：stopWatch.getTaskCount()=1
taskInfo.getTaskName()=, taskInfo.getTimeMillis()=999
获取执行中时间。。。。。。
【没有stop直接获取时间】stopWatch.getTotalTimeNanos()=999667500
...........................
stopWatch.getTotalTimeNanos()=5017381700
stopWatch.getId()=test1
毫秒：stopWatch.getTotalTimeMillis()=5017
秒：stopWatch.getTotalTimeSeconds()=5.0173817
任务总数：stopWatch.getTaskCount()=2
taskInfo.getTaskName()=, taskInfo.getTimeMillis()=999
taskInfo.getTaskName()=test2, taskInfo.getTimeMillis()=4017

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)=1008
stopwatch.elapsed(TimeUnit.NANOSECONDS)=1008945500
获取执行中时间。。。。。。
【没有stop直接获取时间】stopWatch.getTotalTimeNanos()=3014257900
stopwatch.elapsed(TimeUnit.MILLISECONDS)=5015
..........................
stopwatch.elapsed(TimeUnit.NANOSECONDS)=5015885900

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