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

一、背景

有時我們在做開發(fā)的時候需要記錄每個任務(wù)執(zhí)行時間，或者記錄一段代碼執(zhí)行時間，最簡單的方法就是打印當(dāng)前時間與執(zhí)行完時間的差值，一般我們檢測某段代碼執(zhí)行的時間，都是以如下方式來進(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("該段總共耗時：" + elapsedTime + "s");}

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

此時會想是否有一個工具類，提供了這些方法，剛好可以滿足這種場景？

我們可以利用已有的工具類中的秒表，常見的秒表工具類

有org.springframework.util.StopWatch、org.apache.commons.lang.time.StopWatch以及谷歌提供的guava中的秒表（這個我沒怎么用過）

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

二、spring 用法

2.1 初遇

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

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

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

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

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

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();
    // 打印出耗時    System.out.println(stopWatch.prettyPrint());    System.out.println(stopWatch.shortSummary());    // stop后它的值為null    System.out.println(stopWatch.currentTaskName()); 
    // 最后一個任務(wù)的相關(guān)信息    System.out.println(stopWatch.getLastTaskName());    System.out.println(stopWatch.getLastTaskInfo());
    // 任務(wù)總的耗時  如果你想獲取到每個任務(wù)詳情（包括它的任務(wù)名、耗時等等）可使用    System.out.println("所有任務(wù)總耗時：" + sw.getTotalTimeMillis());    System.out.println("任務(wù)總數(shù)：" + sw.getTaskCount());    System.out.println("所有任務(wù)詳情：" + sw.getTaskInfo());}

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

2.2 源碼

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

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

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

2.3 注意事項

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

三、apache 用法

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

    org.apache.commons    commons-lang3    3.6

Apache提供的這個任務(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)計從開始到現(xiàn)在運(yùn)行時間：" + watch.getTime() + "ms");
    Thread.sleep(1000);    watch.split();    System.out.println("從start到此刻為止的時間：" + watch.getTime());    System.out.println("從開始到第一個切入點(diǎn)運(yùn)行時間：" + watch.getSplitTime());    Thread.sleep(1000);    watch.split();    System.out.println("從開始到第二個切入點(diǎn)運(yùn)行時間：" + watch.getSplitTime());
    // 復(fù)位后, 重新計時    watch.reset();    watch.start();    Thread.sleep(1000);    System.out.println("重新開始后到當(dāng)前運(yùn)行時間是：" + watch.getTime());
    // 暫停 與 恢復(fù)    watch.suspend();    System.out.println("暫停2秒鐘");    Thread.sleep(2000);
    // 上面suspend，這里要想重新統(tǒng)計，需要恢復(fù)一下    watch.resume();    System.out.println("恢復(fù)后執(zhí)行的時間是：" + watch.getTime());
    Thread.sleep(1000);    watch.stop();
    System.out.println("花費(fèi)的時間》》" + watch.getTime() + "ms");    // 直接轉(zhuǎn)成s    System.out.println("花費(fèi)的時間》》" + watch.getTime(TimeUnit.SECONDS) + "s");}

四、最后

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

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