The timer tool StopWatch

Make writing a habit together! This is my first day to participate in the “Gold Digging Day New Plan · April More text challenge”, click to see the details of the activity.

I am Chen PI, an ITer in Internet Coding. My personal wechat public account “Chen PI’s JavaLib” pays attention to read the latest articles in the first time.

preface

Usually, when we want to count the execution time of a particular code block or method, the simplest way is as follows.

 package com.chenpi;
 
 / * * *@authorDried tangerine or orange peel *@version 1.0
  * @description
  * @date2022/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("Execution time (ms):"+ (endTime - startTime)); }}// The output is as followsExecution time (ms):1011
Copy the code

However, if we want to time multiple code sections, as well as the proportion of each phase of the timing information, if we still adopt the above way will be filled with a lot of code unrelated to the business, not concise.

Spring StopWatch

Spring framework has a tool class, StopWatch, which can be used to time code blocks or methods in the program, and supports multi-stage timing, as well as stage time ratio and other statistics. The code is relatively simple and lightweight to use.

 package com.chenpi;
 
 import org.springframework.util.StopWatch;
 
 / * * *@authorDried tangerine or orange peel *@version 1.0
  * @description
  * @date2022/4/2 * /
 public class ChenPi {
 
   public static void main(String[] args) throws InterruptedException {
     // Declare a timer
     StopWatch stopWatch = new StopWatch("A timer for Tangerine peel.");
     // Start the timer
     stopWatch.start("Send MQ timing");
     Thread.sleep(1000);
     // End the timer
     stopWatch.stop();
     // Print statisticsSystem.out.println(stopWatch.prettyPrint()); }}// The output is as follows
 StopWatch 'Timer of Tangerine Peel': running time = 1005775500 ns
 ---------------------------------------------
 ns         %     Task name
 ---------------------------------------------
 1005775500  100% send MQ timingCopy the code

Spring StopWatch has the following common methods:

StopWatch() : Construct a timer
StopWatch(String ID) : Constructs a timer with the specified ID

Start () : Creates a timing task named empty string to start the timing
Start (String taskName) : Creates a timer task with a specified name and starts the timer
Stop () : stops the timer of the current task
GetTotalTimeNanos () : Gets the execution time of all tasks, in nanoseconds
GetTotalTimeMillis () : Gets the execution time of all tasks in milliseconds
ShortSummary () : Get simple statistics
PrettyPrint () : Outputs the total count time in a friendly manner, along with the execution times of tasks in each phase
SetKeepTaskList (Boolean keepTaskList) : Specifies whether to store each task in an internal list

Practical example

When there are multiple timers in a program, they can be distinguished by constructing timers with different ids. The following shows a number of different timers, counting execution times at different stages.

 package com.chenpi;
 
 import org.springframework.util.StopWatch;
 
 / * * *@authorDried tangerine or orange peel *@version 1.0
  * @description
  * @date2022/4/2 * /
 public class ChenPi {
 
   public static void main(String[] args) throws InterruptedException {
     m1();
     m2();
   }
 
   private static void m1(a) throws InterruptedException {
 
     // Declare a timer
     StopWatch stopWatch = new StopWatch("M1 Timer");
 
     stopWatch.start("Query database");
     Thread.sleep(1000);
     stopWatch.stop();
 
     stopWatch.start("Logical computation");
     Thread.sleep(500);
     stopWatch.stop();
 
     System.out.println(stopWatch.prettyPrint());
   }
 
   private static void m2(a) throws InterruptedException {
 
     // Declare a timer
     StopWatch stopWatch = new StopWatch("M2 timer");
 
     stopWatch.start("Remote call");
     Thread.sleep(800);
     stopWatch.stop();
 
     stopWatch.start("Send MQ");
     Thread.sleep(200); stopWatch.stop(); System.out.println(stopWatch.prettyPrint()); }}// The output is as follows
 StopWatch 'M1 timer': running time = 1516953200 ns
 ---------------------------------------------
 ns         %     Task name
 ---------------------------------------------
 1008091000  066% query database508862200  034% Logical calculation StopWatch'M2 timer': running time = 1013080000 ns
 ---------------------------------------------
 ns         %     Task name
 ---------------------------------------------
 809345900080% remote call203734100  020% in the MQCopy the code

Source code analysis

In fact, StopWatch underlying implementation is very simple, for each task, at the start and end of the task call System.*nanoTime*() method to obtain the current time of the server, and then calculate the execution time of each task, stored in the internal. Internally, a list is used to store the execution times of different task phases, and the output is printed.

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 {

	// Timer ID
	private final String id;

    // Whether to store tasks in the task list
	private boolean keepTaskList = true;

    // Store a list of all tasks
	private final List<TaskInfo> taskList = new ArrayList<>(1);

	// Start time of the current task
	private long startTimeNanos;

	// The current task name
	@Nullable
	private String currentTaskName;

    // Last task
	@Nullable
	private TaskInfo lastTaskInfo;

    // Total tasks
	private int taskCount;

	// Total execution time
	private long totalTimeNanos;

    // Construct a timer with an empty string id
	public StopWatch(a) {
		this("");
	}

    // Construct a timer with the specified id
	public StopWatch(String id) {
		this.id = id;
	}

    // Get the timer ID
	public String getId(a) {
		return this.id;
	}

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

    // Start the timer
	public void start(a) throws IllegalStateException {
		start("");
	}

    // Starts a timer with the specified task name
	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();
	}

	// Stop task timing
	public void stop(a) 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(a) {
		return (this.currentTaskName ! =null);
	}

	@Nullable
	public String currentTaskName(a) {
		return this.currentTaskName;
	}

	public long getLastTaskTimeNanos(a) 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(a) 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(a) 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(a) throws IllegalStateException {
		if (this.lastTaskInfo == null) {
			throw new IllegalStateException("No tasks run: can't get last task info");
		}
		return this.lastTaskInfo;
	}

	public long getTotalTimeNanos(a) {
		return this.totalTimeNanos;
	}

	public long getTotalTimeMillis(a) {
		return nanosToMillis(this.totalTimeNanos);
	}

	public double getTotalTimeSeconds(a) {
		return nanosToSeconds(this.totalTimeNanos);
	}

	public int getTaskCount(a) {
		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(a) {
		return "StopWatch '" + getId() + "': running time = " + getTotalTimeNanos() + " ns";
	}

	public String prettyPrint(a) {
		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(a) {
		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(The '%'); }}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;
	}

    // Task entity
	public static final class TaskInfo {

        // Task name
		private final String taskName;

        // Task execution time
		private final long timeNanos;

		TaskInfo(String taskName, long timeNanos) {
			this.taskName = taskName;
			this.timeNanos = timeNanos;
		}

		public String getTaskName(a) {
			return this.taskName;
		}

		public long getTimeNanos(a) {
			return this.timeNanos;
		}

		public long getTimeMillis(a) {
			return nanosToMillis(this.timeNanos);
		}

		public double getTimeSeconds(a) {
			return nanosToSeconds(this.timeNanos); }}}Copy the code

StopWatch is simple to use, supports multi-task stage statistics, statistics of multi-task time ratio, etc., and the statistical results are intuitive. However, it also has a disadvantage, that is, a StopWatch instance can only start a task at the same time, and can only start another task after the task is stopped. Note that StopWatch instances are not thread-safe and there is no need for synchronization.

lang3 StopWatch

The Apache Commons Lang3 package also includes a timekeeping utility class, StopWatch. It also has pause time, resume time, set the split point and other functions.

 org.apache.commons:commons-lang3:3.12. 0
Copy the code

It mainly has the following common methods:

Create () : Instantiates a timer
CreateStarted () : Instantiates a timer and starts the timer
StopWatch(Final String Message) : Instantiates a timer with an identifier

Start () : Starts the timer
Split () : Sets the split point
GetSplitTime () : counts the time taken from the last split point since start
Reset () : Resets the timer
Suspend () : Suspend the timer
Resume () : Restores the timer
Stop () : Stops the timer
GetTime () : statistics from start to the current time

 package com.chenpi;
 
 import org.apache.commons.lang3.time.StopWatch;
 
 / * * *@authorDried tangerine or orange peel *@version 1.0
  * @description
  * @date2022/4/2 * /
 public class ChenPi {
 
   public static void main(String[] args) throws InterruptedException {
 
     // Declare a timer
     StopWatch stopWatch = new StopWatch("M1 Timer");
 
     stopWatch.start();
     Thread.sleep(1000);
     System.out.println(Time between start and present: + stopWatch.getTime());
 
     stopWatch.split();
     Thread.sleep(500);
     System.out.println("Time between start and last split:" + stopWatch.getSplitTime());
 
     stopWatch.split();
     Thread.sleep(500);
     System.out.println("Time between start and last split:" + stopWatch.getSplitTime());
 
     // Reset the timer
     stopWatch.reset();
     Thread.sleep(2000);
     stopWatch.start();
     Thread.sleep(1000);
     System.out.println(Time between start and present: + stopWatch.getTime());
 
     // Pause the timer
     stopWatch.suspend();
     Thread.sleep(3000);
     // Restore the timer
     stopWatch.resume();
 
     Thread.sleep(1000);
 
     // End the timer
     stopWatch.stop();
 
     Thread.sleep(1000);
 
     System.out.println("Start to stop time:"+ stopWatch.getTime()); System.out.println(stopWatch); }}// The output is as followsStart time:1000The time between start and last split:1001The time between start and last split:1510Start time:1004Time from start to stop:2015M1 timer00:00:02.015
Copy the code

conclusion

For simple calculations, you can use the JDK’s built-in classes to obtain the system time.
If you need multi-phase timing and need to count the execution time ratio of each phase, you can use the StopWatch utility class.
It is recommended to use Spring StopWatch, because our project uses the Spring framework a lot, so StopWatch comes with it.

This is the end of sharing ~~

If you feel that the article is helpful to you, like, favorites, attention, comment, your support is the biggest motivation for my creation!

preface

Spring StopWatch

Practical example

Source code analysis

lang3 StopWatch

conclusion

Related Posts

MySQL Technical Topics: Technical analysis and guide to the high availability architecture of MySQL

MySQL lock summary

Design Pattern series – Combination pattern