Use StopWatch to calculate time-consuming [easy to understand]

Hello everyone, meet again, I am your friend Quanzhanjun.

1. Traditional computing time-consuming methods

Generally, System.currentTimeMillis() is used to obtain the time, and then print the difference between the current time and the time when the task starts executing.

  • record start time
  • record end time
  • Output the difference between the current time and the start time of the task

code show as below:

    public static void main(String[] args) throws InterruptedException { 
   
        long startTime = System.currentTimeMillis();

        // do something
        TimeUnit.SECONDS.sleep(5);

        System.out.println("Execution time:" + (System.currentTimeMillis() - startTime) + "ms");
    }
copy

2. Use Spring Timer StopWatch

StopWatch is a tool class located in the org.springframework.util package, through which it can easily time part of the program code (ns level), and can easily calculate the time-consuming of the task. There are also implementations under the commons toolkit that can be used directly (org.apache.commons.lang3.time.StopWatch), with similar functions.

1. Use of StopWatch

By creating a StopWatch object, and then calling its start and stop methods to distinguish the execution task interval, the time is obtained based on System.nanoTime(). The total time is obtained by the getTotalTimeMillis() method.

Other methods of StopWatch:

  • The prettyPrint() method can elegantly print out statistical analysis information;
  • getTotalTimeMillis() method, print out the total time;
  • getLastTaskName() method, print the last task name;
  • getLastTaskInfo() method, get the TaskInfo of the last task, and then get more relevant information;
  • getTaskCount() method to get the number of tasks;

demo1: single business module use

    public static void main(String[] args) throws InterruptedException { 
   
        StopWatch sw = new StopWatch("xx task time");

        sw.start();
        // do something
        TimeUnit.SECONDS.sleep(5);
        sw.stop();

        System.out.println(sw.getId() + ":"  + sw.getTotalTimeMillis() + "ms");
        System.out.println(sw.getLastTaskName());
        System.out.println(sw.getLastTaskInfo());
        System.out.println(sw.getTaskCount());
        System.out.println(sw.prettyPrint());
    }
copy

demo2: use of multi-service modules

    public static void main(String[] args) throws InterruptedException { 
   
        StopWatch sw = new StopWatch("xx task time");
        
        sw.start("Business 1");
        TimeUnit.SECONDS.sleep(2);
        sw.stop();

        sw.start("Business 2");
        TimeUnit.SECONDS.sleep(5);
        sw.stop();

        sw.start("Business 3");
        TimeUnit.SECONDS.sleep(3);
        sw.stop();

        System.out.println(sw.getId() + ":"  + sw.getTotalTimeMillis() + "ms");
        System.out.println(sw.prettyPrint());
    }
copy

Advantages and disadvantages of StopWatch: advantage:

  • Spring comes with tool classes, which can be used directly, the code is simple to implement, and the use is easier Through multiple groups of start and stop methods, the business code blocks are distinguished, and the execution time of different code blocks can be obtained. Unified induction, showing the percentage of time spent on each task and the total time occupied, and the results are intuitive.
  • The performance consumption is relatively small, and the accuracy of the time recording between start and stop is guaranteed to the greatest extent.

shortcoming:

  • A StopWatch instance can only start one task at a time, and start and stop must be used in pairs. To open more than one at a time task, requires new and different StopWatch instances
  • Code intrusive use, need to change multiple code

2. StopWatch source code in Spring

The source code implementation in this tool class is also extremely simple. The start time and end time are recorded respectively through the start and stop methods. When the end time is recorded, a tasklist attribute of linked list type is maintained, so that this class can record multiple tasks. Finally, the output is only a unified summary output of the previously recorded information, so that the results can be displayed more internally

  • StopWatch also encapsulates a TaskInfo inner class that records the task name and end time operations.
  • The task name and task execution time are recorded in the start method, and the time is obtained based on System.nanoTime().
  • In the stop method, lastTime is obtained by subtracting two timestamps, that is, the execution time of a task; the total execution time is obtained by cumulative addition of lastTime; at the same time, the task list and task number statistics are recorded.

The source code of StopWatch is as follows:

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 { 
   
    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 ArrayList(1);
        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;
        }
    }

    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");
        } else { 
   
            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");
        } else { 
   
            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");
        } else { 
   
            return this.lastTaskInfo.getTaskName();
        }
    }

    public StopWatch.TaskInfo getLastTaskInfo() throws IllegalStateException { 
   
        if (this.lastTaskInfo == null) { 
   
            throw new IllegalStateException("No tasks run: can't get last task info");
        } else { 
   
            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 StopWatch.TaskInfo[] getTaskInfo() { 
   
        if (!this.keepTaskList) { 
   
            throw new UnsupportedOperationException("Task info is not being kept!");
        } else { 
   
            return (StopWatch.TaskInfo[])this.taskList.toArray(new StopWatch.TaskInfo[0]);
        }
    }

    public String shortSummary() { 
   
        return "StopWatch '" + this.getId() + "': running time = " + this.getTotalTimeNanos() + " ns";
    }

    public String prettyPrint() { 
   
        StringBuilder sb = new StringBuilder(this.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);
            StopWatch.TaskInfo[] var4 = this.getTaskInfo();
            int var5 = var4.length;

            for(int var6 = 0; var6 < var5; ++var6) { 
   
                StopWatch.TaskInfo task = var4[var6];
                sb.append(nf.format(task.getTimeNanos())).append(" ");
                sb.append(pf.format((double)task.getTimeNanos() / (double)this.getTotalTimeNanos())).append(" ");
                sb.append(task.getTaskName()).append("\n");
            }
        }

        return sb.toString();
    }

    public String toString() { 
   
        StringBuilder sb = new StringBuilder(this.shortSummary());
        if (this.keepTaskList) { 
   
            StopWatch.TaskInfo[] var2 = this.getTaskInfo();
            int var3 = var2.length;

            for(int var4 = 0; var4 < var3; ++var4) { 
   
                StopWatch.TaskInfo task = var2[var4];
                sb.append("; [").append(task.getTaskName()).append("] took ").append(task.getTimeNanos()).append(" ns");
                long percent = Math.round(100.0D * (double)task.getTimeNanos() / (double)this.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 (double)duration / 1.0E9D;
    }

    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 StopWatch.nanosToMillis(this.timeNanos);
        }

        public double getTimeSeconds() { 
   
            return StopWatch.nanosToSeconds(this.timeNanos);
        }
    }
}
copy

– If you are hungry for knowledge, you are humble in heart.

Publisher: Full-stack programmer, please indicate the source: https://javaforall.cn/152459.html Original link: https://javaforall.cn

Posted by inghamn on Sat, 10 Sep 2022 02:00:45 +0930