StopWatch

Program timer

During our development process, in order to better monitor the operation of the system, interface, and business, we generally monitor the running time of the program. Initially, we used System.currentTimeMillis() to obtain the start and end times and then subtracted them. Thereby obtaining the program running time, but this method is very cumbersome and not concise and clear enough.

Introduction

StopWatch is available in Spring, Apache, and hutool toolkits. The implementation principles are similar, but some API calls and uses are different.

Let’s first look at the use of StopWatch:

I believe that students who have read the SpringBoot source code should be familiar with this. StopWatch is used when the SpringBoot program starts:

public ConfigurableApplicationContext run(String... args) {
stopWatch = new StopWatch(); // Declare a StopWatch instance
stopWatch.start();//Task start
        …
        stopWatch.stop(); // Task stops
return context;
}

Looking at the SpringBoot example, we can know that the use of StopWatch is basically divided into three steps: creating an instance, starting and stopping. But as a spring tool class, will StopWatch be so simple? of course not.

Let’s take a look at the specific usage:

public static void main(String[] args) {
        // The parameters of the constructor method represent the id of the StopWatch instance, marking the identity of the instance.
        StopWatch watch = new StopWatch("StopWatch-Learning");
        String id = watch.getId();
        System.out.println("StopWatch's id: " + id);
        //Start the task, test is the name of the task
        watch.start("test");
        // Get whether StopWatch is running
        boolean running = watch.isRunning();
        System.out.println("Is it running" + running);
        //Task stops
        watch.stop();
        // Get the name of the task
        String lastTaskName = watch.getLastTaskName();
        System.out.println("StopWatch task name: " + lastTaskName);
        long lastTaskTimeNanos = watch.getLastTaskTimeNanos();//Task running time nanoseconds
// long lastTaskTimeMillis = watch.getLastTaskTimeMillis(); // Task running time in seconds
        System.out.println("Task" + lastTaskName + "Run" + lastTaskTimeNanos + "ns");

    }

operation result:

StopWatch id: StopWatch-Learning
is running true
StopWatch task name: test
Task test ran for 29000ns

We can also define two tasks at the same time:

public static void main(String[] args) {
        // The parameters of the constructor method represent the id of the StopWatch instance, marking the identity of the instance.
        StopWatch watch = new StopWatch("StopWatch-Learning");
        watch.start("test1");
        //Task stops
        watch.stop();
        // Get the name of the task
        String lastTaskName = watch.getLastTaskName();
        long task1TimeNanos = watch.getLastTaskTimeNanos(); // Task running time in nanoseconds
// long lastTaskTimeMillis = watch.getLastTaskTimeMillis(); // Task running time in seconds
        System.out.println("task1" + lastTaskName + "Run" + task1TimeNanos + "ns");


        watch.start("test2");
        watch.stop();
        long task2TimeNanos = watch.getLastTaskTimeNanos();
        System.out.println("task2" + lastTaskName + "Run" + task2TimeNanos + "ns");
        
        int count = watch.getTaskCount();
        System.out.println("A total of tasks started" + count + "tasks");
        long totalTimeNanos = watch.getTotalTimeNanos();
        System.out.println("A total of runs" + totalTimeNanos + "ns");
}

operation result:

task1test1 ran for 2200ns
task2test1 ran for 300ns
A total of 2 tasks were started
It ran for a total of 2500ns
StopWatch 'StopWatch-Learning': running time = 2500 ns

By the way, there is also a method prettyPrint(), which can help us print the output statements more beautifully!

public static void main(String[] args) {
        // The parameters of the constructor method represent the id of the StopWatch instance, marking the identity of the instance.
        StopWatch watch = new StopWatch("StopWatch-Learning");
        watch.start("test1");
        //Task stops
        watch.stop();
        // Get the name of the task
        String lastTaskName = watch.getLastTaskName();
        long task1TimeNanos = watch.getLastTaskTimeNanos(); // Task running time in nanoseconds
// long lastTaskTimeMillis = watch.getLastTaskTimeMillis(); // Task running time in seconds
        System.out.println("task1" + lastTaskName + "Run" + task1TimeNanos + "ns");

        System.out.println("^^^^^^^^^^^^^^^^^^^Separating line^^^^^^^^^^^^^^^^^^^ ^^^^^^^^^^^");
        String info = watch.prettyPrint();
        System.out.println(info);
    }

operation result:

task1test1 ran for 2200ns
^^^^^^^^^^^^^^^^^^^^Dividing line^^^^^^^^^^^^^^^^^^^^^^^^^^^ ^^^
StopWatch 'StopWatch-Learning': running time = 2200 ns
----------------------------------------
ns % Task name
----------------------------------------
000002200 100% test1

Isn’t it very convenient to use, silky smooth and very clear?

Principle

Let’s take a look at the 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();
}

At the beginning of the task, System.nanoTime() was used to obtain the nanosecond timestamp of the current time. In fact, it is the same as we used System.currentTimeMillis() before.

Let’s take a look at the stop() method:

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

It is also the time difference calculated by getting the current time and subtracting the start time. It is essentially the same as the currentTimeMillis we talked about at the beginning. It’s just that its time granularity is even finer, at the nanosecond level.

Suddenly there was a feeling of enlightenment. Isn’t this the same method as the one mentioned at the beginning? Isn’t it a modified version of currentTimeMillis? But just because the transformation is very good, we can calculate the task time very simply and cleverly.

The most ingenious thing is that we can create an ID for StopWatch to mark its identity, give each task a name, start and stop at any time, automatically calculate each task, the time difference of all tasks, and automatically format the results. API is more beautiful and grand. During development, it is easy to misunderstand the calculation time of multi-tasks, resulting in inaccurate calculations, and the advantages of StopWatch for multi-tasks are even more obvious.

Since StopWatch is so easy to use, what are you waiting for? Why not get up? That’s it for today’s sharing. There will be more technical sharing in the future. Everyone is welcome to pay attention!

The knowledge points of the article match the official knowledge files, and you can further learn related knowledge. Java Skill TreeHomepageOverview 138106 people are learning the system