头图

我们经常需要统计一个方法的耗时,一般我们会这样做:

public class Test {
    public static void main(String[] args) throws InterruptedException {
        long start = System.currentTimeMillis();
        // 睡眠100ms,模拟任务耗时
        Thread.sleep(100L);
        long end = System.currentTimeMillis();
        System.out.println("耗时:" + (end - start)); // 输出 耗时:104
    }
}

这样做虽然简单直接,当我们需要分段统计耗时的时候,一不留神就找不到开始时间在哪了。而且也不能汇总结果,不能直观的看到每一步的耗时。

有一个简单的小工具,可以帮助我们非常容易的统计方法耗时。

名字叫StopWatch,在常见的类库,例如Spring、Apache Commons、Google Guava都有这个工具,功能和实现都是大同小异,推荐使用Spring里的,可以更方便统计耗时的汇总结果。

把耗时代码换成StopWatch试一下:

public class Test {
    public static void main(String[] args) throws InterruptedException {
        // 创建统计任务
        StopWatch stopWatch = new StopWatch();
        // 开始计时
        stopWatch.start();
        // 睡眠100ms,模拟任务耗时
        Thread.sleep(100L);
        // 结束计时
        stopWatch.stop();
        // 打印统计结果
        System.out.println(stopWatch.prettyPrint());
    }
}

输出结果是:

StopWatch '': running time (millis) = 104
-----------------------------------------
ms     %     Task name
-----------------------------------------
00104  100%  

只统计了一个任务的耗时,还不能展示出StopWatch优势,下面一次统计多个任务的耗时:

public class CopyTest {
    public static void main(String[] args) {
        // 创建统计任务,并指定ID
        StopWatch stopWatch = new StopWatch("Main方法耗时");
        IntStream.rangeClosed(1, 10).forEach(index -> {
            // 开始计时,并指定任务名称,便于展示
            stopWatch.start("task" + index);
            // 睡眠100ms,模拟任务耗时
            try {
                Thread.sleep(100L);
            } catch (InterruptedException e) {
            }
            // 结束计时
            stopWatch.stop();
        });
        // 打印统计结果
        System.out.println(stopWatch.prettyPrint());
    }
}

输出结果是:

StopWatch 'Main方法耗时': running time (millis) = 1039
-----------------------------------------
ms     %     Task name
-----------------------------------------
00103  010%  task1
00107  010%  task2
00104  010%  task3
00104  010%  task4
00105  010%  task5
00102  010%  task6
00104  010%  task7
00102  010%  task8
00105  010%  task9
00103  010%  task10

打印出了每个任务的耗时,并统计了在总耗时所占百分比,已经非常直观了。

这是怎么实现的呢?其实源码非常简单,就用一个LinkedList记录了每个任务的耗时:

public class StopWatch {

    // 总任务ID
    private final String id;

    // 任务集合
    private final List<TaskInfo> taskList = new LinkedList<TaskInfo>();

    private long startTimeMillis;

    private boolean running;

    private String currentTaskName;

    private TaskInfo lastTaskInfo;

    private long totalTimeMillis;

    public StopWatch() {
        this("");
    }

    public StopWatch(String id) {
        this.id = id;
    }

    public void start() throws IllegalStateException {
        start("");
    }

    // 开始计时,并记录开始时间
    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();
    }

    // 结束计时,统计耗时,并添加到taskList里面
    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);
        this.taskList.add(lastTaskInfo);
        this.running = false;
        this.currentTaskName = null;
    }

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

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

    public double getTotalTimeSeconds() {
        return this.totalTimeMillis / 1000.0;
    }

    public TaskInfo[] getTaskInfo() {
        return this.taskList.toArray(new TaskInfo[this.taskList.size()]);
    }

    public String shortSummary() {
        return "StopWatch '" + getId() + "': running time (millis) = " + getTotalTimeMillis();
    }
        // 打印统计结果
    public String prettyPrint() {
        StringBuilder sb = new StringBuilder(shortSummary());
        sb.append('\n');
        sb.append("-----------------------------------------\n");
        sb.append("ms     %     Task name\n");
        sb.append("-----------------------------------------\n");
        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("\n");
        }
        return sb.toString();
    }

    public static final class TaskInfo {
        private final String taskName;
        private final long timeMillis;
        TaskInfo(String taskName, long timeMillis) {
            this.taskName = taskName;
            this.timeMillis = timeMillis;
        }
    }
}

感觉怎么样?赶紧使用起来吧。


一灯架构
44 声望11 粉丝