Six methods of Java statistical code execution time

Posted by dhodge on Sat, 26 Feb 2022 06:19:05 +0100

In daily development, we often need to test the execution time of some code, but we don't want to use JMH( Java Microbbenchmark harness (Java micro benchmark suite) is such a heavy testing framework, so this paper summarizes some commonly used execution time statistics methods in Java, including the following 6 kinds in total, as shown in the figure below:

Method 1: system currentTimeMillis

This method is a built-in method in Java and uses system Currenttimemillis is used to calculate the time (statistical unit: ms) (statistical unit: ms). The example code is as follows:

public class TimeIntervalTest {
    public static void main(String[] args) throws InterruptedException {
        // start time
        long stime = System.currentTimeMillis();
        // Execution time (1s)
        Thread.sleep(1000);
        // End time
        long etime = System.currentTimeMillis();
        // Calculate execution time
        System.out.printf("Execution duration:%d millisecond.", (etime - stime));
    }
}

The results of the above procedures are:

Execution time: 1000 ms  

Method 2: system nanoTime

This method is a built-in method in Java and uses {system Nanotime is used to count the execution time (statistical unit: nanosecond), its execution method and system Similar to currenttimemillis, the example code is as follows:

public class TimeIntervalTest {
    public static void main(String[] args) throws InterruptedException {
        // start time
        long stime = System.nanoTime();
        // Execution time (1s)
        Thread.sleep(1000);
        // End time
        long etime = System.nanoTime();
        // Calculate execution time
        System.out.printf("Execution duration:%d nanosecond.", (etime - stime));
    }
}

The results of the above procedures are:

Execution time: 1000769200 nanoseconds

Tip: 1 millisecond = 1 million nanoseconds.

Method 3: new Date

This method is also a built-in method of Java. Before execution, create a current time object with new Date(), after execution ends, create a current execution time with new Date(), and then count the time interval between two new dates. The example code is as follows:

import java.util.Date;
 
public class TimeIntervalTest {
    public static void main(String[] args) throws InterruptedException {
        // start time
        Date sdate = new Date();
        // Execution time (1s)
        Thread.sleep(1000);
        // End time
        Date edate = new Date();
        //  Statistics execution time (MS)
        System.out.printf("Execution duration:%d millisecond." , (edate.getTime() - sdate.getTime())); 
    }
}

The results of the above procedures are:

Execution time: 1000 ms

Method 4: Spring StopWatch

If we use Spring or Spring Boot projects, we can directly use the StopWatch object in the project to count the code execution time. The example code is as follows:

StopWatch stopWatch = new StopWatch();
// start time
stopWatch.start();
// Execution time (1s)
Thread.sleep(1000);
// End time
stopWatch.stop();
// Statistical execution time (seconds)
System.out.printf("Execution duration:%d second.%n", stopWatch.getTotalTimeSeconds()); // %n is line feed
// Statistics execution time (MS)
System.out.printf("Execution duration:%d millisecond.%n", stopWatch.getTotalTimeMillis()); 
// Statistical execution time (nanoseconds)
System.out.printf("Execution duration:%d nanosecond.%n", stopWatch.getTotalTimeNanos());

The results of the above procedures are:

Execution time: 0.9996313 seconds Execution time: 999 Ms Execution time: 999631300 nanoseconds

Tip: the execution time of Thread#sleep method deviates slightly, and it is normal in about 1s.

Method 5: commons-lang3 StopWatch

If we use ordinary projects, we can use the StopWatch object in Apache commons-lang3 to realize time statistics. First, add the dependency of commons-lang3:

<!-- https://mvnrepository.com/artifact/org.apache.commons/commons-lang3 -->
<dependency>
  <groupId>org.apache.commons</groupId>
  <artifactId>commons-lang3</artifactId>
  <version>3.10</version>
</dependency>

Then write the time statistics Code:

import org.apache.commons.lang3.time.StopWatch;
import java.util.concurrent.TimeUnit;
 
public class TimeIntervalTest {
    public static void main(String[] args) throws InterruptedException {
        StopWatch stopWatch = new StopWatch();
        // start time
        stopWatch.start();
        // Execution time (1s)
        Thread.sleep(1000);
        // End time
        stopWatch.stop();
        // Statistical execution time (seconds)
        System.out.println("Execution duration:" + stopWatch.getTime(TimeUnit.SECONDS) + " second.");
        // Statistics execution time (MS)
        System.out.println("Execution duration:" + stopWatch.getTime(TimeUnit.MILLISECONDS) + " millisecond.");
        // Statistical execution time (nanoseconds)
        System.out.println("Execution duration:" + stopWatch.getTime(TimeUnit.NANOSECONDS) + " nanosecond.");
    }
}

The results of the above procedures are:

Execution time: 1 second Execution time: 1000 ms

Execution time: 1000555100 nanoseconds

Method 6: Guava Stopwatch

In addition to Apache's commons-lang3, there is also a commonly used Java toolkit, Google's Guava, which also contains the "Stopwatch" statistics class. First, add Guava's dependency:

<!-- https://mvnrepository.com/artifact/com.google.guava/guava -->
<dependency>
  <groupId>com.google.guava</groupId>
  <artifactId>guava</artifactId>
  <version>29.0-jre</version>
</dependency>

Then write the time statistics Code:

import com.google.common.base.Stopwatch;
import java.util.concurrent.TimeUnit;
 
public class TimeIntervalTest {
    public static void main(String[] args) throws InterruptedException {
        // Create and start a timer
        Stopwatch stopwatch = Stopwatch.createStarted();
        // Execution time (1s)
        Thread.sleep(1000);
        // Stop timer
        stopwatch.stop();
        // Execution time in seconds
        System.out.printf("Execution duration:%d second. %n", stopwatch.elapsed().getSeconds()); // %n is line feed
        // Execution time in milliseconds
        System.out.printf("Execution duration:%d Haos.", stopwatch.elapsed(TimeUnit.MILLISECONDS));
    }
}

The results of the above procedures are:

Execution time: 1 second

Execution time: 1000 seconds

Principle analysis

In this article, let's analyze the Guava source code of Spring and Google. How do they implement the bottom layer of their "StopWatch" object?

1. Principle analysis of spring stopwatch

In Spring, the core source code of StopWatch is as follows:

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;
 
public class StopWatch {
    private final String id;
    private boolean keepTaskList;
    private final List<StopWatch.TaskInfo> taskList;
    private long startTimeNanos;
    @Nullable
    private String currentTaskName;
    @Nullable
    private StopWatch.TaskInfo lastTaskInfo;
    private int taskCount;
    private long totalTimeNanos;
 
    public StopWatch() {
        this("");
    }
 
    public StopWatch(String id) {
        this.keepTaskList = true;
        this.taskList = new LinkedList();
        this.id = id;
    }
 
    public String getId() {
        return this.id;
    }
 
    public void setKeepTaskList(boolean keepTaskList) {
        this.keepTaskList = keepTaskList;
    }
 
    public void start() throws IllegalStateException {
        this.start("");
    }
 
    public void start(String taskName) throws IllegalStateException {
        if (this.currentTaskName != null) {
            throw new IllegalStateException("Can't start StopWatch: it's already running");
        } else {
            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");
        } else {
            long lastTime = System.nanoTime() - this.startTimeNanos;
            this.totalTimeNanos += lastTime;
            this.lastTaskInfo = new StopWatch.TaskInfo(this.currentTaskName, lastTime);
            if (this.keepTaskList) {
                this.taskList.add(this.lastTaskInfo);
            }
 
            ++this.taskCount;
            this.currentTaskName = null;
        }
    }
    // ....  Ignore other codes
}

As can be seen from the above source code of , start() and , stop(), the essence of Spring's implementation of time statistics still uses Java's built-in method , system Nanotime().

2. Principle analysis of Google stopwatch

The core source code of Google Stopwatch implementation is as follows:

public final class Stopwatch {
    private final Ticker ticker;
    private boolean isRunning;
    private long elapsedNanos;
    private long startTick;
    @CanIgnoreReturnValue
    public Stopwatch start() {
        Preconditions.checkState(!this.isRunning, "This stopwatch is already running.");
        this.isRunning = true;
        this.startTick = this.ticker.read();
        return this;
    }
 
    @CanIgnoreReturnValue
    public Stopwatch stop() {
        long tick = this.ticker.read();
        Preconditions.checkState(this.isRunning, "This stopwatch is already stopped.");
        this.isRunning = false;
        this.elapsedNanos += tick - this.startTick;
        return this;
    }
    // Ignore other source code
}

From the above source code, we can see that the Stopwatch class has called the ticker class to realize the time statistics. Then we enter the implementation source of the ticker class:

public abstract class Ticker {
    private static final Ticker SYSTEM_TICKER = new Ticker() {
        public long read() {
            return Platform.systemNanoTime();
        }
    };
    protected Ticker() {
    }
    public abstract long read();
    public static Ticker systemTicker() {
        return SYSTEM_TICKER;
    }
}
final class Platform {
    private static final Logger logger = Logger.getLogger(Platform.class.getName());
    private static final PatternCompiler patternCompiler = loadPatternCompiler();
 
    private Platform() {
    }
 
    static long systemNanoTime() {
        return System.nanoTime();
    }
    // Ignore other source code
}

From the above source code, we can see that the essence of Google Stopwatch to realize time statistics is to call the built-in Java Stopwatch system Nanotime().

conclusion

For the StopWatch of all frameworks, its bottom layer is through calling Java's built-in system Nanotime () gets two times, start time and end time, and then calculates the execution time by subtracting the start time from the end time.

summary
This paper introduces six methods to realize code statistics, three of which are built-in methods in Java:

  • System.currentTimeMillis()
  • System.nanoTime()
  • new Date()

The time statistician StopWatch of three common frameworks spring, commons langs3 and guava is also introduced.

If spring, commons langs3 and guava frameworks are not used, system. Com is recommended Currenttimemillis() or system Nanotime() to realize code statistics. Otherwise, it is recommended to directly use StopWatch object to count execution time.

Knowledge expansion Stopwatch makes statistics more convenient

The purpose of StopWatch is to make code statistics easier. For example, the use example of StopWatch in Guava is as follows:

import com.google.common.base.Stopwatch;
import java.util.concurrent.TimeUnit;
 
public class TimeIntervalTest {
    public static void main(String[] args) throws InterruptedException {
        // Create and start a timer
        Stopwatch stopwatch = Stopwatch.createStarted();
        // Execution time (1s)
        Thread.sleep(1000);
        // Stop timer
        stopwatch.stop();
        // Executive statistics
        System.out.printf("Execution duration:%d millisecond. %n",
                stopwatch.elapsed(TimeUnit.MILLISECONDS));
        // Clear timer
        stopwatch.reset();
        // Start statistics again
        stopwatch.start();
        // Execution time (2s)
        Thread.sleep(2000);
        // Stop timer
        stopwatch.stop();
        // Executive statistics
        System.out.printf("Execution duration:%d second. %n",
                stopwatch.elapsed(TimeUnit.MILLISECONDS));
    }
}

We can use a Stopwatch object to count the execution time of multiple pieces of code, or directly count the corresponding time interval by specifying the time type. For example, we can specify the statistical unit of time, such as seconds, milliseconds, nanoseconds and so on.

Topics: Java Back-end