查看原文
其他

分享一个统计代码块耗时的小工具

TomGE 微观技术 2022-11-10

相信很多人都遇到这样一个问题?

加班加点,上线了一个功能,但接口的响应时间有点长?

如何定位排查?



通研发人员一般会采用下面方式,在很多位置点埋入开始时间戳、结束时间戳,相减便得到耗时。代码如下:

long start1 = System.currentTimeMillis();
// 模拟业务逻辑处理
Thread.sleep(300);
long end1 = System.currentTimeMillis();

long start2 = System.currentTimeMillis();
// 模拟业务逻辑处理
Thread.sleep(730);
long end2 = System.currentTimeMillis();

System.out.println("执行操作1,耗时:" + (end1 - start1));
System.out.println("执行操作2,耗时:" + (end2 - start2));

虽然书写简单,但导致系统中充斥着大量低级代码,比较烦人,很容易让人怀疑你的技术实力。

我们的直接想法是能不能写个工具类,即统计代码块耗时,还能将分析结果直观展示出来

恰好 Spring框架提供了一个工具类,org.springframework.util.StopWatch,提供了轻量级统计功能,对应的pom文件依赖

<dependency>
    <groupId>org.springframework</groupId>
    <artifactId>spring-core</artifactId>
    <version>5.2.9.RELEASE</version>
</dependency>

StopWatch 源码

省略。。。
public void start(String taskName) throws IllegalStateException {
    if (this.currentTaskName != null) {
        throw new IllegalStateException("Can't start StopWatch: it's already running");
    } else {
        this.currentTaskName = taskName;
        this.startTimeNanos = System.nanoTime();
    }
}

public void stop() throws IllegalStateException {
    if (this.currentTaskName == null) {
        throw new IllegalStateException("Can't stop StopWatch: it's not running");
    } else {
        long lastTime = System.nanoTime() - this.startTimeNanos;
        this.totalTimeNanos += lastTime;
        this.lastTaskInfo = new StopWatch.TaskInfo(this.currentTaskName, lastTime);
        if (this.keepTaskList) {
            this.taskList.add(this.lastTaskInfo);
        }

        ++this.taskCount;
        this.currentTaskName = null;
    }
}

省略。。。

start与stop方法分别记录开始时间与结束时间。

其中在记录结束时间时,会维护一个链表类型的tasklist属性,从而使该类可记录多个任务,最后的输出也仅仅是对之前记录的信息做了一个统一的归纳输出,从而使结果更加直观的展示出来。

prettyPrint方法,可直观的输出代码执行耗时,以及执行时间百分比。

StopWatch 优点

  • Spring框架自带,操作简单,开箱即用
  • 任务start时可以指定name,显示更加友好
  • 数据归纳,展示每项任务耗时与占用总时间的百分比,展示结果直观

缺点:

  • 一个StopWatch不能同时启动多个任务,必须在当前任务stop之后才能开启新的task。若要一次开启多个,需要new一个新的StopWatch实例
  • 代码有侵入性

代码示例:

StopWatch sw = new StopWatch();
sw.start("任务1");
// 模拟业务逻辑处理
Thread.sleep(300);
sw.stop();

sw.start("任务2");
// 模拟业务逻辑处理
Thread.sleep(730);
sw.stop();

System.out.println(sw.prettyPrint());

运行结果:

StopWatch '': running time (millis) = 1033
-----------------------------------------
ms     %     Task name
-----------------------------------------
00303  029%  任务1
00730  071%  任务2

类似工具

除了上面 Spring 提供了工具外,apache下的org.apache.commons.lang.time.StopWatch 和 Guava 下的com.google.common.base.Stopwatch 都提供了类似的工具

大家根据自己的喜好,选择使用。原理大同小异,只是编码风格略有不同。

项目源码地址

https://github.com/aalansehaiyang/spring-boot-bulking  

模块:spring-boot-bulking-tool

最后,阿里巴巴还开源一种系统诊断工具(Arthas),支持在线分析系统瓶颈,并提供了丰富的命令行操作,感兴趣的同学可以体验。


往期推荐



我们热衷于收集高并发、系统架构、微服务、消息中间件、 RPC框架、高性能缓存、搜索、分布式数据框架、分布式协同服务、分布式配置中心、中台架构、领域驱动设计、系统监控、系统稳定性等技术知识。




一线大厂中台架构技术解决方案,资料下载链接,关注 “微观技术”,回复:中台

您可能也对以下帖子感兴趣

文章有问题?点此查看未经处理的缓存