使用 StopWatch 优雅打印执行耗时

0x01：背景

有时在做开发的时候需要记录每个任务执行时间，或者记录一段代码执行时间，最简单的方法就是打印当前时间与执行完时间的差值，然后这样如果执行大量测试的话就很麻烦，并且不直观，如果想对执行的时间做进一步控制，则需要在程序中很多地方修改，目前spring-framework提供了一个StopWatch类可以做类似任务执行时间控制，也就是封装了一个对开始时间，结束时间记录工具

示例

先来看几个示例

• 统计输出总耗时

 1import org.springframework.util.StopWatch;
 2
 3public class SpringStopWatchExample {
 4
 5    public static void main (String[] args) throws InterruptedException {
 6        StopWatch sw = new StopWatch();
 7        sw.start();
 8        //long task simulation
 9        Thread.sleep(1000);
10        sw.stop();
11        System.out.println(sw.getTotalTimeMillis());
12    }
13}

输出

11013

• 输出最后一个任务的耗时

 1public class SpringStopWatchExample2 {
 2
 3    public static void main (String[] args) throws InterruptedException {
 4        StopWatch sw = new StopWatch();
 5        sw.start("A");//setting a task name
 6        //long task simulation
 7        Thread.sleep(1000);
 8        sw.stop();
 9        System.out.println(sw.getLastTaskTimeMillis());
10    }
11}

输出

11009

• 以优雅的格式打出所有任务的耗时以及占比

 1import org.springframework.util.StopWatch;
 2
 3public class SpringStopWatchExample3 {
 4
 5    public static void main (String[] args) throws InterruptedException {
 6        StopWatch sw = new StopWatch();
 7        sw.start("A");
 8        Thread.sleep(500);
 9        sw.stop();
10        sw.start("B");
11        Thread.sleep(300);
12        sw.stop();
13        sw.start("C");
14        Thread.sleep(200);
15        sw.stop();
16        System.out.println(sw.prettyPrint());
17    }
18}

输出

1StopWatch '': running time (millis) = 1031
2-----------------------------------------
3ms     %     Task name
4-----------------------------------------
500514  050%  A
600302  029%  B
700215  021%  C:

• 序列服务输出耗时信息

1@Override
2public long nextSeq(String name) {
3    StopWatch watch = new StopWatch();
4    watch.start("单序列获取总消耗");
5    long sequence = generator.generateId(name);
6    watch.stop();
7    logger.info(watch.prettyPrint());
8    return sequence;
9}

0x02：更多用法

不同的打印结果

• getTotalTimeSeconds() 获取总耗时秒，同时也有获取毫秒的方法

• prettyPrint() 优雅的格式打印结果，表格形式

• shortSummary() 返回简短的总耗时描述

• getTaskCount() 返回统计时间任务的数量

• getLastTaskInfo().getTaskName() 返回最后一个任务TaskInfo对象的名称

更多查看文档

1https://docs.spring.io/spring-framework/docs/current/javadoc-api/org/springframework/util/StopWatch.html

0x03：总结

以后统计代码执行效率建议大家都使用这个工具来进行输出，不需要在starttime、endtime再相减计算，用优雅的方式来完成这件事情。