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入群" 字样,会手动邀请入群**

相关文章
相关标签/搜索