前言
平常，我们想要统计某一段代码块，或某一个方法的执行时间，最简单的是采用如下的方式。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
|
package com.chenpi;/** * @author 陈皮 * @version 1.0 * @description * @date 2022/4/2 */public class ChenPi { public static void main(String[] args) throws InterruptedException { long startTime = System.currentTimeMillis(); Thread.sleep(1000); long endTime = System.currentTimeMillis(); System.out.println("执行耗时(ms):" + (endTime - startTime)); }}// 输出结果如下执行耗时(ms):1011 |
但如果我们想对多个代码段进行计时，以及每个阶段计时的占比等信息，如果还是采用如上的方式就会充斥比较多的与业务无关的代码，不够简洁。
Spring StopWatch
Spring 框架有个工具类 StopWatch，它可以用来对程序中代码块，或者方法进行计时，并且支持多阶段计时，以及阶段时间占比等统计，使用起来代码比较简洁，轻量。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
|
package com.chenpi;import org.springframework.util.StopWatch;/** * @author 陈皮 * @version 1.0 * @description * @date 2022/4/2 */public class ChenPi { public static void main(String[] args) throws InterruptedException { // 声明一个计时器 StopWatch stopWatch = new StopWatch("陈皮的计时器"); // 开始计时 stopWatch.start("发送MQ计时"); Thread.sleep(1000); // 结束计时 stopWatch.stop(); // 打印统计 System.out.println(stopWatch.prettyPrint()); }}// 输出结果如下StopWatch '陈皮的计时器': running time = 1005775500 ns---------------------------------------------ns % Task name---------------------------------------------1005775500 100% 发送MQ计时 |
Spring StopWatch 有以下几个常用方法：
- StopWatch()：构造一个计时器
- StopWatch(String id)：构造一个指定 id 的计时器
- start()：创建一个名为空字符串的计时任务，开始计时
- start(String taskName)：创建一个指定名称计时任务，开始计时
- stop()：结束当前任务的计时
- getTotalTimeNanos()：获取全部任务的执行时间，单位纳秒
- getTotalTimeMillis()：获取全部任务的执行时间，单位毫秒
- shortSummary()：获取简单的统计信息
- prettyPrint()：以友好方式输出总统计时间，以及各个阶段任务的执行时间
- setKeepTaskList(boolean keepTaskList)：是否在内部的列表中存储每一个任务
实践例子
当程序中有多个计时器时，可通过构造不同 id 的计时器来区分。以下演示多个不同计时器，统计不同阶段的执行时间。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
|
package com.chenpi;import org.springframework.util.StopWatch;/** * @author 陈皮 * @version 1.0 * @description * @date 2022/4/2 */public class ChenPi { public static void main(String[] args) throws InterruptedException { m1(); m2(); } private static void m1() throws InterruptedException { // 声明一个计时器 StopWatch stopWatch = new StopWatch("m1计时器"); stopWatch.start("查询数据库"); Thread.sleep(1000); stopWatch.stop(); stopWatch.start("逻辑计算"); Thread.sleep(500); stopWatch.stop(); System.out.println(stopWatch.prettyPrint()); } private static void m2() throws InterruptedException { // 声明一个计时器 StopWatch stopWatch = new StopWatch("m2计时器"); stopWatch.start("远程调用"); Thread.sleep(800); stopWatch.stop(); stopWatch.start("发送MQ"); Thread.sleep(200); stopWatch.stop(); System.out.println(stopWatch.prettyPrint()); }}// 输出结果如下StopWatch 'm1计时器': running time = 1516953200 ns---------------------------------------------ns % Task name---------------------------------------------1008091000 066% 查询数据库508862200 034% 逻辑计算StopWatch 'm2计时器': running time = 1013080000 ns---------------------------------------------ns % Task name---------------------------------------------809345900 080% 远程调用203734100 020% 发生MQ |
源码分析
其实 StopWatch 底层实现很简单，对于每一个任务，在任务开始和结束时刻调用System.*nanoTime*()方法获取服务器当前的时间，然后计算每一个任务的执行时间，存储在内部。内部使用一个列表存储不同任务阶段的执行时间，最后打印输出。
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
|
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 { // 计时器id private final String id; // 是否将任务存储到任务列表中 private boolean keepTaskList = true; // 存储全部任务的列表 private final List<TaskInfo> taskList = new ArrayList<>(1); // 当前任务开始时间 private long startTimeNanos; // 当前任务名称 @Nullable private String currentTaskName; // 最后一个任务 @Nullable private TaskInfo lastTaskInfo; // 总任务数 private int taskCount; // 总的执行时间 private long totalTimeNanos; // 构造一个id为空字符串的计时器 public StopWatch() { this(""); } // 构造一个指定id的计时器 public StopWatch(String id) { this.id = id; } // 获取计时器id public String getId() { return this.id; } public void setKeepTaskList(boolean keepTaskList) { this.keepTaskList = keepTaskList; } // 开始计时 public void start() throws IllegalStateException { start(""); } // 开始一个指定任务名称的计时 public void start(String taskName) throws IllegalStateException { if (this.currentTaskName != null) { throw new IllegalStateException("Can't start StopWatch: it's already running"); } 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"); } long lastTime = System.nanoTime() - this.startTimeNanos; this.totalTimeNanos += lastTime; this.lastTaskInfo = new 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"); } 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"); } 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 TaskInfo getLastTaskInfo() throws IllegalStateException { if (this.lastTaskInfo == null) { throw new IllegalStateException("No tasks run: can't get last task info"); } 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 TaskInfo[] getTaskInfo() { if (!this.keepTaskList) { throw new UnsupportedOperationException("Task info is not being kept!"); } return this.taskList.toArray(new TaskInfo[0]); } public String shortSummary() { return "StopWatch '" + getId() + "': running time = " + getTotalTimeNanos() + " ns"; } public String prettyPrint() { StringBuilder sb = new StringBuilder(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); for (TaskInfo task : getTaskInfo()) { sb.append(nf.format(task.getTimeNanos())).append(" "); sb.append(pf.format((double) task.getTimeNanos() / getTotalTimeNanos())).append(" "); sb.append(task.getTaskName()).append('\n'); } } return sb.toString(); } @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.getTimeNanos()).append(" ns"); long percent = Math.round(100.0 * task.getTimeNanos() / 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 duration / 1_000_000_000.0; } // 任务实体 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 nanosToMillis(this.timeNanos); } public double getTimeSeconds() { return nanosToSeconds(this.timeNanos); } }}复制代码 |
StopWatch 使用起来简洁，支持多任务阶段统计，统计多任务时间占比等，统计结果直观。但是它也有不好的地方，就是一个 StopWatch 实例只能同时 start 一个 task，只能等这个 task 进行 stop 之后，才能继续 start 另一个 task。注意，StopWatch 实例不是线程安全的，也没必要进行同步处理。
lang3 StopWatch
Apache commons lang3 包下也有一个用于计时工具类 StopWatch。它还有暂停计时，恢复计时，设置分割点等功能。
|
1
2
|
org.apache.commons:commons-lang3:3.12.0复制代码 |
它主要有以下几个常用方法：
- create()：实例化一个计时器
- createStarted()：实例化一个计时器，并开始计时
- StopWatch(final String message)：实例化一个带有标识符的计时器
- start()：开始计时
- split()：设置分割点
- getSplitTime()：统计从 start 开始最后一个分割点的用时
- reset()：重置计时
- suspend()：暂停计时
- resume()：恢复计时
- stop()：停止计时
- getTime()：统计从 start 到当前时刻的同时
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
|
package com.chenpi;import org.apache.commons.lang3.time.StopWatch;/** * @author 陈皮 * @version 1.0 * @description * @date 2022/4/2 */public class ChenPi { public static void main(String[] args) throws InterruptedException { // 声明一个计时器 StopWatch stopWatch = new StopWatch("m1计时器"); stopWatch.start(); Thread.sleep(1000); System.out.println("start开始到现在的时间：" + stopWatch.getTime()); stopWatch.split(); Thread.sleep(500); System.out.println("start开始到最后一个split的时间：" + stopWatch.getSplitTime()); stopWatch.split(); Thread.sleep(500); System.out.println("start开始到最后一个split的时间：" + stopWatch.getSplitTime()); // 重置计时 stopWatch.reset(); Thread.sleep(2000); stopWatch.start(); Thread.sleep(1000); System.out.println("start开始到现在的时间：" + stopWatch.getTime()); // 暂停计时 stopWatch.suspend(); Thread.sleep(3000); // 恢复计时 stopWatch.resume(); Thread.sleep(1000); // 结束计时 stopWatch.stop(); Thread.sleep(1000); System.out.println("start开始到stop结束的时间：" + stopWatch.getTime()); System.out.println(stopWatch); }}// 输出结果如下start开始到现在的时间：1000start开始到最后一个split的时间：1001start开始到最后一个split的时间：1510start开始到现在的时间：1004start开始到stop结束的时间：2015m1计时器 00:00:02.015 |
总结
- 如果是简单的计算执行计时，可以使用 JDK 自带的类获取系统时间进行计时。
- 如果需要多阶段计时，并且需要统计每个阶段的执行时间占比等信息，可以使用 StopWatch 工具类。
- 推荐使用 Spring StopWatch，因为本身我们项目使用 Spring 框架比较多，这样就自带了 StopWatch。
到此这篇关于Java计时器工具StopWatch的具体使用的文章就介绍到这了,更多相关Java计时器工具StopWatch内容请搜索服务器之家以前的文章或继续浏览下面的相关文章希望大家以后多多支持服务器之家！
原文链接：https://juejin.cn/post/7082191799682334727
