耗时统计利器——StopWatch秒表

【前言】在程序性能分析的过程中，最直观的方式就是通过统计程序的实际耗时来衡量代码的性能，从而了解程序的整体性能表现，以便快速定位出耗时长的位置进行分析优化。

以往我们统计的程序的运行时间，常常采用如下的方式：

public class StaticTimeTest {

    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):1012

如果想获取各阶段的耗时，以更友好的方式给出各个代码块的执行时间统计结果，往往需要封装更多的代码来完成。StopWatch给我们提供了更加优雅的方式，去统计程序各部分耗时情况，让我们更纯粹的关注于业务逻辑的本身，堪称耗时统计的利器。

StopWatch核心方法

在org.springframework.util包下我们可以找到这个工具类，作者在源码中标注的描述信息如下：

Simple stop watch, allowing for timing of a number of tasks, exposing total running time and running time for each named task.
Conceals use of System.nanoTime(), improving the readability of application code and reducing the likelihood of calculation errors.
Note that this object is not designed to be thread-safe and does not use synchronization.
This class is normally used to verify performance during proof-of-concept work and in development, rather than as part of production applications.
As of Spring Framework 5.2, running time is tracked and reported in nanoseconds.

Since: May 2, 2001
Author: Rod Johnson, Juergen Hoeller, Sam Brannen

从作者的这段描述信息中我们可以看到，StopWatch秒表工具允许对多个任务计时，显示程序总耗时和每个指定任务的运行时间。

其隐藏了System.nanoTime（）的使用，通过该工具封装，提高应用程序代码的可读性，降低计算错误的可能性。

请注意，此对象不是为线程安全而设计的，并且不使用同步。通常用于概念验证工作和开发期间测试程序的性能，而不是作为生产应用程序的一部分。从Spring Framework 5.2开始，运行时间以纳秒为单位进行跟踪和报告。

Hutool基于Spring Framework的工具类，对秒表工具进行了进一步的封装，常用方法如下：

• create(String id)：创建一个指定id的计时任务
• getId()：获取StopWatch的ID，用于多个秒表对象的区分
• setKeepTaskList(boolean keepTaskList): 设置是否在停止后保留任务
• start()：开始默认的新任务计时
• start(String taskName)：开始指定名称的新任务计时
• stop()：结束当前任务的计时
• getTotalTimeNanos()：获取所有任务的执行时间（纳秒）
• getTotalTimeMillis()：获取全部任务的执行时间（毫秒）
• getTotalTimeSeconds()：获取全部任务的执行时间（秒）
• shortSummary()：获取简单的统计信息
• prettyPrint()：以友好方式输出总统计时间，以及各个阶段任务的执行时间

StopWatch实战

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

public class StaticTimeTest {
    public static void main(String[] args) throws InterruptedException {
        StopWatch stopWatch = new StopWatch("测试 task");
        stopWatch.start("任务阶段1");
        Thread.sleep(1000);
        stopWatch.stop();
        stopWatch.start("任务阶段2");
        Thread.sleep(2000);
        stopWatch.stop();
        stopWatch.start("任务阶段3");
        System.out.println("任务执行...");
        stopWatch.stop();
        System.out.println(stopWatch.prettyPrint());  
    }
}
		// 运行结果如下：
		任务执行...
		StopWatch '测试 task': running time = 3019289500 ns
		---------------------------------------------
		ns         %     Task name
		---------------------------------------------
		1008034300  033%  任务阶段1
		2010897200  067%  任务阶段2
		000358000  000%  任务阶段3

源码分析

StopWatch的源码实现非常简单，可以看下springframework的源码如下：

	/**
	 * Start a named task.
	 * <p>The results are undefined if {@link #stop()} or timing methods are
	 * called without invoking this method first.
	 * @param taskName the name of the task to start
	 * @see #start()
	 * @see #stop()
	 */
	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();
	}

	/**
	 * Stop the current task.
	 * <p>The results are undefined if timing methods are called without invoking
	 * at least one pair of {@code start()} / {@code stop()} methods.
	 * @see #start()
	 * @see #start(String)
	 */
	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;
	}

看到这，大家可能会恍然大悟，StopWatch主要是围绕着System.nanoTime封了一层时间相减的外衣进行操作。
但妙就妙在，这层外衣足够的漂亮，足够的优雅。通过内部静态类TaskInfo 可以记录每个子任务的名称耗时信息，以及按格式化打印结果，尤其是针对多任务统计时更友好一点。

PS. System.nanoTime与System.currentTimeMillis的区别
System.nanoTime提供相对精确的计时，但是不能用他来计算当前日期。返回最准确的可用系统计时器的当前值，以纳秒为单位。此方法只能用于测量已过的时间，与系统或钟表时间的其他任何时间概念无关。
System.currentTimeMillis返回的是从1970.1.1 UTC 零点开始到现在的时间，精确到毫秒，平时我们可以根据System.currentTimeMillis来计算当前日期，星期几等，可以方便的与Date进行转换。

总结

StopWatch的封装很漂亮，日常可以使用秒表来进行耗时统计，性能评估，排查问题。
多读源码，向高手学习。Fighting…