计时任务之StopWatch

StopWatch对应的中文名称为秒表，经常我们对一段代码耗时检测的代码如下：

long startTime = System.currentTimeMillis();

// 业务处理代码
doSomeThing();

long endTime = System.currentTimeMillis();

long costTime = endTime -startTime;

System.err.println("该段代码耗时：" + costTime + " ms");

改进的代码写法：

我们可以利用已有的工具类中的秒表，常见的秒表工具类有org.springframework.util.StopWatch、org.apache.commons.lang.time.StopWatch以及谷歌提供的guava中的秒表。这里重点讲下，org.springframework.util.StopWatch的用法。

org.springframework.util.StopWatch的用法：

源码：

package org.springframework.util;

import java.text.NumberFormat;
import java.util.LinkedList;
import java.util.List;

public class StopWatch {

    private final String id;

    private boolean keepTaskList = true;

    private final List<TaskInfo> taskList = new LinkedList<TaskInfo>();

    /** Start time of the current task */
    private long startTimeMillis;

    /** Is the stop watch currently running? */
    private boolean running;

    /** Name of the current task */
    private String currentTaskName;

    private TaskInfo lastTaskInfo;

    private int taskCount;

    /** Total running time */
    private long totalTimeMillis;
    /**
     * Construct a new stop watch. Does not start any task.
     */
    public StopWatch() {
        this.id = "";
    }

    /**
     * Construct a new stop watch with the given id.
     * Does not start any task.
     * @param id identifier for this stop watch.
     * Handy when we have output from multiple stop watches
     * and need to distinguish between them.
     */
    public StopWatch(String id) {
        this.id = id;
    }
    /**
     * Determine whether the TaskInfo array is built over time. Set this to
     * "false" when using a StopWatch for millions of intervals, or the task
     * info structure will consume excessive memory. Default is "true".
     */
    public void setKeepTaskList(boolean keepTaskList) {
        this.keepTaskList = keepTaskList;
    }
    /**
     * Start an unnamed task. The results are undefined if {@link #stop()}
     * or timing methods are called without invoking this method.
     * @see #stop()
     */
    public void start() throws IllegalStateException {
        start("");
    }

    /**
     * Start a named task. The results are undefined if {@link #stop()}
     * or timing methods are called without invoking this method.
     * @param taskName the name of the task to start
     * @see #stop()
     */
    public void start(String taskName) throws IllegalStateException {
        if (this.running) {
            throw new IllegalStateException("Can't start StopWatch: it's already running");
        }
        this.running = true;
        this.currentTaskName = taskName;
        this.startTimeMillis = System.currentTimeMillis();
    }
    /**
     * Stop the current task. The results are undefined if timing
     * methods are called without invoking at least one pair
     * {@code start()} / {@code stop()} methods.
     * @see #start()
     */
    public void stop() throws IllegalStateException {
        if (!this.running) {
            throw new IllegalStateException("Can't stop StopWatch: it's not running");
        }
        long lastTime = System.currentTimeMillis() - this.startTimeMillis;
        this.totalTimeMillis += lastTime;
        this.lastTaskInfo = new TaskInfo(this.currentTaskName, lastTime);
        if (this.keepTaskList) {
            this.taskList.add(lastTaskInfo);
        }
        ++this.taskCount;
        this.running = false;
        this.currentTaskName = null;
    }

    /**
     * Return whether the stop watch is currently running.
     */
    public boolean isRunning() {
        return this.running;
    }
    /**
     * Return the time taken by the last task.
     */
    public long getLastTaskTimeMillis() throws IllegalStateException {
        if (this.lastTaskInfo == null) {
            throw new IllegalStateException("No tasks run: can't get last task interval");
        }
        return this.lastTaskInfo.getTimeMillis();
    }
    /**
     * Return the name of the last task.
     */
    public String getLastTaskName() throws IllegalStateException {
        if (this.lastTaskInfo == null) {
            throw new IllegalStateException("No tasks run: can't get last task name");
        }
        return this.lastTaskInfo.getTaskName();
    }

    /**
     * Return the last task as a TaskInfo object.
     */
    public TaskInfo getLastTaskInfo() throws IllegalStateException {
        if (this.lastTaskInfo == null) {
            throw new IllegalStateException("No tasks run: can't get last task info");
        }
        return this.lastTaskInfo;
    }

    /**
     * Return the total time in milliseconds for all tasks.
     */
    public long getTotalTimeMillis() {
        return this.totalTimeMillis;
    }
    /**
     * Return the total time in seconds for all tasks.
     */
    public double getTotalTimeSeconds() {
        return this.totalTimeMillis / 1000.0;
    }

    /**
     * Return the number of tasks timed.
     */
    public int getTaskCount() {
        return this.taskCount;
    }

    /**
     * Return an array of the data for tasks performed.
     */
    public TaskInfo[] getTaskInfo() {
        if (!this.keepTaskList) {
            throw new UnsupportedOperationException("Task info is not being kept!");
        }
        return this.taskList.toArray(new TaskInfo[this.taskList.size()]);
    }

    /**
     * Return a short description of the total running time.
     */
    public String shortSummary() {
        return "StopWatch '" + this.id + "': running time (millis) = " + getTotalTimeMillis();
    }
    /**
     * Return a string with a table describing all tasks performed.
     * For custom reporting, call getTaskInfo() and use the task info directly.
     */
    public String prettyPrint() {
        StringBuilder sb = new StringBuilder(shortSummary());
        sb.append('
');
        if (!this.keepTaskList) {
            sb.append("No task info kept");
        }
        else {
            sb.append("-----------------------------------------
");
            sb.append("ms     %     Task name
");
            sb.append("-----------------------------------------
");
            NumberFormat nf = NumberFormat.getNumberInstance();
            nf.setMinimumIntegerDigits(5);
            nf.setGroupingUsed(false);
            NumberFormat pf = NumberFormat.getPercentInstance();
            pf.setMinimumIntegerDigits(3);
            pf.setGroupingUsed(false);
            for (TaskInfo task : getTaskInfo()) {
                sb.append(nf.format(task.getTimeMillis())).append("  ");
                sb.append(pf.format(task.getTimeSeconds() / getTotalTimeSeconds())).append("  ");
                sb.append(task.getTaskName()).append("
");
            }
        }
        return sb.toString();
    }

    /**
     * Return an informative string describing all tasks performed
     * For custom reporting, call {@code getTaskInfo()} and use the task info directly.
     */
    @Override
    public String toString() {
        StringBuilder sb = new StringBuilder(shortSummary());
        if (this.keepTaskList) {
            for (TaskInfo task : getTaskInfo()) {
                sb.append("; [").append(task.getTaskName()).append("] took ").append(task.getTimeMillis());
                long percent = Math.round((100.0 * task.getTimeSeconds()) / getTotalTimeSeconds());
                sb.append(" = ").append(percent).append("%");
            }
        }
        else {
            sb.append("; no task info kept");
        }
        return sb.toString();
    }
    /**
     * Inner class to hold data about one task executed within the stop watch.
     */
    public static final class TaskInfo {

        private final String taskName;

        private final long timeMillis;

        TaskInfo(String taskName, long timeMillis) {
            this.taskName = taskName;
            this.timeMillis = timeMillis;
        }
        /**
         * Return the name of this task.
         */
        public String getTaskName() {
            return this.taskName;
        }

        /**
         * Return the time in milliseconds this task took.
         */
        public long getTimeMillis() {
            return this.timeMillis;
        }

        /**
         * Return the time in seconds this task took.
         */
        public double getTimeSeconds() {
            return (this.timeMillis / 1000.0);
        }
    }

}

可以看到有一个List<StopWatch.TaskInfo> taskList，用于存储一组任务的耗时时间。这个很有用。比如：我们可以记录多段代码耗时时间，然后一次性打印（这里：org.springframework.util.StopWatch提供了一个prettyString()函数用于按照指定格式打印出耗时）

举个例子：

package com.coco.controller;

import org.springframework.util.StopWatch;

public class TestStopWatch {

    public static void main(String[] args) throws InterruptedException {
        // 定义一个计数器
        StopWatch stopWatch = new StopWatch("统计一组任务耗时");
        // 统计任务一耗时
        stopWatch.start("任务一");
        Thread.sleep(1000);
        stopWatch.stop();

        // 统计任务二耗时
        stopWatch.start("任务二");
        Thread.sleep(2000);
        stopWatch.stop();
        // 打印出耗时
        String result = stopWatch.prettyPrint();
        System.out.println(result);
    }
}

结果为：

分析：

可以看到可以统一定义一个计数器为“统计一组任务耗时”，然后看到整段代码的耗时。以及各个部分程序代码的执行时间，并且输出的格式帮我们整理好了。