Spring Boot源碼實現StopWatch優雅統計耗時

Posted on by

引言

昨天，一位球友問我能不能給他解釋一下 @SpringBootApplication 註解是什麼意思，還有 Spring Boot 的運行原理，於是我就帶著他扒拉瞭一下這個註解的源碼，還有 SpringApplication 類的 run() 方法的源碼，一下子他就明白瞭。

你別說，看源碼的過程還真的是挺有趣，這不，我就發現瞭一個有意思的點。

public ConfigurableApplicationContext run(String... args) {
	StopWatch stopWatch = new StopWatch();
	stopWatch.start();
	......
	stopWatch.stop();
}

Spring Boot 是用 StopWatch 來統計耗時的，而通常情況下，我們會用 System.currentTimeMillis() 來統計耗時，對吧？編程喵🐱開源項目裡就有這樣一段代碼，在處理統一日志處理切面的時候。

@Around("webLog()")
public Object doAround(ProceedingJoinPoint joinPoint) throws Throwable {
    long startTime = System.currentTimeMillis();
    long endTime = System.currentTimeMillis();
    webLog.setSpendTime((int) (endTime - startTime));
}

對比之下，我們就能發現，JDK 提供的 System.currentTimeMillis() 沒有 Spring 提供的 StopWatch 簡潔、清晰。

StopWatch使用

尤其是在多任務的情況下，StopWatch 簡直好用到爆🤗！

// 創建一個 StopWatch 實例
StopWatch sw = new StopWatch("沉默王二是傻 X");
// 開始計時
sw.start("任務1");
Thread.sleep(1000);
// 停止計時
sw.stop();
System.out.printf("任務1耗時：%d%s.\n", sw.getLastTaskTimeMillis(), "ms");
sw.start("任務2");
Thread.sleep(1100);
sw.stop();
System.out.printf("任務2耗時：%d%s.\n", sw.getLastTaskTimeMillis(), "ms");
System.out.printf("任務數量：%s，總耗時：%ss.\n", sw.getTaskCount(), sw.getTotalTimeSeconds());

看到沒，是不是很簡單？

  • 先 new 一個 StopWatch 對象
  • 再 start 開始計時
  • 然後 stop 停止計時
  • 最後通過 sw.getLastTaskTimeMillis() 得出時間差

如果換成 System.currentTimeMillis() 就要瞭老命，先得聲明好幾個 long 型的局部變量，然後要第二個減第一個，第三個減第二個，稍微粗心一點（尤其是 CV 大法）時，很容易搞錯。

除瞭可以通過局部時間，還可以通過 sw.getTotalTimeSeconds() 獲取總的耗時。

任務1耗時：1002ms.
任務2耗時：1105ms.
任務數量：2，總耗時：2.107820109s.

另外，StopWatch 還提供瞭一個 sw.prettyPrint() 方法供打印出漂亮的格式化結果：

StopWatch '沉默王二是傻 X': running time = 2108529351 ns
———————————————
ns         %     Task name
———————————————
1004338467  048%  任務1
1104190884  052%  任務2

有耗時，有占用百分比，還有任務名，非常清晰。

除瞭 Spring，hutool 工具庫和 Apache common 工具包都提供瞭各自的 StopWatch。

查看 hutool 工具庫中的 StopWatch 源碼可以得出，該類其實就來自 Spring 的 StopWatch.java，用法也完全一致。

這說明 hutool 的作者也認為 Spring 的 StopWatch 寫得好，哈哈哈😁。

使用Beyond compare比較

使用 Beyond compare 比較後也能得出，兩者除瞭一個中文註釋，一個英文註釋，代碼幾乎一樣。setKeepTaskList 方法有比較大的不同。

那也就是說，如果你的項目中沒有使用 Spring 全傢桶，隻用瞭 hutool 工具包，那就可以使用 hutool 的 StopWatch 來代替 System.currentTimeMillis()。

通過分析 StopWatch 的 stop 方法源碼：

public void stop() throws IllegalStateException {
	if (null == this.currentTaskName) {
		throw new IllegalStateException("Can't stop StopWatch: it's not running");
	}
	final long lastTime = System.nanoTime() - this.startTimeNanos;
	this.totalTimeNanos += lastTime;
	this.lastTaskInfo = new TaskInfo(this.currentTaskName, lastTime);
	if (null != this.taskList) {
		this.taskList.add(this.lastTaskInfo);
	}
	++this.taskCount;
	this.currentTaskName = null;
}

其實可以發現，StopWatch 的內部是通過 System.nanoTime() 來計時的，本質上和 System.currentTimeMillis() 差別並不大。

nanoTime 比 currentTimeMillis 的粒度更細，前者是以納秒為單位，後者是以毫秒為單位。

註意兩者都是 native 方法，也就是說，值的粒度其實取決於底層的操作系統。

看到這，大傢可能會恍然大悟，StopWatch 不過是披著一層外衣的 System.currentTimeMillis() 嘛？

但妙就妙在，這層外衣足夠的漂亮，足夠的優雅。StopWatch 可以記錄每個子任務的名稱，以及按格式化打印結果，尤其是針對多任務統計時更友好一點。

當然瞭，除瞭選擇 Spring 和 hutool 的 StopWatch，Apache commons-lang3 的 StopWatch 也是一個不錯的可選項，更加靈活多變。

StopWatch sw = StopWatch.createStarted();
Thread.sleep(1000);
System.out.printf("耗時：%dms.\n", sw.getTime());

其他兩個都是通過 new 來創建 StopWatch 對象，commons-lang3 還可以通過 createStarted（創建並立即啟動）、create（創建）來完成。

還可以調用 suspend 方法暫停計時、resume 方法恢復計時、reset 重新計時。

// 暫停計時
sw.suspend();
System.out.printf("暫停耗時：%dms.\n", sw.getTime());
// 恢復計時
sw.resume();
System.out.printf("恢復耗時：%dms.\n", sw.getTime());
// 停止計時
sw.stop();
System.out.printf("總耗時：%dms.\n", sw.getTime());
// 重置計時
sw.reset();
// 開始計時
sw.start();
System.out.printf("重置耗時：%dms.\n", sw.getTime());

https://github.com/itwanger/toBeBetterJavaer

以上就是Spring Boot源碼實現StopWatch優雅統計耗時的詳細內容，更多關於Spring Boot StopWatch統計耗時的資料請關註WalkonNet其它相關文章！

推薦閱讀：