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。

相关文章

Redis实现延迟任务的三种方法详解

Redis实现延迟任务的三种方法详解

《Redis实现延迟任务的三种方法详解》延迟任务（DelayedTask）是指在未来的某个时间点,执行相应的任务,本文为大家整理了三种常见的实现方法,感兴趣的小伙伴可以参考一下... 目录1.前言2.Redis如何实现延迟任务3.代码实现3.1. 过期键通知事件实现3.2. 使用ZSet实现延迟任务3.3
阅读更多...
golang获取当前时间、时间戳和时间字符串及它们之间的相互转换方法

golang获取当前时间、时间戳和时间字符串及它们之间的相互转换方法

《golang获取当前时间、时间戳和时间字符串及它们之间的相互转换方法》：本文主要介绍golang获取当前时间、时间戳和时间字符串及它们之间的相互转换,本文通过实例代码给大家介绍的非常详细,感兴趣... 目录1、获取当前时间2、获取当前时间戳3、获取当前时间的字符串格式4、它们之间的相互转化上篇文章给大家介
阅读更多...
Feign Client超时时间设置不生效的解决方法

Feign Client超时时间设置不生效的解决方法

《FeignClient超时时间设置不生效的解决方法》这篇文章主要为大家详细介绍了FeignClient超时时间设置不生效的原因与解决方法,具有一定的的参考价值,希望对大家有一定的帮助... 在使用Feign Client时，可以通过两种方式来设置超时时间：1.针对整个Feign Client设置超时时间
阅读更多...
springboot+dubbo实现时间轮算法

springboot+dubbo实现时间轮算法

《springboot+dubbo实现时间轮算法》时间轮是一种高效利用线程资源进行批量化调度的算法,本文主要介绍了springboot+dubbo实现时间轮算法,文中通过示例代码介绍的非常详细,对大家... 目录前言一、参数说明二、具体实现1、HashedwheelTimer2、createWheel3、n
阅读更多...
Linux中的计划任务(crontab)使用方式

Linux中的计划任务(crontab)使用方式

《Linux中的计划任务(crontab)使用方式》：本文主要介绍Linux中的计划任务(crontab)使用方式,具有很好的参考价值,希望对大家有所帮助,如有错误或未考虑完全的地方,望不吝赐教... 目录一、前言1、linux的起源与发展2、什么是计划任务（crontab）二、crontab基础1、cro
阅读更多...
Java中StopWatch的使用示例详解

Java中StopWatch的使用示例详解

《Java中StopWatch的使用示例详解》stopWatch是org.springframework.util包下的一个工具类,使用它可直观的输出代码执行耗时,以及执行时间百分比,这篇文章主要介绍... 目录stopWatch 是org.springframework.util 包下的一个工具类，使用它
阅读更多...
Java实现时间与字符串互相转换详解

Java实现时间与字符串互相转换详解

《Java实现时间与字符串互相转换详解》这篇文章主要为大家详细介绍了Java中实现时间与字符串互相转换的相关方法,文中的示例代码讲解详细,感兴趣的小伙伴可以跟随小编一起学习一下... 目录一、日期格式化为字符串（一）使用预定义格式（二）自定义格式二、字符串解析为日期（一）解析ISO格式字符串（二）解析自定义
阅读更多...
Spring定时任务只执行一次的原因分析与解决方案

Spring定时任务只执行一次的原因分析与解决方案

《Spring定时任务只执行一次的原因分析与解决方案》在使用Spring的@Scheduled定时任务时,你是否遇到过任务只执行一次,后续不再触发的情况？这种情况可能由多种原因导致,如未启用调度、线程... 目录1. 问题背景2. Spring定时任务的基本用法3. 为什么定时任务只执行一次？3.1 未启用
阅读更多...
Java时间轮调度算法的代码实现

Java时间轮调度算法的代码实现

《Java时间轮调度算法的代码实现》时间轮是一种高效的定时调度算法,主要用于管理延时任务或周期性任务,它通过一个环形数组（时间轮）和指针来实现,将大量定时任务分摊到固定的时间槽中,极大地降低了时间复杂... 目录1、简述2、时间轮的原理3. 时间轮的实现步骤3.1 定义时间槽3.2 定义时间轮3.3 使用时
阅读更多...
如何使用Python实现一个简单的window任务管理器

如何使用Python实现一个简单的window任务管理器

《如何使用Python实现一个简单的window任务管理器》这篇文章主要为大家详细介绍了如何使用Python实现一个简单的window任务管理器,文中的示例代码讲解详细,感兴趣的小伙伴可以跟随小编一起... 任务管理器效果图完整代码import tkinter as tkfrom tkinter i
阅读更多...

Copyright China编程 23002807@qq.com

沪ICP备2023033072号-2