• 如何知道代码跑得多慢?


    分享一下,我自研的一个代码块耗时测算实用工具类。它主要包含以下的功能:

    1. 测算耗时
    2. 显示进度

    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内部的规则如下:

    1. 5秒内不输出两次
    2. 5~10秒,前进至少3%才输出
    3. 10~15秒,前进至少1%才输出
    4. 大于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就是最外层。
    它的每一处实现,都是平淡无奇。借用棋类的话,就是“通盘无妙手”。关键是实用。

  • 相关阅读:
    ActiveMq学习⑦__ActiveMq协议
    git 基础使用(上传,修改上传)
    vue3——使用axios
    国密https访问
    【C语言】预处理详解
    未整理的知识链接
    【高级语言程序设计】python函数式编程(一)
    三大运营商乘风破浪,为什么离不开BAT等互联网企业?
    2022 ECCV 三维人体重建相关论文汇总
    Linux文本处理三剑客(grep,sed,awk)
  • 原文地址:https://www.cnblogs.com/BillySir/p/17419705.html