使用StopWatch查看程序执行时间（普通篇）

摘要: stopwatch 查看执行时间

在平时的开发调试工作中，时常会遇到程序执行效率非常慢，通过一般的经验只能判断出部分逻辑有问题，但判断并不直观且效率较低。这时我们就会用一些比较直观的方法来检查，比如看看某一段程序执行的时间，从而来判断是否比较耗时。比较常用的办法就是在程序开始时使用System.currentTimeMillis()记个时，然后再结束时计个时，再进行两个时间取差值就可以看出来了。

long stime =System.currentTimeMillis();
// ... 程序代码
long etime =System.currentTimeMillis();
System.out.println("执行时间:"+(etime-stime));

但这种方法较麻烦，且如果同时要观察多个代码执行程序，要写较多代码。故现在可以直接使用 org.springframework.util.StopWatch 类来帮我们统计时间。

它可以方便统计程序的每一段的执行时间，最后一起输出并显示每一个的时间占比情况。

public void run() throws Exception {
StopWatch stopWatch = new StopWatch("demo1");
stopWatch.start("step1");
step1();
stopWatch.stop();

stopWatch.start("step2");
step2();
stopWatch.stop();

stopWatch.start("step3");
step3();
stopWatch.stop();

System.out.println(stopWatch.prettyPrint());
}

private void step1() throws InterruptedException {
Thread.sleep(100L);
}

private void step2() throws InterruptedException {
Thread.sleep(850L);
}

private void step3() throws InterruptedException {
Thread.sleep(2000L);
}

输出结果：

StopWatch 'demo1': running time (millis) = 2972
-----------------------------------------
ms % Task name
-----------------------------------------
00108 004% step1
00861 029% step2
02003 067% step3

从结果看出总执行时间为2972ms，将每一步的进行时间和占比，这样我们就很容易可以排查哪一个程序段执行的效率了，用起来特别方便。

虽然现在的方法已经很强大了，也很容易使用，但也要写好多代码并对被观察的代码段入侵太大，观察完后也还要一行一行删除代码，下一篇文章将介绍stopwatch的注解式用法，观察代码更少，敬请期待。