Apache和Spring提供的StopWatch執行時間監視器

相關閱讀

【小家java】java5新特性(簡述十大新特性) 重要一躍
【小家java】java6新特性(簡述十大新特性) 雞肋升級
【小家java】java7新特性(簡述八大新特性) 不溫不火
【小家java】java8新特性(簡述十大新特性) 飽受讚譽
【小家java】java9新特性(簡述十大新特性) 褒貶不一
【小家java】java10新特性(簡述十大新特性) 小步迭代
【小家java】java11新特性(簡述八大新特性) 首個重磅LTS版本java


前言

編碼過程當中咱們常常會但願獲得一段代碼(一個方法)的執行時間,本文將介紹兩種時間監視器(秒錶)來讓你優雅的、靈活的處理這個問題。spring

Java源生方式

這種方式最最簡單,最好理解,固然也是最爲經常使用:咱們本身書寫。
例如:咱們若是要統計一段代碼的執行時間,常常會這麼來寫:架構

public static void main(String[] args) {
        long startTime = System.currentTimeMillis();   //獲取開始時間

        //函數主體代碼
        //...

        long endTime = System.currentTimeMillis(); //獲取結束時間
        System.out.println("程序運行時間: " + (endTime - startTime) + "ms");
    }

大多數時候咱們使用ms來表示便可,可是這麼寫缺少靈活性。假若咱們要展現成納秒、秒、甚至分鐘,還得咱們本身處理(把毫秒值拿來進行轉換~ )框架

固然可能到了JDK8之後,咱們這麼作能變得稍微靈活一些:能夠這麼處理:dom

public static void main(String[] args) {
        Instant start = Instant.now();
        //doSomething();
        Instant end = Instant.now();

        Duration duration = Duration.between(start, end);
        System.out.println("millis = " + duration.toMillis());
    }

這個比上面靈活度強一些。但也仍是有必定的缺點:步驟稍顯複雜,整體上仍是不夠優雅,也不是那麼的靈活。
那麼本文針對此問題介紹一個工具:StopWatch執行時間監視器。藉助它來統計咱們程序的執行時間,帶給很是多的方便和優雅。函數

StopWatch須要依賴額外的Jar: commons-lang3或者 spring-core,但因這兩個Jar是Java開發中都必導的,所以依賴兼容性方面能夠忽略

StopWatch有不少開源的框架都有提供相似的功能:好比Apache的commons-lang3,固然還有Spring framwork本身提供的,本文將針對此倆分別作介紹~工具

Commons-lang3的StopWatch

Apache提供的這個任務執行監視器功能豐富強大(比Spring的強大),靈活性強,以下經典實用案例:this

public static void main(String[] args) throws Exception {
        StopWatch watch = StopWatch.createStarted(); //建立後當即start,經常使用
        //StopWatch watch = new StopWatch();
        //watch.start();

        Thread.sleep(1000);
        System.out.println("統計從開始到如今運行時間:" + watch.getTime() + "ms"); //1000ms

        Thread.sleep(1000);
        watch.split();
        System.out.println("從start到此刻爲止的時間:" + watch.getTime());
        System.out.println("從開始到第一個切入點運行時間:" + watch.getSplitTime()); //2245

        Thread.sleep(1000);
        watch.split();
        System.out.println("從開始到第二個切入點運行時間:" + watch.getSplitTime());

        watch.reset(); //重置後必須使用start方法
        watch.start();
        Thread.sleep(1000);
        System.out.println("從新開始後到當前運行時間是:" + watch.getTime()); //1000

        watch.suspend(); //暫停
        Thread.sleep(6000); //模擬暫停6秒鐘

        watch.resume(); //上面suspend,這裏要想從新統計,須要恢復一下
        System.out.println("恢復後執行的時間是:" + watch.getTime()); //1000  注意此時這個值仍是1000

        watch.stop();
        System.out.println("花費的時間》》" + watch.getTime() + "ms"); //1002ms
        System.out.println("花費的時間》》" + watch.getTime(TimeUnit.SECONDS) + "s"); //1s 能夠直接轉成s

    }

打印結果:編碼

統計從開始到如今運行時間:1007ms
從start到此刻爲止的時間:2008
從開始到第一個切入點運行時間:2008
從開始到第二個切入點運行時間:3009
從新開始後到當前運行時間是:1000
恢復後執行的時間是:1000
花費的時間》》1001ms
花費的時間》》1s

如上就是StopWatch的基本使用方法,足以見到了它的強大吧,固然使用起來複雜度也是提高了些的。.net

核心原理解釋

原理相對簡單,簡單看看源碼便知:

// @since 2.0
public class StopWatch {
    // @since 3.5  這個靜態方法出現得稍微晚點哦~
    public static StopWatch createStarted() {
        final StopWatch sw = new StopWatch();
        sw.start();
        return sw;
    }

    // 這些成員變量是實現的核心~~~~~~~~~~~~~~
    private State runningState = State.UNSTARTED;
    private SplitState splitState = SplitState.UNSPLIT;
    private long startTime;
    // 思考:爲什麼有了nonaTime這裏還得記錄一個Millis Time呢???
    // 由於nanoTime只能拿來計算差值(耗時) 可是getStartTime()這個老API還得靠MillsTime~~~
    private long startTimeMillis;
    private long stopTime;
    
    // 可見:start方法可不是可以屢次調用的哦~~和狀態是有關的
    public void start() {
        if (this.runningState == State.STOPPED) {
            throw new IllegalStateException("Stopwatch must be reset before being restarted. ");
        }
        if (this.runningState != State.UNSTARTED) {
            throw new IllegalStateException("Stopwatch already started. ");
        }
        this.startTime = System.nanoTime();
        this.startTimeMillis = System.currentTimeMillis();
        this.runningState = State.RUNNING;
    }

    // 停表時,最重要的是記錄下了stopTime 的值~~~而後標記狀態
    public void stop() {
        if (this.runningState != State.RUNNING && this.runningState != State.SUSPENDED) {
            throw new IllegalStateException("Stopwatch is not running. ");
        }
        if (this.runningState == State.RUNNING) {
            this.stopTime = System.nanoTime();
        }
        this.runningState = State.STOPPED;
    }

    // 狀態變爲非開始狀態...
    public void reset() {
        this.runningState = State.UNSTARTED;
        this.splitState = SplitState.UNSPLIT;
    }

    // 暫停:stopTime 也給了一個值
    public void suspend() {
        if (this.runningState != State.RUNNING) {
            throw new IllegalStateException("Stopwatch must be running to suspend. ");
        }
        this.stopTime = System.nanoTime();
        this.runningState = State.SUSPENDED;
    }

    // 這兩個方法是獲取差值的
    public long getTime() {
        return getNanoTime() / NANO_2_MILLIS;
    }
    // @since 3.5
    public long getTime(final TimeUnit timeUnit) {
        return timeUnit.convert(getNanoTime(), TimeUnit.NANOSECONDS);
    }

    // @since 2.4 老API  這叫獲取啓動的時間(啥時候啓動的)
    public long getStartTime() {
        if (this.runningState == State.UNSTARTED) {
            throw new IllegalStateException("Stopwatch has not been started");
        }
        // System.nanoTime is for elapsed time
        return this.startTimeMillis;
    }
}

能夠看到原理是很簡單的,無非就是包裝了暫停、回覆、split等功能嘛

使用細節

==getTimegetSplitTime有啥區別呢?==
爲了說明問題,此處咱們看看getNanoTime()getSplitNanoTime()亦可:

public long getNanoTime() {
        if (this.runningState == State.STOPPED || this.runningState == State.SUSPENDED) {
            return this.stopTime - this.startTime;
        } else if (this.runningState == State.UNSTARTED) {
            return 0;
        } else if (this.runningState == State.RUNNING) {
            return System.nanoTime() - this.startTime;
        }
        throw new RuntimeException("Illegal running state has occurred.");
    }

     public long getSplitNanoTime() {
        if (this.splitState != SplitState.SPLIT) {
            throw new IllegalStateException("Stopwatch must be split to get the split time. ");
        }
        return this.stopTime - this.startTime;
    }

咱們發現:

  • 調用getSplit...相關方法前,必須先調用Split方法

spilit()方法源碼以下:

public void split() {
        if (this.runningState != State.RUNNING) {
            throw new IllegalStateException("Stopwatch is not running. ");
        }
        this.stopTime = System.nanoTime();
        this.splitState = SplitState.SPLIT;
    }

在調用split方法後,watch的狀態改成了SPLIT且,且,且stopTime 設置爲了當前時間。所以此處咱們的stopTime中止了,這個時候調用getSplitNanoTime(),返回的是start到split那時的時間差值。所以用此方法能夠插入先中止stopTime()(有點插隊的趕腳),最後再輸出(先插好隊,最後在輸出)~

getTime()就是拿當前的時間戳,減去startTime,通常不涉及到stopTime的值,所以splitTime處理計算時間顯然更加的靈活,可是,通常咱們使用getTime()就足夠了

Spring的StopWatch

Spring提供的這個任務監視器,我仍是蠻喜歡使用的,由於一個它可以幫我同事監控多個任務,使用起來也很方便。先看一個簡單的使用案例:

注意:一個監視器可以記錄多個任務的執行時間這個特色很是重要哦~
好比:咱們能夠記錄 多段代碼耗時時間,而後一次性打印~
public static void main(String[] args) throws Exception {
        // 強烈每個秒錶都給一個id,這樣查看日誌起來可以更加的精確
        // 至於Id 我以爲給UUID是可行的~
        StopWatch sw = new StopWatch(UUID.randomUUID().toString());

        sw.start("起牀");
        Thread.sleep(1000);
        System.out.println("當前任務名稱:" + sw.currentTaskName());
        sw.stop();

        sw.start("洗漱");
        Thread.sleep(2000);
        System.out.println("當前任務名稱:" + sw.currentTaskName());
        sw.stop();

        sw.start("鎖門");
        Thread.sleep(500);
        System.out.println("當前任務名稱:" + sw.currentTaskName());
        sw.stop();

        System.out.println(sw.prettyPrint()); // 這個方法打印在咱們記錄日誌時是很是友好的  還有百分比的分析哦
        System.out.println(sw.shortSummary());
        System.out.println(sw.currentTaskName()); // stop後它的值爲null


        // 最後一個任務的相關信息
        System.out.println(sw.getLastTaskName());
        System.out.println(sw.getLastTaskInfo());

        // 任務總的耗時  若是你想獲取到每一個任務詳情(包括它的任務名、耗時等等)可以使用
        System.out.println("全部任務總耗時:" + sw.getTotalTimeMillis());
        System.out.println("任務總數:" + sw.getTaskCount());
        System.out.println("全部任務詳情:" + sw.getTaskInfo()); // 拿到全部的任務
    }

打印:

當前任務名稱:起牀
當前任務名稱:洗漱
當前任務名稱:鎖門
StopWatch 'd6ba9412-d551-4ba7-8b0e-1b7ccb42855d': running time (millis) = 3504
-----------------------------------------
ms     %     Task name
-----------------------------------------
01001  029%  起牀
02000  057%  洗漱
00503  014%  鎖門

StopWatch 'd6ba9412-d551-4ba7-8b0e-1b7ccb42855d': running time (millis) = 3504
null
鎖門
org.springframework.util.StopWatch$TaskInfo@2d554825
全部任務總耗時:3504
任務總數:3
全部任務詳情:[Lorg.springframework.util.StopWatch$TaskInfo;@68837a77

我我的偏心使用Spring提供的這個監視器,是由於它提供的prettyPrint()打印在日誌裏進行分析能夠很是的直觀,而且我以爲提供的多任務支持也更加實用一點,固然僅僅我的偏好而已~

最後

不少時候,寫代碼也是一種藝術,而藉助這種實用工具我就以爲藝術感更強些。但願咱們能有追求更加美好事物的心,這點對於接納新知識特別重要。此處推薦這個監視器來代替以前的的使用,能讓小夥伴們更加靈活的分析你的代碼~

知識交流

若文章格式混亂,可點擊原文連接-原文連接-原文連接-原文連接-原文連接

==The last:若是以爲本文對你有幫助,不妨點個讚唄。固然分享到你的朋友圈讓更多小夥伴看到也是被做者本人許可的~==

**若對技術內容感興趣能夠加入wx羣交流:Java高工、架構師3羣
若羣二維碼失效,請加wx號:fsx641385712(或者掃描下方wx二維碼)。而且備註:"java入羣" 字樣,會手動邀請入羣**

相關文章
相關標籤/搜索