[实践总结] 执行时间监视器StopWatch怎么使用？

[Q&A] 统计方法用时通俗做法

public static <T, R> R measureDuration(Function<T, R> f, T input) {
    long start = System.nanoTime();
    
    R result = f.apply(input);
    
    long duration = (System.nanoTime() - start) / 1_000_000;
    System.out.println("执行用时 " + duration + " seconds");
    
    return result;
}

---

[Q&A] StopWatch统计用时

第１步：引入依赖

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-context</artifactId>
    <version>5.1.3.RELEASE</version>
</dependency>

第２步：耗时收集

import org.springframework.util.StopWatch;

# 创建StopWatch 
StopWatch stopWatch = new StopWatch("任务组名称");

# 采集子任务用时
stopWatch.start("事前准备");
try {
    Thread.sleep(2000);
} catch (InterruptedException e) {
    throw new RuntimeException(e);
} finally {
    stopWatch.stop();
}

# 采集子任务用时
for (int i = 0; i < 5; i++) {
    stopWatch.start("子任务" + i);
    try {
        Thread.sleep(1000L);
    } catch (InterruptedException e) {
        throw new RuntimeException(e);
    } finally {
        stopWatch.stop();
    }
}

# 记录耗时信息
logStopWatch(stopWatch);

第３步：用时信息打印

3.1・自定义用时信息格式

public static void logStopWatch(StopWatch stopWatch) {
    String format = String.format("%s total cost time = %s ms", stopWatch.getId(), stopWatch.getTotalTimeMillis());
    System.out.println(format);
    log.info("{} total cost time = {}} ms", stopWatch.getId(), stopWatch.getTotalTimeMillis());
    
    for (StopWatch.TaskInfo taskInfo : stopWatch.getTaskInfo()) {
        String present = String.format("%.2f", (float) taskInfo.getTimeMillis() / stopWatch.getTotalTimeMillis() * 100);
        String format1 = String.format("%s cost : %s ms, %s%%", postFillSpace(taskInfo.getTaskName()), taskInfo.getTimeMillis(), present);
        System.out.println(format1);
        log.info("{} cost : {} ms, {}%", postFillSpace(taskInfo.getTaskName()), taskInfo.getTimeMillis(), present);
    }
}

public static String postFillSpace(String str) {
    if (str.length() >= 10) {
        return str;
    }
    return postFillSpace(str + " ");
}

// 输出结果：
任务组名称 total cost time = 7050 ms
事前准备       cost : 2014 ms, 28.57%
子任务0       cost : 1007 ms, 14.28%
子任务1       cost : 1010 ms, 14.33%
子任务2       cost : 1013 ms, 14.37%
子任务3       cost : 1003 ms, 14.23%
子任务4       cost : 1000 ms, 14.18%

3,2・默认用时信息格式

System.out.println(stopWatch.prettyPrint());

// 输出结果：
StopWatch '任务组名称': running time (millis) = 7031
-----------------------------------------
ms     %     Task name
-----------------------------------------
02002  028%  事前准备
01002  014%  子任务0
01008  014%  子任务1
01009  014%  子任务2
01004  014%  子任务3
01006  014%  子任务4

---

StopWatch其他方法介绍

stopWatch.shortSummary()         信息摘要                     StopWatch '任务组名称': running time = 7054477100 ns
stopWatch.getTotalTimeMillis()   所有任务总耗时               7059
stopWatch.currentTaskName()      currentTaskName             stop后它的值为null
stopWatch.getTaskCount()         任务总数                     6
stopWatch.getTaskInfo()          拿到所有的任务               [Lorg.springframework.util.StopWatch$TaskInfo;@41cf53f9
stopWatch.getLastTaskName()      获取最后一个任务的相关名字    子任务4
stopWatch.getLastTaskInfo()      获取最后一个任务的相关信息    org.springframework.util.StopWatch$TaskInfo@5a10411

---

参考

https://blog.csdn.net/f641385712/article/details/82591603