還在用new Date計算任務執行時間？強烈建議使用這個API

在實踐過程中，我們經常需要記錄一個任務執行的耗時，這是評價代碼好壞，評測代碼性能，排查業務執行問題的重要操作。那麼，你是如何來擷取并計算任務執行耗時的呢？通過new Date獲得時間進行換算？還是有更好的方案？本文給你答案。

擷取任務耗時通常做法

擷取任務耗時，最簡單的方式就是列印目前時間與任務開始執行時間的內插補點，執行個體代碼如下：

@Test
	public void testElapsedTimes() throws InterruptedException {
		long startTime = new Date().getTime();

		// do something
		Thread.sleep(1000);

		System.out.println("執行耗時：" + (new Date().getTime() - startTime) + "ms");
	}

複制

上述方式實作簡單，邏輯也比較直覺。但如果執行大量測試，測試中還有不同的代碼邏輯塊，那麼需要改動的地方就比較多。

改進做法

在上述代碼中，如果IDE安裝有代碼檢查工具，則會提示采用System.currentTimeMillis()來擷取時間，而不是new Date().getTime()的方式。

改造之後，實作代碼如下：

@Test
	public void testElapsedTimes1() throws InterruptedException {
		long startTime = System.currentTimeMillis();

		// do something
		Thread.sleep(1000);

		System.out.println("執行耗時：" + (System.currentTimeMillis() - startTime) + "ms");
	}

複制

在這樣的場景下（無需擷取更多Date相關資訊）也推薦使用System.currentTimeMillis()來擷取時間戳。至于為什麼，看一下Date的源碼實作就知道了。

Date的構造方法：

public Date() {
    this(System.currentTimeMillis());
}

複制

Date在構造時，本質上也是先獲得了System.currentTimeMillis()，然後再初始化其他資訊。既然我們隻需要時間戳，那就沒必要再建構Date對象了。從性能層面來說，能優化則優化。

Spring的StopWatch

上述兩種方式雖然性能和寫法有所差別，但本質是一樣的。下面我們來講講Spring提供的StopWatch類，它不僅可實作上述功能，而且還可以做類似任務執行時間控制，也就是封裝了一個對開始時間、結束時間記錄操作的Java類。

先通過StopWatch類來實作一下上述功能：

@Test
	public void testStopWatch() throws InterruptedException {
		StopWatch sw = new StopWatch();

		sw.start("開始執行業務");
		// do something
		Thread.sleep(1000);
		sw.stop();

		System.out.println(sw.getTotalTimeMillis());
	}

複制

通過建立StopWatch對象，然後調用它的start、stop方法來區分執行任務區間，通過getTotalTimeMillis()方法獲得總耗時。

乍一看，代碼好像還比之前的方式多了，展現不出來什麼優勢啊！下面我們再來看一個複雜點的示例：

@Test
	public void testStopWatch1() throws InterruptedException {
		StopWatch sw = new StopWatch();

		sw.start("起床");
		Thread.sleep(1000);
		sw.stop();

		sw.start("洗漱");
		Thread.sleep(2000);
		sw.stop();

		sw.start("鎖門");
		Thread.sleep(500);
		sw.stop();

		System.out.println(sw.prettyPrint());
		System.out.println(sw.getTotalTimeMillis());
		System.out.println(sw.getLastTaskName());
		System.out.println(sw.getLastTaskInfo());
		System.out.println(sw.getTaskCount());
	}

複制

執行上述測試示例，列印結果如下：

StopWatch '': running time = 3509166972 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1003330360  029%  起床
2001421734  057%  洗漱
504414878  014%  鎖門

3509
鎖門
org.springframework.util.StopWatch$TaskInfo@12f40c25
3

複制

此時，看到StopWatch的魅力所在了嗎？

通過多組start、stop方法，将業務代碼塊進行區分，可獲得不同代碼塊的執行耗時；
可以通過start方法傳入taskName，對每個代碼塊進行命名；
可以對總任務耗時、每個任務耗時進行統計分析；
prettyPrint()方法，可以優雅的列印出統計分析資訊；
getTotalTimeMillis()方法，列印出總耗時；
getLastTaskName()方法，列印最後一個任務名稱；
getLastTaskInfo()方法，獲得最後一個任務的TaskInfo，進而獲得更多相關資訊；
getTaskCount()方法，獲得任務數；

現在再看，使用StopWatch是不是可以獲得更多有用的資訊？

StopWatch的實作原理

最後呢，我們再來看一眼源碼，了解一下StopWatch的實作機制。

先看StopWatch的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();
	}

複制

start方法中記錄了任務名稱和任務執行的時間，基于System.nanoTime()獲得。

stop方法實作如下：

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;
	}

複制

在stop方法中，通過兩個時間戳相減獲得lastTime，也就是一個任務的執行時間；lastTime累計相加獲得總的執行時間；同時，記錄任務清單、任務數統計。

而其他get方法，則是對start、stop中擷取的資料的進一步統計、分析、格式化輸出而已。

小結

有些功能當我們使用習慣了，可能就固守于一個實作方式，但如果去參考學習其他架構中類似功能的實作，往往會有些新的突破。如果你在使用Spring的架構，建議你嘗試一下StopWatch這個API，可以讓你的時間統計日志更加高端大氣。

部落客簡介：《SpringBoot技術内幕》技術圖書作者，酷愛鑽研技術，寫技術幹貨文章。