使用StopWatch来统计执行时间

一般项目里会遇到需要统计方法或者逻辑的执行时间，java一般是这么做的:

long startTime = System.currentTimeMillis();
//TO DO
long endTime = System.currentTimeMillis();
logger.debug("XX COST TIME : " + (endTime - startTime));

这样做有什么问题？

1. 很low

2. 多个时间段算来算去容易出错

3. 整理时间和局部时间等需要自己处理计算

目前有很多的工具类有此功能，比如Spring 提供的 StopWatch就非常简洁、清晰

引入也比较简单，目前springframework的core包就包含此工具类

下面看个示例：

// 创建一个 StopWatch 实例
StopWatch sw = new StopWatch("创建虚拟机流程");

// 开始计时
sw.start("虚拟机模板创建");
//虚拟机模板创建代码逻辑;
// 停止计时
sw.stop();
logger.debug("虚拟机模板创建耗时：{} ",sw.getLastTaskTimeMillis());

sw.start("镜像拷贝");
//镜像拷贝逻辑
sw.stop();
logger.debug("镜像拷贝耗时：{} ", sw.getLastTaskTimeMillis());

logger.debug("任务数量：{}，总耗时：{}", sw.getTaskCount(), sw.getTotalTimeSeconds());

总体的流程就是：

1. 先创建StopWatch对象

2. 开始计时

3. 内部业务逻辑

4. 结束计时

5. 获取结果

除了可以通过局部时间，还可以通过 sw.getTotalTimeSeconds() 获取总的耗时，先看下结果：

虚拟机模板创建好事耗时：1002ms.
镜像拷贝耗时：1105ms.
任务数量：2，总耗时：2.107820109s.

另外，StopWatch 还提供了一个  sw.prettyPrint()  方法供打印出漂亮的格式化结果：

StopWatch '创建虚拟机流程': running time = 2108529351 ns
---------------------------------------------
ns         %     Task name
---------------------------------------------
1004338467  048%  虚拟机模板创建
1104190884  052%  镜像拷贝

除了spring提供的StopWatch外，apache的common也提供了工具包等，单spring我们项目都有使用，这边就只介绍spring相关。

扩展：

1. Spring的StopWatch本质的还是使用System.nanoTime()来计时

2. StopWatch是非线程安全，需要考虑使用场景和使用方式

3. 若是为了做服务的方法执行统计，可以结合spring的面向切面方式进行。