In practice, we often need to record the execution time of a task, which is an important operation to evaluate the quality of the code, evaluate the performance of the code and check the execution problems of the business. So, how do you capture and calculate the task execution time? Get the time from new Date for conversion? Or is there a better plan? This article gives you the answer.

The common practice of obtaining the task time

The simplest way to obtain the task time is to print the difference between the current time and the start time of the task. Example code is as follows:

@Test public void testElapsedTimes() throws InterruptedException { long startTime = new Date().getTime(); // do something Thread.sleep(1000); System.out.println(" execution time: "+ (new Date().getTime() -starttime) + "ms"); }Copy the code

The above method is simple and the logic is intuitive. But if you run a lot of tests with different chunks of code logic, you have a lot to change.

Improve practices

In the above code, if the IDE has a code-checking tool installed, it prompts you to use System.currentTimemillis () to get the time instead of new Date().getTime().

After the transformation, the implementation code is as follows:

@Test public void testElapsedTimes1() throws InterruptedException { long startTime = System.currentTimeMillis(); // do something Thread.sleep(1000); System.out.println(" Execution time: "+ (system.currentTimemillis () -startTime) + "ms"); }Copy the code

It is also recommended to use System.currentTimemillis () to get the timestamp in such scenarios without needing to get more Date information. As for why, take a look at the source implementation of Date.

Date constructor:

public Date() {
    this(System.currentTimeMillis());
}
Copy the code

Date is constructed by essentially getting System.currentTimemillis () and then initializing the rest of the information. Since all we need is a timestamp, there is no need to build a Date object. From a performance perspective, what can be optimized is optimized.

Spring’s StopWatch

Although the performance and writing of the above two methods are different, the essence is the same. Spring provides a StopWatch class that not only performs the above functions, but also performs similar task execution time control, that is, encapsulates a Java class that records operations on start and end times.

First through the StopWatch class to achieve the above functions:

@Test public void testStopWatch() throws InterruptedException { StopWatch sw = new StopWatch(); Sw. Start (" start business "); // do something Thread.sleep(1000); sw.stop(); System.out.println(sw.getTotalTimeMillis()); }Copy the code

Create a StopWatch object and call its start and stop methods to separate the execution interval. Get the total time using getTotalTimeMillis() method.

At first glance, the code seems to have more advantages than the previous approach. Let’s look at a more complicated example:

@Test public void testStopWatch1() throws InterruptedException { StopWatch sw = new StopWatch(); Sw. Start (" up "); Thread.sleep(1000); sw.stop(); Sw. Start (" wash "); Thread.sleep(2000); sw.stop(); Sw. Start (" to lock the door "); Thread.sleep(500); sw.stop(); System.out.println(sw.prettyPrint()); System.out.println(sw.getTotalTimeMillis()); System.out.println(sw.getLastTaskName()); System.out.println(sw.getLastTaskInfo()); System.out.println(sw.getTaskCount()); }Copy the code

Run the preceding test example. The following output is displayed:

StopWatch '': running time = 3509166972 ns --------------------------------------------- ns % Task name -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- -- get up 1003330360 029%, 2001421734 057% wash gargle 504414878 014% 3509 to lock the door to lock the door org.springframework.util.StopWatch$TaskInfo@12f40c25 3Copy the code

At this point, see the charm of StopWatch?

  • Through multiple groups of start and stop methods, business code blocks are distinguished to obtain the execution time of different code blocks.
  • You can name each code block by passing in a taskName through the start method.
  • Statistical analysis can be performed on the total task time and each task time.
  • The prettyPrint() method can elegantly print out statistical analysis information;
  • GetTotalTimeMillis () to print the total time;
  • The getLastTaskName() method prints the last task name;
  • GetLastTaskInfo () method to get the TaskInfo of the last task for more information;
  • GetTaskCount () method to get the number of tasks;

Now, can we get more useful information by using StopWatch?

The implementation principle of StopWatch

Finally, let’s take a look at the source code to understand the implementation mechanism of StopWatch.

StopWatch start method

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(); }Copy the code

The start method records the task name and the execution time of the task, based on system.nanotime ().

The stop method is implemented as follows:

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;
  }
Copy the code

In the stop method, the two timestamps are subtracted to obtain lastTime, which is the execution time of a task; LastTime adds up to get the total execution time; At the same time, record the task list and task count statistics.

Other GET methods are simply further statistics, analysis, and formatted output of the data obtained in start and stop.

summary

Some functions when we are used to using, we may stick to a way of implementation, but if we refer to the implementation of similar functions in other frameworks, there will often be some new breakthroughs. If you are using the Spring framework, you are advised to try the StopWatch API, which can make your time statistics log more sophisticated.

About the blogger: Author of the technology book SpringBoot Inside Technology, loves to delve into technology and writes technical articles.

Public account: “program new vision”, the blogger’s public account, welcome to follow ~

Technical exchange: Please contact the weibo user at Zhuan2quan