优化开发效率：耗时分析利器Apache StopWatch

修己xj

发布于 2023-08-25 11:31:07

3520

发布于 2023-08-25 11:31:07

文章被收录于专栏：修己xj

Apache StopWatch是Apache Commons库中的一个组件，它提供了简单而强大的计时器功能。StopWatch可以帮助开发人员精确地计时方法或代码块的执行时间，以便进行性能分析和优化。它提供了计时、暂停、继续、重置等功能，使我们能够更好地监控和控制代码的执行时间。

在这给家人们准备了一些java书籍

与System.currentTimeMillis()打印耗时相比

精确性：StopWatch提供了更高的精确性。当前毫秒数的差是一种简单粗略的计时方式，但它无法提供毫秒级别以下的时间精度。而StopWatch使用更精确的计时机制，可以测量和记录更细小的时间间隔，提供更准确的耗时信息。
可读性：StopWatch提供了更友好的耗时信息。当前毫秒数的差通常以数字形式呈现，难以直观地理解。而StopWatch可以提供更加可读的耗时信息，包括毫秒、秒、分钟等单位，并可以格式化输出，方便开发人员理解和分析。
多段计时：StopWatch支持多段计时。使用当前毫秒数的差只能获取整体耗时，无法区分不同阶段的执行时间。而StopWatch提供了分段计时的功能，可以记录不同阶段的耗时，帮助开发人员更细致地分析任务或方法的执行性能。
功能丰富：StopWatch提供了更多功能和控制选项。除了计时和打印耗时外，StopWatch还支持计时器的暂停、继续、重置等操作。这使得开发人员可以更灵活地控制计时过程，并在需要时进行更精细的时间管理。

Spring Boot与Apache StopWatch的结合应

功能

性能分析：借助Apache StopWatch，我们可以在Spring Boot应用程序中测量和监控关键代码块的执行时间。通过计时器的记录和统计，我们能够发现潜在的性能瓶颈，并针对性地进行优化，提升系统的响应速度和并发处理能力。
接口性能监控：在开发和测试阶段，我们可以使用Apache StopWatch来监控接口的响应时间。通过在接口方法中嵌入计时器，我们可以实时地测量每个接口的执行时间，并记录下来。这有助于我们发现耗时较长的接口，并进行性能调优。
任务调度监控：Spring Boot提供了强大的任务调度功能，可以进行定时任务的管理和执行。结合Apache StopWatch，我们可以在任务方法中嵌入计时器，测量任务的执行时间，并对任务的性能进行监控和优化。
日志记录：使用Apache StopWatch可以在日志中记录关键代码块的执行时间。这对于排查系统问题、定位性能瓶颈非常有帮助。通过将计时器的记录输出到日志中，我们可以在开发和生产环境中追踪和分析代码的执行时间。

依赖

    <dependency>
        <groupId>org.apache.commons</groupId>
        <artifactId>commons-lang3</artifactId>
        <version>3.12.0</version>
    </dependency>

方法说明

start()：启动计时器。在需要开始计时的地方调用此方法，例如在某个任务或方法的起始位置。
stop()：停止计时器。在需要结束计时的地方调用此方法，例如在某个任务或方法的结束位置。
reset()：重置计时器。将计时器的时间重置为0，可以在需要重新计时的地方调用此方法。
split()：记录分段时间。在某个任务或方法的不同阶段调用此方法，可以记录各个阶段的执行时间。
unsplit()：取消最后一次分段时间。如果在某个阶段调用了split()方法，但后续发现该阶段不需要计算执行时间，可以调用此方法进行取消。
suspend()：暂停计时器。可以在需要暂停计时的地方调用此方法，例如在处理某个中断或等待的过程中。
resume()：恢复计时器。在暂停后需要继续计时的地方调用此方法，使计时器继续计算时间。
getTime()：获取经过的总时间（以毫秒为单位）。表示从开始计时到调用getTime()方法时经过的时间。

示例代码

打印耗时：

package cn.xj.common.utils;

import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.time.StopWatch;

import java.util.concurrent.TimeUnit;

@Slf4j
public class Test {
    public static void main(String[] args) throws InterruptedException {
        StopWatch stopWatch = new StopWatch();
        stopWatch.start();
        Thread.sleep(3000);
        stopWatch.stop();
        log.info("方法执行时间：{}毫秒",stopWatch.getTime());
        log.info("方法执行时间：{}秒",stopWatch.getTime(TimeUnit.SECONDS));
    }
}

输出

已连接到目标 VM, 地址: ''127.0.0.1:52888'，传输: '套接字''
21:03:47.430 [main] INFO cn.xj.common.utils.Test - 方法执行时间：3011毫秒
21:03:47.433 [main] INFO cn.xj.common.utils.Test - 方法执行时间：3秒
与目标 VM 断开连接, 地址为: ''127.0.0.1:52888'，传输: '套接字''

进程已结束,退出代码0

暂停和恢复计时器：

package cn.xj.common.utils;

import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.time.StopWatch;

import java.util.concurrent.TimeUnit;

@Slf4j
public class Test {
    public static void main(String[] args) throws InterruptedException {
        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        // 执行业务逻辑，一顿执行猛如虎，一看代码睡3秒
        Thread.sleep(3000);

        stopWatch.suspend(); // 暂停计时器

        // 执行其他操作，暂停期间不计入计时
        Thread.sleep(2000);

        stopWatch.resume(); // 恢复计时器

        // 继续执行操作，让我再睡1秒
        Thread.sleep(1000);

        stopWatch.stop();
        log.info("方法执行时间：{}毫秒",stopWatch.getTime());
        log.info("方法执行时间：{}秒",stopWatch.getTime(TimeUnit.SECONDS));
    }
}

输出

已连接到目标 VM, 地址: ''127.0.0.1:53100'，传输: '套接字''
21:15:38.963 [main] INFO cn.xj.common.utils.Test - 方法执行时间：4017毫秒
21:15:38.967 [main] INFO cn.xj.common.utils.Test - 方法执行时间：4秒
与目标 VM 断开连接, 地址为: ''127.0.0.1:53100'，传输: '套接字''

进程已结束,退出代码0

记录多个分段时间：

package cn.xj.common.utils;

import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.time.StopWatch;

@Slf4j
public class Test {
    public static void main(String[] args) throws InterruptedException {
        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        // 第一段业务逻辑，一顿执行猛如虎，一看代码睡3秒
        Thread.sleep(3000);

        stopWatch.split();
        log.info("第一段耗时：{}毫秒",stopWatch.getSplitTime());

        // 第二段业务逻辑，再睡2秒
        Thread.sleep(2000);
        stopWatch.split();
        log.info("第二段耗时：{}毫秒",stopWatch.getSplitTime());

        // 第三段业务逻辑，这次睡4秒
        Thread.sleep(4000);
        stopWatch.stop();

        log.info("总耗时：{}毫秒",stopWatch.getTime());
    }
}

输出

已连接到目标 VM, 地址: ''127.0.0.1:58391'，传输: '套接字''
21:37:15.972 [main] INFO cn.xj.common.utils.Test - 第一段耗时：3014毫秒
21:37:17.988 [main] INFO cn.xj.common.utils.Test - 第二段耗时：5031毫秒
21:37:22.002 [main] INFO cn.xj.common.utils.Test - 总耗时：9046毫秒
与目标 VM 断开连接, 地址为: ''127.0.0.1:58391'，传输: '套接字''

进程已结束,退出代码0

重置计时器：

package cn.xj.common.utils;

import lombok.extern.slf4j.Slf4j;
import org.apache.commons.lang3.time.StopWatch;

import java.util.concurrent.TimeUnit;

@Slf4j
public class Test {
    public static void main(String[] args) throws InterruptedException {
        StopWatch stopWatch = new StopWatch();
        stopWatch.start();

        // 执行业务逻辑1，一顿执行猛如虎，一看代码睡3秒
        Thread.sleep(3000);
        stopWatch.stop();

        log.info("方法1执行时间：{}毫秒",stopWatch.getTime());
        log.info("方法1执行时间：{}秒",stopWatch.getTime(TimeUnit.SECONDS));

        stopWatch.reset(); // 重置计时器

        stopWatch.start();

        // 执行其他业务逻辑2，扶我躺下，我还能睡2秒
        Thread.sleep(2000);

        stopWatch.stop();

        log.info("方法2执行时间：{}毫秒",stopWatch.getTime());
        log.info("方法2执行时间：{}秒",stopWatch.getTime(TimeUnit.SECONDS));
    }
}

输出

已连接到目标 VM, 地址: ''127.0.0.1:58622'，传输: '套接字''
21:48:25.252 [main] INFO cn.xj.common.utils.Test - 方法1执行时间：3005毫秒
21:48:25.255 [main] INFO cn.xj.common.utils.Test - 方法1执行时间：3秒
21:48:27.263 [main] INFO cn.xj.common.utils.Test - 方法2执行时间：2007毫秒
21:48:27.263 [main] INFO cn.xj.common.utils.Test - 方法2执行时间：2秒
与目标 VM 断开连接, 地址为: ''127.0.0.1:58622'，传输: '套接字''

进程已结束,退出代码0

本文参与腾讯云自媒体同步曝光计划，分享自微信公众号。

原始发表：2023-06-30，如有侵权请联系 cloudcommunity@tencent.com 删除

apache