计时器工具 StopWatch

Posted 2022-04-05 陈皮的JavaLib

我是陈皮，一个在互联网 Coding 的 ITer，个人微信公众号「陈皮的JavaLib」关注第一时间阅读最新文章。

文章目录

• • 前言
  • Spring StopWatch
  • 实践例子
  • 源码分析
  • lang3 StopWatch
  • 总结

前言

平常，我们想要统计某一段代码块，或某一个方法的执行时间，最简单的是采用如下的方式。

package com.chenpi;

/**
 * @author 陈皮
 * @version 1.0
 * @description
 * @date 2022/4/2
 */
public class ChenPi 

  public static void main(String[] args) throws InterruptedException 
    long startTime = System.currentTimeMillis();
    Thread.sleep(1000);
    long endTime = System.currentTimeMillis();
    System.out.println("执行耗时(ms):" + (endTime - startTime));
  



// 输出结果如下
执行耗时(ms):1011

但如果我们想对多个代码段进行计时，以及每个阶段计时的占比等信息，如果还是采用如上的方式就会充斥比较多的与业务无关的代码，不够简洁。

Spring StopWatch

Spring 框架有个工具类 StopWatch，它可以用来对程序中代码块，或者方法进行计时，并且支持多阶段计时，以及阶段时间占比等统计，使用起来代码比较简洁，轻量。

package com.chenpi;

import org.springframework.util.StopWatch;

/**
 * @author 陈皮
 * @version 1.0
 * @description
 * @date 2022/4/2
 */
public class ChenPi 

  public static void main(String[] args) throws InterruptedException 
    // 声明一个计时器
    StopWatch stopWatch = new StopWatch("陈皮的计时器");
    // 开始计时
    stopWatch.start("发送MQ计时");
    Thread.sleep(1000);
    // 结束计时
    stopWatch.stop();
    // 打印统计
    System.out.println(stopWatch.prettyPrint());
  




// 输出结果如下
StopWatch '陈皮的计时器': running time = 1005775500 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1005775500  100%  发送MQ计时

Spring StopWatch 有以下几个常用方法：

• StopWatch()：构造一个计时器

• StopWatch(String id)：构造一个指定 id 的计时器

• start()：创建一个名为空字符串的计时任务，开始计时

• start(String taskName)：创建一个指定名称计时任务，开始计时

• stop()：结束当前任务的计时

• getTotalTimeNanos()：获取全部任务的执行时间，单位纳秒

• getTotalTimeMillis()：获取全部任务的执行时间，单位毫秒

• shortSummary()：获取简单的统计信息

• prettyPrint()：以友好方式输出总统计时间，以及各个阶段任务的执行时间

• setKeepTaskList(boolean keepTaskList)：是否在内部的列表中存储每一个任务

实践例子

当程序中有多个计时器时，可通过构造不同 id 的计时器来区分。以下演示多个不同计时器，统计不同阶段的执行时间。

package com.chenpi;

import org.springframework.util.StopWatch;

/**
 * @author 陈皮
 * @version 1.0
 * @description
 * @date 2022/4/2
 */
public class ChenPi 

  public static void main(String[] args) throws InterruptedException 
    m1();
    m2();
  

  private static void m1() throws InterruptedException 

    // 声明一个计时器
    StopWatch stopWatch = new StopWatch("m1计时器");

    stopWatch.start("查询数据库");
    Thread.sleep(1000);
    stopWatch.stop();

    stopWatch.start("逻辑计算");
    Thread.sleep(500);
    stopWatch.stop();

    System.out.println(stopWatch.prettyPrint());
  

  private static void m2() throws InterruptedException 

    // 声明一个计时器
    StopWatch stopWatch = new StopWatch("m2计时器");

    stopWatch.start("远程调用");
    Thread.sleep(800);
    stopWatch.stop();

    stopWatch.start("发送MQ");
    Thread.sleep(200);
    stopWatch.stop();

    System.out.println(stopWatch.prettyPrint());
  


// 输出结果如下
StopWatch 'm1计时器': running time = 1516953200 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1008091000  066%  查询数据库
508862200  034%  逻辑计算

StopWatch 'm2计时器': running time = 1013080000 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
809345900  080%  远程调用
203734100  020%  发生MQ

源码分析

其实 StopWatch 底层实现很简单，对于每一个任务，在任务开始和结束时刻调用System.nanoTime()方法获取服务器当前的时间，然后计算每一个任务的执行时间，存储在内部。内部使用一个列表存储不同任务阶段的执行时间，最后打印输出。

package org.springframework.util;

import java.text.NumberFormat;
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.TimeUnit;

import org.springframework.lang.Nullable;

public class StopWatch 

	// 计时器id
	private final String id;

    // 是否将任务存储到任务列表中
	private boolean keepTaskList = true;

    // 存储全部任务的列表
	private final List<TaskInfo> taskList = new ArrayList<>(1);

	// 当前任务开始时间
	private long startTimeNanos;

	// 当前任务名称
	@Nullable
	private String currentTaskName;

    // 最后一个任务
	@Nullable
	private TaskInfo lastTaskInfo;

    // 总任务数
	private int taskCount;

	// 总的执行时间
	private long totalTimeNanos;

    // 构造一个id为空字符串的计时器
	public StopWatch() 
		this("");
	

    // 构造一个指定id的计时器
	public StopWatch(String id) 
		this.id = id;
	

    // 获取计时器id
	public String getId() 
		return this.id;
	

	public void setKeepTaskList(boolean keepTaskList) 
		this.keepTaskList = keepTaskList;
	

    // 开始计时
	public void start() throws IllegalStateException 
		start("");
	

    // 开始一个指定任务名称的计时
	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();
	

	// 停止任务计时
	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);
	

	@Nullable
	public 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();
	

	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";
	

	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();
	

	@Override
	public 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;
	

    // 任务实体
	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 使用起来简洁，支持多任务阶段统计，统计多任务时间占比等，