大家好，又见面了，我是你们的朋友全栈君。

一、传统计算耗时方式

一般采用 System.currentTimeMillis() 来获取时间，然后打印当前时间与任务开始执行时间的差值。

• 记录开始时间点
• 记录结束时间点
• 输出当前时间与任务开始执行时间的差值

代码如下：

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

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

        System.out.println("执行耗时：" + (System.currentTimeMillis() - startTime) + "ms");
    }

二、使用 Spring 计时器 StopWatch

StopWatch是位于 org.springframework.util包下的一个工具类，通过它可方便的对程序部分代码进行计时(ns级别),可以很方便的计算出任务的耗时.
commons工具包下也有的实现可以直接使用 (org.apache.commons.lang3.time.StopWatch) ，功能差不多。

1、StopWatch使用

通过创建 StopWatch对象，然后调用它的start、stop方法来区分执行任务区间，基于 System.nanoTime()获得时间。 通过 getTotalTimeMillis()方法获得总耗时。

StopWatch的其他方法：

• prettyPrint()方法，可以优雅的打印出统计分析信息；
• getTotalTimeMillis()方法，打印出总耗时；
• getLastTaskName()方法，打印最后一个任务名称；
• getLastTaskInfo()方法，获得最后一个任务的TaskInfo，进而获得更多相关信息；
• getTaskCount()方法，获得任务数；

demo1：单业务模块使用

    public static void main(String[] args) throws InterruptedException { 
   
        StopWatch sw = new StopWatch("xx任务的耗时");

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

demo2：多业务模块使用

    public static void main(String[] args) throws InterruptedException { 
   
        StopWatch sw = new StopWatch("xx任务的耗时");
        
        sw.start("业务1");
        TimeUnit.SECONDS.sleep(2);
        sw.stop();

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

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

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

StopWatch优缺点：
优点：

• Spring自带工具类，可直接使用，代码实现简单，使用更简单
  通过多组start、stop方法，将业务代码块进行区分，可获得不同代码块的执行耗时
  统一归纳，展示每项任务耗时与占用总时间的百分比，展示结果直观。
• 性能消耗相对较小，并且最大程度的保证了start与stop之间的时间记录的准确性

缺点：

• 一个StopWatch实例一次只能开启一个task，start和stop要成对使用。若要一次开启多个
  task，需要new不同的StopWatch实例
• 代码侵入式使用，需要改动多处代码

2、Spring中StopWatch源码

该工具类中源码实现也极其简单，通过 start与stop方法分别记录开始时间与结束时间，其中在记录结束时间时，会维护一个链表类型的 tasklist属性，从而使该类可记录多个任务，最后的输出也仅仅是对之前记录的信息做了一个统一的归纳输出，从而使结果更加直观的展示出来。

• StopWatch也封装了一个记录任务名、结束时间操作的 TaskInfo内部类。
• 在 start方法中记录了任务名称和任务执行的时间，基于 System.nanoTime()获得时间。
• 在 stop方法中，通过两个时间戳相减获得 lastTime，也就是一个任务的执行时间；lastTime累计相加获得总的执行时间；同时记录任务列表、任务数统计。

StopWatch源码如下:

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

– 求知若饥，虚心若愚。