利用StopWatch監(jiān)控Java代碼運(yùn)行時(shí)間和分析性能

一、背景

有時(shí)我們?cè)谧鲩_(kāi)發(fā)的時(shí)候需要記錄每個(gè)任務(wù)執(zhí)行時(shí)間，或者記錄一段代碼執(zhí)行時(shí)間，最簡(jiǎn)單的方法就是打印當(dāng)前時(shí)間與執(zhí)行完時(shí)間的差值，一般我們檢測(cè)某段代碼執(zhí)行的時(shí)間，都是以如下方式來(lái)進(jìn)行的：

public static void main(String[] args) {  Long startTime = System.currentTimeMillis();  // 你的業(yè)務(wù)代碼  Long endTime = System.currentTimeMillis();  Long elapsedTime = (endTime - startTime) / 1000;  System.out.println("該段總共耗時(shí)：" + elapsedTime + "s");}

事實(shí)上該方法通過(guò)獲取執(zhí)行完成時(shí)間與執(zhí)行開(kāi)始時(shí)間的差值得到程序的執(zhí)行時(shí)間，簡(jiǎn)單直接有效，但想必寫(xiě)多了也是比較煩人的，尤其是碰到不可描述的代碼時(shí)，會(huì)更加的讓人忍不住多寫(xiě)幾個(gè)bug聊表敬意，而且如果想對(duì)執(zhí)行的時(shí)間做進(jìn)一步控制，則需要在程序中很多地方修改。

此時(shí)會(huì)想是否有一個(gè)工具類(lèi)，提供了這些方法，剛好可以滿足這種場(chǎng)景？

我們可以利用已有的工具類(lèi)中的秒表，常見(jiàn)的秒表工具類(lèi)

有org.springframework.util.StopWatch、org.apache.commons.lang.time.StopWatch以及谷歌提供的guava中的秒表（這個(gè)我沒(méi)怎么用過(guò)）

這里重點(diǎn)講下基于spring、Apache的使用

二、spring 用法

2.1 初遇

StopWatch 是位于 org.springframework.util 包下的一個(gè)工具類(lèi)，通過(guò)它可方便的對(duì)程序部分代碼進(jìn)行計(jì)時(shí)(ms級(jí)別)，適用于同步單線程代碼塊。簡(jiǎn)單總結(jié)一句，Spring提供的計(jì)時(shí)器StopWatch對(duì)于秒、毫秒為單位方便計(jì)時(shí)的程序，尤其是單線程、順序執(zhí)行程序的時(shí)間特性的統(tǒng)計(jì)輸出支持比較好。

也就是說(shuō)假如我們手里面有幾個(gè)在順序上前后執(zhí)行的幾個(gè)任務(wù)，而且我們比較關(guān)心幾個(gè)任務(wù)分別執(zhí)行的時(shí)間占用狀況，希望能夠形成一個(gè)不太復(fù)雜的日志輸出，StopWatch提供了這樣的功能。而且Spring的StopWatch基本上也就是僅僅為了這樣的功能而實(shí)現(xiàn)。

想要使用它，首先你需要在你的 Maven 中引入 Spring 核心包，當(dāng)然 Spring MVC 和 Spring Boot 都已經(jīng)自動(dòng)引入了該包：

    org.springframework    spring-core    ${spring.version}

對(duì)一切事物的認(rèn)知，都是從使用開(kāi)始，那就先來(lái)看看它的用法，會(huì)如下所示：

public static void main(String[] args) throws InterruptedException {    StopWatch stopWatch = new StopWatch();
    // 任務(wù)一模擬休眠3秒鐘    stopWatch.start("TaskOneName");    Thread.sleep(1000 * 3);    System.out.println("當(dāng)前任務(wù)名稱：" + stopWatch.currentTaskName());    stopWatch.stop();
    // 任務(wù)一模擬休眠10秒鐘    stopWatch.start("TaskTwoName");    Thread.sleep(1000 * 10);    System.out.println("當(dāng)前任務(wù)名稱：" + stopWatch.currentTaskName());    stopWatch.stop();
    // 任務(wù)一模擬休眠10秒鐘    stopWatch.start("TaskThreeName");    Thread.sleep(1000 * 10);    System.out.println("當(dāng)前任務(wù)名稱：" + stopWatch.currentTaskName());    stopWatch.stop();
    // 打印出耗時(shí)    System.out.println(stopWatch.prettyPrint());    System.out.println(stopWatch.shortSummary());    // stop后它的值為null    System.out.println(stopWatch.currentTaskName()); 
    // 最后一個(gè)任務(wù)的相關(guān)信息    System.out.println(stopWatch.getLastTaskName());    System.out.println(stopWatch.getLastTaskInfo());
    // 任務(wù)總的耗時(shí)  如果你想獲取到每個(gè)任務(wù)詳情（包括它的任務(wù)名、耗時(shí)等等）可使用    System.out.println("所有任務(wù)總耗時(shí)：" + sw.getTotalTimeMillis());    System.out.println("任務(wù)總數(shù)：" + sw.getTaskCount());    System.out.println("所有任務(wù)詳情：" + sw.getTaskInfo());}

如圖所示，StopWatch 不僅正確記錄了上個(gè)任務(wù)的執(zhí)行時(shí)間，并且在最后還可以給出精確的任務(wù)執(zhí)行時(shí)間（納秒級(jí)別）和耗時(shí)占比，這或許就會(huì)比我們自己輸出要優(yōu)雅那么一些。

2.2 源碼

老規(guī)矩，由淺入深?？赐暧梅?，我們來(lái)看看源碼。先看下組成 StopWatch 的屬性

public class StopWatch {    /**  * 本實(shí)例的唯一 Id，用于在日志或控制臺(tái)輸出時(shí)區(qū)分的。  */    private final String id;    /**  * 是否保持一個(gè) taskList 鏈表  * 每次停止計(jì)時(shí)時(shí)，會(huì)將當(dāng)前任務(wù)放入這個(gè)鏈表，用以記錄任務(wù)鏈路和計(jì)時(shí)分析  */ private boolean keepTaskList = true;   /**  * 任務(wù)鏈表  * 用來(lái)存儲(chǔ)每個(gè)task的信息, taskInfo由taskName 和 totoalTime組成  */    private final List taskList;    /**  * 當(dāng)前任務(wù)的開(kāi)始時(shí)間  */    private long startTimeMillis;    /**  *   */    private boolean running;    /**  * 當(dāng)前任務(wù)名稱  */    private String currentTaskName;    /**  * 最后一個(gè)任務(wù)的信息  */    private StopWatch.TaskInfo lastTaskInfo;    /**  * 任務(wù)總數(shù)  */    private int taskCount;    /**  * 程序執(zhí)行時(shí)間  */    private long totalTimeMillis;    ...}

接下來(lái)，我們看一下StopWatch類(lèi)的構(gòu)造器和一些關(guān)鍵方法

2.3 注意事項(xiàng)

• StopWatch對(duì)象不是設(shè)計(jì)為線程安全的，并且不使用同步。
• 一個(gè)StopWatch實(shí)例一次只能開(kāi)啟一個(gè)task，不能同時(shí)start多個(gè)task
• 在該task還沒(méi)stop之前不能start一個(gè)新的task，必須在該task stop之后才能開(kāi)啟新的task
• 若要一次開(kāi)啟多個(gè)，需要new不同的StopWatch實(shí)例

三、apache 用法

StopWath是 apache commons lang3 包下的一個(gè)任務(wù)執(zhí)行時(shí)間監(jiān)視器，與我們平時(shí)常用的秒表的行為比較類(lèi)似，我們先看一下其中的一些重要方法：

    org.apache.commons    commons-lang3    3.6

Apache提供的這個(gè)任務(wù)執(zhí)行監(jiān)視器功能豐富強(qiáng)大，靈活性強(qiáng)，如下經(jīng)典實(shí)用案例：

public static void main(String[] args) throws InterruptedException {    //創(chuàng)建后立即start，常用    StopWatch watch = StopWatch.createStarted();
    // StopWatch watch = new StopWatch();    // watch.start();
    Thread.sleep(1000);    System.out.println(watch.getTime());    System.out.println("統(tǒng)計(jì)從開(kāi)始到現(xiàn)在運(yùn)行時(shí)間：" + watch.getTime() + "ms");
    Thread.sleep(1000);    watch.split();    System.out.println("從start到此刻為止的時(shí)間：" + watch.getTime());    System.out.println("從開(kāi)始到第一個(gè)切入點(diǎn)運(yùn)行時(shí)間：" + watch.getSplitTime());    Thread.sleep(1000);    watch.split();    System.out.println("從開(kāi)始到第二個(gè)切入點(diǎn)運(yùn)行時(shí)間：" + watch.getSplitTime());
    // 復(fù)位后, 重新計(jì)時(shí)    watch.reset();    watch.start();    Thread.sleep(1000);    System.out.println("重新開(kāi)始后到當(dāng)前運(yùn)行時(shí)間是：" + watch.getTime());
    // 暫停 與 恢復(fù)    watch.suspend();    System.out.println("暫停2秒鐘");    Thread.sleep(2000);
    // 上面suspend，這里要想重新統(tǒng)計(jì)，需要恢復(fù)一下    watch.resume();    System.out.println("恢復(fù)后執(zhí)行的時(shí)間是：" + watch.getTime());
    Thread.sleep(1000);    watch.stop();
    System.out.println("花費(fèi)的時(shí)間》》" + watch.getTime() + "ms");    // 直接轉(zhuǎn)成s    System.out.println("花費(fèi)的時(shí)間》》" + watch.getTime(TimeUnit.SECONDS) + "s");}

四、最后

很多時(shí)候，寫(xiě)代碼也是一種藝術(shù)，而借助這種實(shí)用工具我就覺(jué)得藝術(shù)感更強(qiáng)些。希望我們能有追求更加美好事物的心，這點(diǎn)對(duì)于接納新知識(shí)特別重要。

此處推薦這個(gè)監(jiān)視器來(lái)代替之前的的使用，能讓小伙伴們更加靈活的分析你的代碼。