计时器工具 StopWatch

我是陈皮，一个在互联网 Coding 的 ITer，个人微信公众号「陈皮的JavaLib」关注第一时间阅读最新文章。

文章目录

前言
Spring StopWatch
实践例子
源码分析
lang3 StopWatch
总结

前言

平常，我们想要统计某一段代码块，或某一个方法的执行时间，最简单的是采用如下的方式。

package com.chenpi;/*** @author 陈皮* @version 1.0* @description* @date 2022/4/2*/
public class ChenPi {public static void main(String[] args) throws InterruptedException {long startTime = System.currentTimeMillis();Thread.sleep(1000);long endTime = System.currentTimeMillis();System.out.println("执行耗时(ms):" + (endTime - startTime));}}// 输出结果如下
执行耗时(ms):1011

但如果我们想对多个代码段进行计时，以及每个阶段计时的占比等信息，如果还是采用如上的方式就会充斥比较多的与业务无关的代码，不够简洁。

Spring StopWatch

Spring 框架有个工具类 StopWatch，它可以用来对程序中代码块，或者方法进行计时，并且支持多阶段计时，以及阶段时间占比等统计，使用起来代码比较简洁，轻量。

package com.chenpi;import org.springframework.util.StopWatch;/*** @author 陈皮* @version 1.0* @description* @date 2022/4/2*/
public class ChenPi {public static void main(String[] args) throws InterruptedException {// 声明一个计时器StopWatch stopWatch = new StopWatch("陈皮的计时器");// 开始计时stopWatch.start("发送MQ计时");Thread.sleep(1000);// 结束计时stopWatch.stop();// 打印统计System.out.println(stopWatch.prettyPrint());}}// 输出结果如下
StopWatch '陈皮的计时器': running time = 1005775500 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1005775500  100%  发送MQ计时

Spring StopWatch 有以下几个常用方法：

StopWatch()：构造一个计时器
StopWatch(String id)：构造一个指定 id 的计时器
start()：创建一个名为空字符串的计时任务，开始计时
start(String taskName)：创建一个指定名称计时任务，开始计时
stop()：结束当前任务的计时
getTotalTimeNanos()：获取全部任务的执行时间，单位纳秒
getTotalTimeMillis()：获取全部任务的执行时间，单位毫秒
shortSummary()：获取简单的统计信息
prettyPrint()：以友好方式输出总统计时间，以及各个阶段任务的执行时间
setKeepTaskList(boolean keepTaskList)：是否在内部的列表中存储每一个任务

实践例子

当程序中有多个计时器时，可通过构造不同 id 的计时器来区分。以下演示多个不同计时器，统计不同阶段的执行时间。

package com.chenpi;import org.springframework.util.StopWatch;/*** @author 陈皮* @version 1.0* @description* @date 2022/4/2*/
public class ChenPi {public static void main(String[] args) throws InterruptedException {m1();m2();}private static void m1() throws InterruptedException {// 声明一个计时器StopWatch stopWatch = new StopWatch("m1计时器");stopWatch.start("查询数据库");Thread.sleep(1000);stopWatch.stop();stopWatch.start("逻辑计算");Thread.sleep(500);stopWatch.stop();System.out.println(stopWatch.prettyPrint());}private static void m2() throws InterruptedException {// 声明一个计时器StopWatch stopWatch = new StopWatch("m2计时器");stopWatch.start("远程调用");Thread.sleep(800);stopWatch.stop();stopWatch.start("发送MQ");Thread.sleep(200);stopWatch.stop();System.out.println(stopWatch.prettyPrint());}
}// 输出结果如下
StopWatch 'm1计时器': running time = 1516953200 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1008091000  066%  查询数据库
508862200  034%  逻辑计算StopWatch 'm2计时器': running time = 1013080000 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
809345900  080%  远程调用
203734100  020%  发生MQ

源码分析

其实 StopWatch 底层实现很简单，对于每一个任务，在任务开始和结束时刻调用System.nanoTime()方法获取服务器当前的时间，然后计算每一个任务的执行时间，存储在内部。内部使用一个列表存储不同任务阶段的执行时间，最后打印输出。

package org.springframework.util;import java.text.NumberFormat;
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.TimeUnit;import org.springframework.lang.Nullable;public class StopWatch {// 计时器idprivate final String id;// 是否将任务存储到任务列表中private boolean keepTaskList = true;// 存储全部任务的列表private final List<TaskInfo> taskList = new ArrayList<>(1);// 当前任务开始时间private long startTimeNanos;// 当前任务名称@Nullableprivate String currentTaskName;// 最后一个任务@Nullableprivate TaskInfo lastTaskInfo;// 总任务数private int taskCount;// 总的执行时间private long totalTimeNanos;// 构造一个id为空字符串的计时器public StopWatch() {this("");}// 构造一个指定id的计时器public StopWatch(String id) {this.id = id;}// 获取计时器idpublic String getId() {return this.id;}public void setKeepTaskList(boolean keepTaskList) {this.keepTaskList = keepTaskList;}// 开始计时public void start() throws IllegalStateException {start("");}// 开始一个指定任务名称的计时public void start(String taskName) throws IllegalStateException {if (this.currentTaskName != null) {throw new IllegalStateException("Can't start StopWatch: it's already running");}this.currentTaskName = taskName;this.startTimeNanos = System.nanoTime();}// 停止任务计时public void stop() throws IllegalStateException {if (this.currentTaskName == null) {throw new IllegalStateException("Can't stop StopWatch: it's not running");}long lastTime = System.nanoTime() - this.startTimeNanos;this.totalTimeNanos += lastTime;this.lastTaskInfo = new TaskInfo(this.currentTaskName, lastTime);if (this.keepTaskList) {this.taskList.add(this.lastTaskInfo);}++this.taskCount;this.currentTaskName = null;}public boolean isRunning() {return (this.currentTaskName != null);}@Nullablepublic String currentTaskName() {return this.currentTaskName;}public long getLastTaskTimeNanos() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task interval");}return this.lastTaskInfo.getTimeNanos();}public long getLastTaskTimeMillis() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task interval");}return this.lastTaskInfo.getTimeMillis();}public String getLastTaskName() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task name");}return this.lastTaskInfo.getTaskName();}public TaskInfo getLastTaskInfo() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task info");}return this.lastTaskInfo;}public long getTotalTimeNanos() {return this.totalTimeNanos;}public long getTotalTimeMillis() {return nanosToMillis(this.totalTimeNanos);}public double getTotalTimeSeconds() {return nanosToSeconds(this.totalTimeNanos);}public int getTaskCount() {return this.taskCount;}public TaskInfo[] getTaskInfo() {if (!this.keepTaskList) {throw new UnsupportedOperationException("Task info is not being kept!");}return this.taskList.toArray(new TaskInfo[0]);}public String shortSummary() {return "StopWatch '" + getId() + "': running time = " + getTotalTimeNanos() + " ns";}public String prettyPrint() {StringBuilder sb = new StringBuilder(shortSummary());sb.append('\n');if (!this.keepTaskList) {sb.append("No task info kept");}else {sb.append("---------------------------------------------\n");sb.append("ns         %     Task name\n");sb.append("---------------------------------------------\n");NumberFormat nf = NumberFormat.getNumberInstance();nf.setMinimumIntegerDigits(9);nf.setGroupingUsed(false);NumberFormat pf = NumberFormat.getPercentInstance();pf.setMinimumIntegerDigits(3);pf.setGroupingUsed(false);for (TaskInfo task : getTaskInfo()) {sb.append(nf.format(task.getTimeNanos())).append("  ");sb.append(pf.format((double) task.getTimeNanos() / getTotalTimeNanos())).append("  ");sb.append(task.getTaskName()).append('\n');}}return sb.toString();}@Overridepublic String toString() {StringBuilder sb = new StringBuilder(shortSummary());if (this.keepTaskList) {for (TaskInfo task : getTaskInfo()) {sb.append("; [").append(task.getTaskName()).append("] took ").append(task.getTimeNanos()).append(" ns");long percent = Math.round(100.0 * task.getTimeNanos() / getTotalTimeNanos());sb.append(" = ").append(percent).append('%');}}else {sb.append("; no task info kept");}return sb.toString();}private static long nanosToMillis(long duration) {return TimeUnit.NANOSECONDS.toMillis(duration);}private static double nanosToSeconds(long duration) {return duration / 1_000_000_000.0;}// 任务实体public static final class TaskInfo {// 任务名称private final String taskName;// 任务执行时间private final long timeNanos;TaskInfo(String taskName, long timeNanos) {this.taskName = taskName;this.timeNanos = timeNanos;}public String getTaskName() {return this.taskName;}public long getTimeNanos() {return this.timeNanos;}public long getTimeMillis() {return nanosToMillis(this.timeNanos);}public double getTimeSeconds() {return nanosToSeconds(this.timeNanos);}}}

StopWatch 使用起来简洁，支持多任务阶段统计，统计多任务时间占比等，统计结果直观。但是它也有不好的地方，就是一个 StopWatch 实例只能同时 start 一个 task，只能等这个 task 进行 stop 之后，才能继续 start 另一个 task。注意，StopWatch 实例不是线程安全的，也没必要进行同步处理。

lang3 StopWatch

Apache commons lang3 包下也有一个用于计时工具类 StopWatch。它还有暂停计时，恢复计时，设置分割点等功能。

org.apache.commons:commons-lang3:3.12.0

它主要有以下几个常用方法：

create()：实例化一个计时器
createStarted()：实例化一个计时器，并开始计时
StopWatch(final String message)：实例化一个带有标识符的计时器
start()：开始计时
split()：设置分割点
getSplitTime()：统计从 start 开始最后一个分割点的用时
reset()：重置计时
suspend()：暂停计时
resume()：恢复计时
stop()：停止计时
getTime()：统计从 start 到当前时刻的同时

package com.chenpi;import org.apache.commons.lang3.time.StopWatch;/*** @author 陈皮* @version 1.0* @description* @date 2022/4/2*/
public class ChenPi {public static void main(String[] args) throws InterruptedException {// 声明一个计时器StopWatch stopWatch = new StopWatch("m1计时器");stopWatch.start();Thread.sleep(1000);System.out.println("start开始到现在的时间：" + stopWatch.getTime());stopWatch.split();Thread.sleep(500);System.out.println("start开始到最后一个split的时间：" + stopWatch.getSplitTime());stopWatch.split();Thread.sleep(500);System.out.println("start开始到最后一个split的时间：" + stopWatch.getSplitTime());// 重置计时stopWatch.reset();Thread.sleep(2000);stopWatch.start();Thread.sleep(1000);System.out.println("start开始到现在的时间：" + stopWatch.getTime());// 暂停计时stopWatch.suspend();Thread.sleep(3000);// 恢复计时stopWatch.resume();Thread.sleep(1000);// 结束计时stopWatch.stop();Thread.sleep(1000);System.out.println("start开始到stop结束的时间：" + stopWatch.getTime());System.out.println(stopWatch);}
}// 输出结果如下
start开始到现在的时间：1000
start开始到最后一个split的时间：1001
start开始到最后一个split的时间：1510
start开始到现在的时间：1004
start开始到stop结束的时间：2015
m1计时器 00:00:02.015

总结

如果是简单的计算执行计时，可以使用 JDK 自带的类获取系统时间进行计时。
如果需要多阶段计时，并且需要统计每个阶段的执行时间占比等信息，可以使用 StopWatch 工具类。
推荐使用 Spring StopWatch，因为本身我们项目使用 Spring 框架比较多，这样就自带了 StopWatch。

本次分享到此结束啦~~

如果觉得文章对你有帮助，点赞、收藏、关注、评论，您的支持就是我创作最大的动力！