StopWatch：被忽视的任务执行时间监视器

2023-10-13 00:38
文章标签 时间 执行 任务 stopwatch 被忽视 监视器

本文主要是介绍StopWatch：被忽视的任务执行时间监视器，希望对大家解决编程问题提供一定的参考价值，需要的开发者们随着小编来一起学习吧！

背景引入

学习源码的过程中，在springboot启动类的run方法里，看到这样一个对象，遂对其学习了一番。
在这里插入图片描述
在这里插入图片描述

简介

StopWatch是位于org.springframework.util包下的一个工具类，通过它可方便的对程序部分代码进行计时(ms级别)，适用于同步单线程代码块。用于代码性能监控，不用于实际业务。

允许多个任务的计时，暴露每个命名任务的总运行时间和运行时间。隐藏使用System.currentTimeMillis（），提高应用程序代码的可读性并减少计算错误的可能性。

源码学习

附上中文注释的源码

package org.springframework.util;import java.text.NumberFormat;
import java.util.LinkedList;
import java.util.List;
import java.util.concurrent.TimeUnit;import org.springframework.lang.Nullable;/*** 简单的秒表，允许对多个任务进行计时，公开总运行时间和每个命名任务的运行时间。* 隐藏 System.nanoTime()的使用，提高了应用程序代码的可读性，并减少了计算错误的可能性。* 请注意，此对象并非设计为线程安全的，并且不使用同步。* 此类通常用于在概念验证工作和开发过程中验证性能，而不是作为生产应用程序的一部分。* 从Spring Framework 5.2开始，以纳秒为单位跟踪和报告运行时间。*/
public class StopWatch {/*** 此秒表的标识符。* 当我们有多个秒表的输出并且需要在日志或控制台输出中进行区分时，此功能非常方便。*/private final String id;private boolean keepTaskList = true;private final List<TaskInfo> taskList = new LinkedList<>();/** 当前任务的开始时间。 */private long startTimeNanos;/** 当前任务的名称。 */@Nullableprivate String currentTaskName;@Nullableprivate TaskInfo lastTaskInfo;private int taskCount;/** 总运行时间。 */private long totalTimeNanos;/*** 构造一个新的秒表。* 不启动任何任务*/public StopWatch() {this("");}/*** 使用给定的ID构造一个新的StopWatch。* 当我们从多个秒表中输出并且需要区分它们时，该ID十分方便。* 不启动任何任务。*/public StopWatch(String id) {this.id = id;}/***获取此秒表的ID，该ID在构造时已指定。* 返回值：ID（默认为空字符串）*/public String getId() {return this.id;}/*** 配置StopWatch.TaskInfo数组是否随着时间的推移而构建。* 使用秒表进行数百万个间隔时，将其设置为false；否则，TaskInfo结构将消耗过多的内存。* 默认为true。*/public void setKeepTaskList(boolean keepTaskList) {this.keepTaskList = keepTaskList;}/*** 启动一个未命名的任务。* 如果在没有先调用该方法的情况下调用stop（）或计时方法，则结果是不确定的*/public void start() throws IllegalStateException {start("");}/*** 启动一个命名的任务。* 如果在没有先调用该方法的情况下调用stop（）或计时方法，则结果是不确定的*/public void start(String taskName) throws IllegalStateException {if (this.currentTaskName != null) {throw new IllegalStateException("Can't start StopWatch: it's already running");}this.currentTaskName = taskName;this.startTimeNanos = System.nanoTime();}/*** 停止当前任务。* 如果在不调用至少一对start()/ stop()方法的情况下调用计时方法，则结果是不确定的。*/public void stop() throws IllegalStateException {if (this.currentTaskName == null) {throw new IllegalStateException("Can't stop StopWatch: it's not running");}long lastTime = System.nanoTime() - this.startTimeNanos;this.totalTimeNanos += lastTime;this.lastTaskInfo = new TaskInfo(this.currentTaskName, lastTime);if (this.keepTaskList) {this.taskList.add(this.lastTaskInfo);}++this.taskCount;this.currentTaskName = null;}/*** 确定此秒表当前是否正在运行。*/public boolean isRunning() {return (this.currentTaskName != null);}/*** 获取当前正在运行的任务的名称（如果有）。*/@Nullablepublic String currentTaskName() {return this.currentTaskName;}/*** 获取上一个任务花费的时间（以纳秒为单位）。*/public long getLastTaskTimeNanos() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task interval");}return this.lastTaskInfo.getTimeNanos();}/*** 获取上一个任务花费的时间（以毫秒为单位）。*/public long getLastTaskTimeMillis() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task interval");}return this.lastTaskInfo.getTimeMillis();}/*** 获取上一个任务的名称。*/public String getLastTaskName() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task name");}return this.lastTaskInfo.getTaskName();}/*** 获取最后一个任务作为StopWatch.TaskInfo对象。*/public TaskInfo getLastTaskInfo() throws IllegalStateException {if (this.lastTaskInfo == null) {throw new IllegalStateException("No tasks run: can't get last task info");}return this.lastTaskInfo;}/*** 获取所有任务的总时间（以纳秒为单位）。*/public long getTotalTimeNanos() {return this.totalTimeNanos;}/*** 获取所有任务的总时间（以毫秒为单位）。*/public long getTotalTimeMillis() {return nanosToMillis(this.totalTimeNanos);}/*** 获取所有任务的总时间（以秒为单位）。*/public double getTotalTimeSeconds() {return nanosToSeconds(this.totalTimeNanos);}/*** 获取计时的任务数。*/public int getTaskCount() {return this.taskCount;}/*** 获取执行的任务的数据数组。*/public TaskInfo[] getTaskInfo() {if (!this.keepTaskList) {throw new UnsupportedOperationException("Task info is not being kept!");}return this.taskList.toArray(new TaskInfo[0]);}/*** 获得总运行时间的简短描述。*/public String shortSummary() {return "StopWatch '" + getId() + "': running time = " + getTotalTimeNanos() + " ns";}/*** 生成带有描述所有已执行任务的表的字符串。* 对于自定义报告，请调用getTaskInfo()并直接使用任务信息。*/public String prettyPrint() {StringBuilder sb = new StringBuilder(shortSummary());sb.append('\n');if (!this.keepTaskList) {sb.append("No task info kept");}else {sb.append("---------------------------------------------\n");sb.append("ns         %     Task name\n");sb.append("---------------------------------------------\n");NumberFormat nf = NumberFormat.getNumberInstance();nf.setMinimumIntegerDigits(9);nf.setGroupingUsed(false);NumberFormat pf = NumberFormat.getPercentInstance();pf.setMinimumIntegerDigits(3);pf.setGroupingUsed(false);for (TaskInfo task : getTaskInfo()) {sb.append(nf.format(task.getTimeNanos())).append("  ");sb.append(pf.format((double) task.getTimeNanos() / getTotalTimeNanos())).append("  ");sb.append(task.getTaskName()).append("\n");}}return sb.toString();}/*** 生成描述所有已执行任务的信息字符串* 对于自定义报告，请调用getTaskInfo（）并直接使用任务信息。*/@Overridepublic String toString() {StringBuilder sb = new StringBuilder(shortSummary());if (this.keepTaskList) {for (TaskInfo task : getTaskInfo()) {sb.append("; [").append(task.getTaskName()).append("] took ").append(task.getTimeNanos()).append(" ns");long percent = Math.round(100.0 * task.getTimeNanos() / getTotalTimeNanos());sb.append(" = ").append(percent).append("%");}}else {sb.append("; no task info kept");}return sb.toString();}private static long nanosToMillis(long duration) {return TimeUnit.NANOSECONDS.toMillis(duration);}private static double nanosToSeconds(long duration) {return duration / 1_000_000_000.0;}/*** 嵌套类，用于保存有关StopWatch中执行的一项任务的数据。*/public static final class TaskInfo {private final String taskName;private final long timeNanos;TaskInfo(String taskName, long timeNanos) {this.taskName = taskName;this.timeNanos = timeNanos;}/*** 获取此任务的名称。*/public String getTaskName() {return this.taskName;}/*** 获取此任务花费的时间（以纳秒为单位）。*/public long getTimeNanos() {return this.timeNanos;}/*** 获取此任务花费的时间（以毫秒为单位）。*/public long getTimeMillis() {return nanosToMillis(this.timeNanos);}/*** 获取此任务花费的时间（以秒为单位）。*/public double getTimeSeconds() {return nanosToSeconds(this.timeNanos);}}}

通过对该工具类源码的学习，我们可以通过调用该StopWatch的start()和stop()方法来分别记录被执行任务的开始时间和结束时间，在记录结束的时候，会维护一个链表类型的taskList属性，从而使该类能够记录多个任务，调用prettyPrint()方法可使最后的输出也可以对之前的记录的信息整理后统一输出，使多任务的计时结果更加直观。此外调用shortSummary()和getTotalTimeMillis()，可以查看程序执行时间。

代码演练

 /**不指定任务名*/
private static void test1() throws InterruptedException {StopWatch sw = new StopWatch();sw.start();//执行任务 do somethingThread.sleep(1000);sw.stop();System.out.println(sw.prettyPrint());
}输出：
StopWatch '': running time = 999802159 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
999802159  100% 

/**指定任务名*/
private static void test2() throws InterruptedException {StopWatch sw = new StopWatch("测试任务");sw.start("任务-01");//执行任务 do somethingThread.sleep(1000);sw.stop();System.out.println(sw.prettyPrint());
}输出：
StopWatch '测试任务': running time = 1000332330 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1000332330  100%  任务-01

/**多任务执行计时*/
private static void test3() throws InterruptedException {StopWatch sw = new StopWatch("测试任务");sw.start("任务-01");//执行任务01-do somethingThread.sleep(1000);sw.stop();sw.start("任务-02");//执行任务02-do somethingThread.sleep(500);sw.stop();System.out.println(sw.prettyPrint());
}输出：
StopWatch '测试任务': running time = 1500807290 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1000139444  067%  任务-01
500667846  033%  任务-02

/** 工具类方法演示 */
private static void test4() throws InterruptedException {StopWatch sw = new StopWatch("测试任务");sw.start("任务-01");//执行任务01-do somethingThread.sleep(1000);sw.stop();sw.start("任务-02");//执行任务02-do something//获取当前任务名System.out.println("**************** currentTaskName() ****************");System.out.println(sw.currentTaskName());Thread.sleep(500);sw.stop();//获取简单说明的任务总时间System.out.println("**************** shortSummary() ****************");System.out.println(sw.shortSummary());//获取任务总时间System.out.println("**************** getTotalTimeMillis() ****************");System.out.println(sw.getTotalTimeMillis());//获取美化任务时间明细System.out.println("**************** prettyPrint() ****************");System.out.println(sw.prettyPrint());//获取任务信息System.out.println("**************** getTaskInfo() ****************");StopWatch.TaskInfo[] taskInfo = sw.getTaskInfo();Arrays.stream(taskInfo).forEach(task -> System.out.println("TaskName: "+task.getTaskName() +", TimeSeconds: " + task.getTimeSeconds() +", TimeMillis: " + task.getTimeMillis() +", TimeNanos: " + task.getTimeNanos()));
}输出：
**************** currentTaskName() ****************
任务-02
**************** shortSummary() ****************
StopWatch '测试任务': running time = 1500632807 ns
**************** getTotalTimeMillis() ****************
1500
**************** prettyPrint() ****************
StopWatch '测试任务': running time = 1500632807 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
999926384  067%  任务-01
500706423  033%  任务-02**************** getTaskInfo() ****************
TaskName: 任务-01, TimeSeconds: 0.999926384, TimeMillis: 999, TimeNanos: 999926384
TaskName: 任务-02, TimeSeconds: 0.500706423, TimeMillis: 500, TimeNanos: 500706423

归纳总结

StopWatch优缺点：

优点：

  1. spring自带工具类，可直接使用
  2. 代码实现简单，使用更简单
  3. 统一归纳，展示每项任务耗时与占用总时间的百分比，展示结果直观
    性能消耗相对较小，并且最大程度的保证了start与stop之间的时间记录的准确性
  4. 可在start时直接指定任务名字，从而更加直观的显示记录结果

缺点：

  1. 一个StopWatch实例一次只能开启一个task，不能同时start多个task，并且在该task未stop之前不能start一个新的task，必须在该task stop之后才能开启新的task，若要一次开启多个，需要new不同的StopWatch实例
  2. 代码侵入式使用，需要改动多处代码

实战应用

使用StopWatch记录请求摘要日志信息

@Slf4j
public class PerformanceInteceptor implements HandlerInterceptor {private ThreadLocal<StopWatch> stopWatchThreadLocal = new ThreadLocal<>();@Overridepublic boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {StopWatch sw = new StopWatch();stopWatchThreadLocal.set(sw);sw.start();return true;}@Overridepublic void postHandle(HttpServletRequest request, HttpServletResponse response, Object handler, ModelAndView modelAndView) throws Exception {stopWatchThreadLocal.get().stop();stopWatchThreadLocal.get().start();}@Overridepublic void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {StopWatch sw = stopWatchThreadLocal.get();sw.stop();String method = handler.getClass().getSimpleName();if (handler instanceof HandlerMethod) {String beanType = ((HandlerMethod) handler).getBeanType().getName();String methodName = ((HandlerMethod) handler).getMethod().getName();method = beanType + "." + methodName;}// sw.getTotalTimeMillis(), 总执行时间//sw.getTotalTimeMillis() - sw.getLastTaskTimeMillis(), 执行方法体所需要的时间log.info("{};{};{};{};{}ms;{}ms;{}ms", request.getRequestURI(), method,response.getStatus(), ex == null ? "-" : ex.getClass().getSimpleName(),sw.getTotalTimeMillis(), sw.getTotalTimeMillis() - sw.getLastTaskTimeMillis(),sw.getLastTaskTimeMillis());stopWatchThreadLocal.remove();}
}

这篇关于StopWatch：被忽视的任务执行时间监视器的文章就介绍到这儿，希望我们推荐的文章对编程师们有所帮助！


http://www.chinasem.cn/article/199534。

相关文章

JavaScript中的reduce方法执行过程、使用场景及进阶用法

JavaScript中的reduce方法执行过程、使用场景及进阶用法

《JavaScript中的reduce方法执行过程、使用场景及进阶用法》：本文主要介绍JavaScript中的reduce方法执行过程、使用场景及进阶用法的相关资料,reduce是JavaScri... 目录1. 什么是reduce2. reduce语法2.1 语法2.2 参数说明3. reduce执行过程
阅读更多...
在MySQL执行UPDATE语句时遇到的错误1175的解决方案

在MySQL执行UPDATE语句时遇到的错误1175的解决方案

《在MySQL执行UPDATE语句时遇到的错误1175的解决方案》MySQL安全更新模式（SafeUpdateMode）限制了UPDATE和DELETE操作,要求使用WHERE子句时必须基于主键或索引... mysql 中遇到的 Error Code: 1175 是由于启用了 安全更新模式（Safe Upd
阅读更多...
如何利用Java获取当天的开始和结束时间

如何利用Java获取当天的开始和结束时间

《如何利用Java获取当天的开始和结束时间》：本文主要介绍如何使用Java8的LocalDate和LocalDateTime类获取指定日期的开始和结束时间,展示了如何通过这些类进行日期和时间的处... 目录前言1. Java日期时间API概述2. 获取当天的开始和结束时间代码解析运行结果3. 总结前言在J
阅读更多...
修改若依框架Token的过期时间问题

修改若依框架Token的过期时间问题

《修改若依框架Token的过期时间问题》本文介绍了如何修改若依框架中Token的过期时间,通过修改`application.yml`文件中的配置来实现,默认单位为分钟,希望此经验对大家有所帮助,也欢迎... 目录修改若依框架Token的过期时间修改Token的过期时间关闭Token的过期时js间总结修改若依
阅读更多...
Go Mongox轻松实现MongoDB的时间字段自动填充

Go Mongox轻松实现MongoDB的时间字段自动填充

《GoMongox轻松实现MongoDB的时间字段自动填充》这篇文章主要为大家详细介绍了Go语言如何使用mongox库,在插入和更新数据时自动填充时间字段,从而提升开发效率并减少重复代码,需要的可以... 目录前言时间字段填充规则Mongox 的安装使用 Mongox 进行插入操作使用 Mongox 进行更
阅读更多...
Spring Boot 整合 ShedLock 处理定时任务重复执行的问题小结

Spring Boot 整合 ShedLock 处理定时任务重复执行的问题小结

《SpringBoot整合ShedLock处理定时任务重复执行的问题小结》ShedLock是解决分布式系统中定时任务重复执行问题的Java库,通过在数据库中加锁,确保只有一个节点在指定时间执行... 目录前言什么是 ShedLock？ShedLock 的工作原理：定时任务重复执行China编程的问题使用 Shed
阅读更多...
对postgresql日期和时间的比较

对postgresql日期和时间的比较

《对postgresql日期和时间的比较》文章介绍了在数据库中处理日期和时间类型时的一些注意事项,包括如何将字符串转换为日期或时间类型,以及在比较时自动转换的情况,作者建议在使用数据库时,根据具体情况... 目录PostgreSQL日期和时间比较DB里保存到时分秒，需要和年月日比较db里存储date或者ti
阅读更多...
详解如何在React中执行条件渲染

详解如何在React中执行条件渲染

《详解如何在React中执行条件渲染》在现代Web开发中,React作为一种流行的JavaScript库,为开发者提供了一种高效构建用户界面的方式,条件渲染是React中的一个关键概念,本文将深入探讨... 目录引言什么是条件渲染？基础示例使用逻辑与运算符（&&）使用条件语句列表中的条件渲染总结引言在现代
阅读更多...
Python Invoke自动化任务库的使用

Python Invoke自动化任务库的使用

《PythonInvoke自动化任务库的使用》Invoke是一个强大的Python库,用于编写自动化脚本,本文就来介绍一下PythonInvoke自动化任务库的使用,具有一定的参考价值,感兴趣的可以... 目录什么是 Invoke？如何安装 Invoke？Invoke 基础1. 运行测试2. 构建文档3.
阅读更多...
解决Cron定时任务中Pytest脚本无法发送邮件的问题

解决Cron定时任务中Pytest脚本无法发送邮件的问题

《解决Cron定时任务中Pytest脚本无法发送邮件的问题》文章探讨解决在Cron定时任务中运行Pytest脚本时邮件发送失败的问题,先优化环境变量,再检查Pytest邮件配置,接着配置文件确保SMT... 目录引言1. 环境变量优化：确保Cron任务可以正确执行解决方案：1.1. 创建一个脚本1.2. 修
阅读更多...

Copyright China编程 23002807@qq.com

沪ICP备2023033072号-2