StopWatch是Spring提供的工具类,可以统计分析线程执行的时间、占比情况。
含义源码分析可以参考:https://blog.csdn.net/sober_snail/article/details/120393440
StopWatch每次只能分析一个线程的执行情况,StopWatch提供API:
- isRunning(),当前是否有正在分析的线程
- start(),开始分析当前线程
- stop(),停止分析当前线程
- prettyPrint(),打印统计过的线程情况
StopWatch进行再封装:
import org.springframework.util.StopWatch;
import com.sf.nwms.core.util.common.LogTextHolder;
import com.sf.nwms.core.util.common.LogUtil;
import lombok.extern.slf4j.Slf4j;
@Slf4j
public class StopWatchUtil {
// 线程独有
private static final ThreadLocal<StopWatch> threadLocal = new ThreadLocal<StopWatch>() {
@Override
protected StopWatch initialValue() {
return new StopWatch("性能跟踪");
}
};
// 线程执行开始调用
public static void start(String tastName) {
try {
StopWatch stopWatch = threadLocal.get();
if (stopWatch.isRunning()) {
stopWatch.stop();
}
stopWatch.start(tastName);
} catch (Exception e) {
LogUtil.errorLog(log, () -> LogTextHolder.instance("exception occured during start:{}", e));
}
}
// 线程结束前调用
public static void stop() {
try {
StopWatch stopWatch = threadLocal.get();
if (stopWatch.isRunning()) {
stopWatch.stop();
}
} catch (Exception e) {
LogUtil.errorLog(log, () -> LogTextHolder.instance("exception occured during stop:{}", e));
}
}
// 打印各个线程的执行情况
public static void print() {
StopWatch stopWatch = threadLocal.get();
LogUtil.infoLog(log, () -> LogTextHolder.instance("性能耗时跟踪日志 = {}", stopWatch.prettyPrint()));
}
public static void main(String[] args) {
// StopWatch每次只能统计一个线程,执行完放到List中,print打印遍历所有线程执行信息
for (int i = 0; i < 4; i++) {
//调用Thread的currentThread()方法获取当前线程
int finalI = i;
Runnable test = new Runnable() {
@Override
public void run() {
StopWatchUtil.start("test1"+ finalI);
try {
Thread.sleep(10);
} catch (InterruptedException e) {
e.printStackTrace();
}
StopWatchUtil.stop();
StopWatchUtil.start("test2"+finalI);
try {
Thread.sleep(10);
} catch (InterruptedException e) {
e.printStackTrace();
}
StopWatchUtil.stop();
StopWatchUtil.print();
}
};
test.run();
}
}
}
执行结果:
10:48:45.867 [main] INFO StopWatchUtil - 性能耗时跟踪日志 = StopWatch '性能跟踪': running time (millis) = 40
-----------------------------------------
ms % Task name
-----------------------------------------
00025 062% test10
00015 038% test20
10:48:45.907 [main] INFO StopWatchUtil - 性能耗时跟踪日志 = StopWatch '性能跟踪': running time (millis) = 74
-----------------------------------------
ms % Task name
-----------------------------------------
00025 034% test10
00015 020% test20
00019 026% test11
00015 020% test21
10:48:45.939 [main] INFO StopWatchUtil - 性能耗时跟踪日志 = StopWatch '性能跟踪': running time (millis) = 106
-----------------------------------------
ms % Task name
-----------------------------------------
00025 024% test10
00015 014% test20
00019 018% test11
00015 014% test21
00016 015% test12
00016 015% test22
10:48:45.970 [main] StopWatchUtil - 性能耗时跟踪日志 = StopWatch '性能跟踪': running time (millis) = 136
-----------------------------------------
ms % Task name
-----------------------------------------
00025 018% test10
00015 011% test20
00019 014% test11
00015 011% test21
00016 012% test12
00016 012% test22
00015 011% test13
00015 011% test23