Java实现代码块耗时测算工具类

1. 测算耗时

背景

程序员经常需要知道一段代码的执行耗时。典型的例如查询数据库，不同参数查询到不同的数据量，耗时相差很大。如果一个操作总体耗时较大，包含了几次数据库操作，自然就想知道哪一次操作是长耗时的主要原因，甚至每一个的耗时是多少。从而可以有的放矢地做优化。

使用要简单

测算一段代码的耗时，通常就是用stop watch（秒表）。在执行的开始点开始计时，在执行的结束点停止计时，并把耗时输出到日志。虽然代码也就几行，但每个地方都这么写，会显得很啰嗦，编码效率也低。

所以我把这个功能封装成一个实用工具类。用起来大概是这样子:

MonitorUtil.time(() -> {
    // 一个耗时操作，如查询数据库
}, "给这个操作起个名");

它会这样输出到日志：

[WARN] 2023-05-19T08:26:00.007 xx-project com.xxx.util.MonitorUtil 给这个操作起个名 elapsed 3,140 ms. warning

末尾的warning会在某些终端上显示为黄色，显眼。

输出要简洁

在线上运行时，也希望能知道耗时比较大的代码。但如果每处测算耗时的地方都输出日志，日志就会太多，而我们只关注那些长耗时。所以我规定：少于500毫秒的，不输出。

暂停与继续

有一种场景，在一个代码范围内，只期望计算一部分操作的累计耗时，而忽略其它操作的耗时。

比如，处理一批文件，每个文件要解析后将结果存为另一个文件。这里只关心解析的时间，而忽略写文件的耗时。所以MonitorUtil提供了暂停和继续的功能。在写文件时，暂停计时，写文件后开始解析另一个文件时继续计时。

最终会输出累计的耗时以及累计等待耗时。累计等待耗时，即是从暂停到继续的时长的总和。

代码：

MonitorUtil.time(monitor -> {
    for (...) {
        // 文件解析
        monitor.pause();
        // 其它操作
        monitor.continue();
    }
}, "仅算文件解析");

输出如下：

[WARN] 2023-05-19T08:26:00.008 xx-project com.xxx.util.MonitorUtil 仅算文件解析 elapsed 1,140 ms，waited 2,000ms. warning
这样就能知道那段代码是工作的时间多还是等待的时间多了。

2. 显示进度

说另一个问题，也是跟时间有关的。有些功能耗时比较长，比如循环处理数据。或许是10秒，或许是10分钟。对着没有什么输出的屏幕，显得很无助。此时如果能知道剩下大概需要多少时间，无疑对做决策有大帮助。如，是中断还是继续等。

当然了，进度百分比，只有业务代码才知道。但业务代码难以把握如何输出这个进度。密了则输出一大堆，干扰视线。疏了又是漫长无助的等待。所以，是由业务代码报告进度，由这个工具决定要不要输出。

代码：

MonitorUtil.time(monitor -> {
    for (...) {
        // 一些操作
        monitor.process(proc);     // proc 是[0,1]区间的浮点数，表示进度
    }
}, "给这个操作起个名");

要做到输出不能太密，不能太疏。所以MonitorUtil内部的规则如下：

• 5秒内不输出两次
• 5~10秒，前进至少3%才输出
• 10~15秒，前进至少1%才输出
• 大于15秒，无论进度如何都输出

这里说的多少秒，是相对于上一次输出的时间而言。前进也是相对于上一次输出。

输出：

[INFO] 2023-05-19T08:26:00.009 xx-project com.xxx.util.MonitorUtil 给这个操作起个名 7% 30% 61% 98% 100%`

嵌套使用

假如有两个进度测试的代码嵌套在一起，如

MonitorUtil.time(monitor -> {
    for (...) {
        // 一些操作
        abc();
        // 一些操作
        monitor.process(proc);     // proc 是[0,1]区间的浮点数，表示进度
    }
}, "大功能名");

void abc() {
    MonitorUtil.time(monitor -> {
        for (...) {
            // 一些操作
            monitor.process(proc);     // proc 是[0,1]区间的浮点数，表示进度
        }
    }, "小功能名");
}

由于日志只有一份，两个进度的输出就会混在一起，很乱，看不清。所以解决这个问题，我规定当发生进度测算嵌套时，只有最外层的有效，即只有最外层的会输出。好像也没有更好的办法了，如果您有更好的建议，请留言。感谢。

3. 这个工具的优势

高性能

• 它的输出都是被动的。即只在被测代码开始、结束、主动调用process方法时，才执行逻辑，才有可能输出。如果process方法没有被调用，就算过了15秒，也不会有进度输出。所以，在应用的时候，可以偏频繁一些地调用process方法。调了不一定有输出，不调一定不会输出。
• 它的内部是顺序的判断，没有循环，更没有复杂算法，非常高效。
• 它并没有创建新的线程(单线程)，而是与业务代码工作在同一个线程。它消耗的资源非常少，包括内存消耗很少。在除了“开始、结束、process方法被调用时”之外，消耗的CPU为零。用它来测算时间，成本极低，可以大量使用。

支持异常

业务代码发生异常时，它还能不能测算出耗时？可以的。回调方法（lambda表达式）如果发生的异常，它也能计算耗时，并在耗时超过500毫秒时输出。异常也是结束的一种。

测算的目标形式

如前面所见，它测算的目标形式是代码块，而代码块是最灵活的表现形式。它可以是一行代码，可以是多行。可以是一个函数的完整代码，也可以是函数的一部分代码。

4. 实现原理简介

它的内部实现原理并不难。测算时间，就是记录(用变量保存)开始时间，并在结束时计算一下时间差。进度功能，则是记录上一次的输出时间和进度，下次输出时作对比。暂停功能，则是用两个变量分别记录工作和等待的耗时累加值。至于如何知道自己是不是“最外层”，则是用一个static变量来保存当前的层数。如果是0就是最外层。

它的每一处实现，都是平淡无奇。借用棋类的话，就是“通盘无妙手”。关键是实用。

到此这篇关于Java实现代码块耗时测算工具类的文章就介绍到这了,更多相关Java代码耗时内容请搜索脚本之家以前的文章或继续浏览下面的相关文章希望大家以后多多支持脚本之家！

最新评论