用 Spring StopWatch 做方法级别耗时统计 + 支持回调写法 + 自动打印日志
javaString result = StopWatchUtil.time("查询用户信息", () -> {});javaStopWatchUtil.time("发送MQ消息", () -> {});java[StopWatch] 查询用户信息 耗时: 132 ms。
一、目标效果
我们希望这样用：
javaString result = StopWatchUtil.time("查询用户信息", () -> {
return userService.getUser(userId);
});
或者无返回值：
javaStopWatchUtil.time("发送MQ消息", () -> {
mqService.send(msg);
});
自动打印：
java[StopWatch] 查询用户信息 耗时: 132 ms
二、简单的工具类封装
javapackage com.xxx.common.util;
import org.springframework.util.StopWatch;
import java.util.function.Supplier;
public class StopWatchUtil {
/**
* 有返回值的计时
*/
public static <T> T time(String taskName, Supplier<T> supplier) {
StopWatch stopWatch = new StopWatch(taskName);
stopWatch.start();
try {
return supplier.get();
} finally {
stopWatch.stop();
log(stopWatch);
}
}
/**
* 无返回值的计时
*/
public static void time(String taskName, Runnable runnable) {
StopWatch stopWatch = new StopWatch(taskName);
stopWatch.start();
try {
runnable.run();
} finally {
stopWatch.stop();
log(stopWatch);
}
}
private static void log(StopWatch stopWatch) {
System.out.println(String.format(
"[StopWatch] %s 耗时: %d ms",
stopWatch.getId(),
stopWatch.getTotalTimeMillis()
));
}
}
三、增强版（支持嵌套分段统计）
如果你想像下面这样分段统计：
javaStopWatchUtil.multi("下单流程", watch -> {
watch.run("校验参数", () -> validate());
watch.run("库存扣减", () -> deductStock());
watch.run("生成订单", () -> createOrder());
});
那我们可以再封一层：
javapackage com.xxx.common.util;
import org.springframework.util.StopWatch;
import java.util.function.Consumer;
public class StopWatchUtil {
public static void multi(String taskName, Consumer<StopWatchWrapper> consumer) {
StopWatch stopWatch = new StopWatch(taskName);
StopWatchWrapper wrapper = new StopWatchWrapper(stopWatch);
stopWatch.start("total");
try {
consumer.accept(wrapper);
} finally {
stopWatch.stop();
System.out.println(stopWatch.prettyPrint());
}
}
public static class StopWatchWrapper {
private final StopWatch stopWatch;
public StopWatchWrapper(StopWatch stopWatch) {
this.stopWatch = stopWatch;
}
public void run(String taskName, Runnable runnable) {
stopWatch.start(taskName);
try {
runnable.run();
} finally {
stopWatch.stop();
}
}
}
}
这段代码执行报下面这个错误 Exception in thread "main" java.lang.IllegalStateException: Can't start StopWatch: it's already running
问题根源
Spring 的 StopWatch 一次只能有一个 task 在运行（start() 时如果已经在 running 就会抛 IllegalStateException: Can't start StopWatch: it's already running）。
你现在的 multi(...) + 嵌套 watch.run(...) 的写法正好违背了这一点： 外层 run 还没 stop()，内层就又 start() 了 → 报错。
解决方案
在每次启动子任务前，如果当前有正在运行的任务（即父任务），就先 stop() 它（实现“暂停”），执行完子任务后再 start() 恢复父任务。 这样既能支持任意层级的嵌套，又不会改变原有的耗时统计逻辑和 prettyPrint() 输出格式。
修改后的完整 StopWatchWrapper
java/**
* StopWatch 包装类。
*
* <p>支持分段执行与任意层级嵌套统计（通过暂停/恢复父任务实现）。</p>
*/
public static class StopWatchWrapper {
private final StopWatch stopWatch;
private final Deque<String> taskStack = new ArrayDeque<>();
private StopWatchWrapper(StopWatch stopWatch) {
this.stopWatch = stopWatch;
}
/**
* 执行一个无返回值的分段任务（支持嵌套）。
*/
public void run(String taskName, Runnable runnable) {
String fullTaskName = buildNestedName(taskName);
execute(fullTaskName, () -> {
runnable.run();
return null;
});
}
/**
* 执行一个有返回值的分段任务（支持嵌套）。
*/
public <T> T run(String taskName, Supplier<T> supplier) {
String fullTaskName = buildNestedName(taskName);
return execute(fullTaskName, supplier);
}
/**
* 核心：带「暂停/恢复」机制的嵌套执行逻辑
* （解决 Spring StopWatch 不能同时运行多个 task 的问题）
*/
private <T> T execute(String fullTaskName, Supplier<T> supplier) {
// 1. 如果当前有父任务正在运行，先暂停它
boolean wasRunning = stopWatch.isRunning();
String pausedName = wasRunning ? stopWatch.currentTaskName() : null;
if (wasRunning) {
stopWatch.stop();
}
// 2. 启动当前任务
stopWatch.start(fullTaskName);
taskStack.push(fullTaskName);
try {
return supplier.get();
} finally {
// 3. 结束当前任务
stopWatch.stop();
taskStack.pop();
// 4. 如果之前有暂停的父任务，恢复它
if (wasRunning) {
stopWatch.start(pausedName);
}
}
}
/**
* 构建带缩进的嵌套任务名称（保持原来的树状视觉效果）
*/
private String buildNestedName(String taskName) {
int depth = taskStack.size();
StringBuilder prefix = new StringBuilder();
for (int i = 0; i < depth; i++) {
prefix.append(" ");
}
return prefix + taskName;
}
}
四、进行测试
测试代码
javapackage com.mmusic.common.core.util;
public class StopWatchUtilTest {
public static void main(String[] args) {
// ----------------------------
// 1️⃣ 单方法计时（有返回值）
// ----------------------------
String result = StopWatchUtil.time("获取字符串任务", () -> {
try {
Thread.sleep(100); // 模拟耗时
} catch (InterruptedException e) {
e.printStackTrace();
}
return "Hello StopWatch";
});
System.out.println("返回值: " + result);
// ----------------------------
// 2️⃣ 单方法计时（无返回值）
// ----------------------------
StopWatchUtil.time("打印日志任务", () -> {
try {
Thread.sleep(50); // 模拟耗时
System.out.println("任务执行完成");
} catch (InterruptedException e) {
e.printStackTrace();
}
});
// ----------------------------
// 3️⃣ 多段分段统计
// ----------------------------
StopWatchUtil.multi("下单流程", watch -> {
watch.run("参数校验", () -> {
try { Thread.sleep(60); } catch (InterruptedException ignored) {}
});
watch.run("库存扣减", () -> {
try { Thread.sleep(80); } catch (InterruptedException ignored) {}
});
watch.run("生成订单", () -> {
try { Thread.sleep(100); } catch (InterruptedException ignored) {}
});
});
// ----------------------------
// 4️⃣ 嵌套分段统计
// ----------------------------
StopWatchUtil.multi("支付流程", watch -> {
watch.run("参数校验", () -> {
try { Thread.sleep(50); } catch (InterruptedException ignored) {}
});
watch.run("远程调用", () -> {
watch.run("调用账户服务", () -> {
try { Thread.sleep(70); } catch (InterruptedException ignored) {}
});
watch.run("调用积分服务", () -> {
try { Thread.sleep(90); } catch (InterruptedException ignored) {}
});
});
});
}
}
打印效果示例
java15:03:55.002 [main] INFO com.mmusic.common.core.util.StopWatchUtil -- [StopWatch] 获取字符串任务 耗时: 100 ms
返回值: Hello StopWatch
任务执行完成
15:03:55.062 [main] INFO com.mmusic.common.core.util.StopWatchUtil -- [StopWatch] 打印日志任务 耗时: 53 ms
15:03:55.329 [main] INFO com.mmusic.common.core.util.StopWatchUtil --
StopWatch '下单流程': 0.2610164 seconds
----------------------------------------
Seconds % Task name
----------------------------------------
0.06122 23% 参数校验
0.0920423 35% 库存扣减
0.1077541 41% 生成订单
15:03:55.559 [main] INFO com.mmusic.common.core.util.StopWatchUtil --
StopWatch '支付流程': 0.2275085 seconds
----------------------------------------
Seconds % Task name
----------------------------------------
0.0567488 25% 参数校验
0.0003864 00% 远程调用
0.076972 34% 调用账户服务
0.0005038 00% 远程调用
0.0928946 41% 调用积分服务
0.0000029 00% 远程调用
五、最终完整代码（增强 + 嵌套 + 详细注释）
生产可用版本的完整代码，包含：
- ✅ 单方法计时（支持返回值）
- ✅ 单方法计时（无返回值）
- ✅ 增强版：支持多段统计
- ✅ 支持嵌套分段统计（树状结构）
- ✅ 线程安全（每次调用独立 StopWatch）
- ✅ 详细注释（包含使用示例）
javapackage com.mmusic.common.core.util;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.util.StopWatch;
import java.util.ArrayDeque;
import java.util.Deque;
import java.util.function.Consumer;
import java.util.function.Supplier;
/**
* 工具类：StopWatchUtil
*
* <p>
* 基于 Spring {@link StopWatch} 的增强封装工具，
* 支持：
* </p>
*
* <ul>
* <li>单方法耗时统计</li>
* <li>多段分段统计</li>
* <li>嵌套分段统计（树状结构）</li>
* </ul>
*
* <p>适用场景：</p>
* <ul>
* <li>Controller 接口耗时分析</li>
* <li>Service 分段性能排查</li>
* <li>复杂业务流程耗时统计</li>
* </ul>
*
* @author
* @since 1.0
*/
public final class StopWatchUtil {
private static final Logger log = LoggerFactory.getLogger(StopWatchUtil.class);
private StopWatchUtil() {
// 工具类禁止实例化
}
/**
* 对有返回值的方法进行耗时统计。
*
* <p>使用示例：</p>
*
* <pre>
* String result = StopWatchUtil.time("查询用户", () -> {
* return userService.getUser(userId);
* });
* </pre>
*
* @param taskName 任务名称
* @param supplier 需要执行的业务逻辑
* @param <T> 返回值类型
* @return 业务执行结果
*/
public static <T> T time(String taskName, Supplier<T> supplier) {
StopWatch stopWatch = new StopWatch(taskName);
stopWatch.start();
try {
return supplier.get();
} finally {
stopWatch.stop();
log.info("[StopWatch] {} 耗时: {} ms",
stopWatch.getId(),
stopWatch.getTotalTimeMillis());
}
}
/**
* 对无返回值的方法进行耗时统计。
*
* <p>使用示例：</p>
*
* <pre>
* StopWatchUtil.time("发送MQ", () -> {
* mqService.send(msg);
* });
* </pre>
*
* @param taskName 任务名称
* @param runnable 需要执行的业务逻辑
*/
public static void time(String taskName, Runnable runnable) {
StopWatch stopWatch = new StopWatch(taskName);
stopWatch.start();
try {
runnable.run();
} finally {
stopWatch.stop();
log.info("[StopWatch] {} 耗时: {} ms",
stopWatch.getId(),
stopWatch.getTotalTimeMillis());
}
}
/**
* 对一个完整业务流程进行多段统计（支持嵌套）。
*
* <p>使用示例：</p>
*
* <pre>
* StopWatchUtil.multi("下单流程", watch -> {
* watch.run("参数校验", () -> validate());
* watch.run("库存扣减", () -> deductStock());
* watch.run("生成订单", () -> createOrder());
* });
* </pre>
*
* <p>嵌套示例：</p>
*
* <pre>
* StopWatchUtil.multi("支付流程", watch -> {
* watch.run("远程调用", () -> {
* watch.run("调用账户服务", () -> accountService.call());
* watch.run("调用积分服务", () -> pointService.call());
* });
* });
* </pre>
*
* @param taskName 流程名称
* @param consumer 回调函数
*/
public static void multi(String taskName, Consumer<StopWatchWrapper> consumer) {
StopWatch stopWatch = new StopWatch(taskName);
StopWatchWrapper wrapper = new StopWatchWrapper(stopWatch);
try {
consumer.accept(wrapper);
} finally {
log.info("\n{}", stopWatch.prettyPrint());
}
}
/**
* StopWatch 包装类。
*
* <p>支持分段执行与任意层级嵌套统计（通过暂停/恢复父任务实现）。</p>
*/
public static class StopWatchWrapper {
private final StopWatch stopWatch;
private final Deque<String> taskStack = new ArrayDeque<>();
private StopWatchWrapper(StopWatch stopWatch) {
this.stopWatch = stopWatch;
}
/**
* 执行一个无返回值的分段任务（支持嵌套）。
*/
public void run(String taskName, Runnable runnable) {
String fullTaskName = buildNestedName(taskName);
execute(fullTaskName, () -> {
runnable.run();
return null;
});
}
/**
* 执行一个有返回值的分段任务（支持嵌套）。
*/
public <T> T run(String taskName, Supplier<T> supplier) {
String fullTaskName = buildNestedName(taskName);
return execute(fullTaskName, supplier);
}
/**
* 核心：带「暂停/恢复」机制的嵌套执行逻辑
* （解决 Spring StopWatch 不能同时运行多个 task 的问题）
*/
private <T> T execute(String fullTaskName, Supplier<T> supplier) {
// 1. 如果当前有父任务正在运行，先暂停它
boolean wasRunning = stopWatch.isRunning();
String pausedName = wasRunning ? stopWatch.currentTaskName() : null;
if (wasRunning) {
stopWatch.stop();
}
// 2. 启动当前任务
stopWatch.start(fullTaskName);
taskStack.push(fullTaskName);
try {
return supplier.get();
} finally {
// 3. 结束当前任务
stopWatch.stop();
taskStack.pop();
// 4. 如果之前有暂停的父任务，恢复它
if (wasRunning) {
stopWatch.start(pausedName);
}
}
}
/**
* 构建带缩进的嵌套任务名称（保持原来的树状视觉效果）
*/
private String buildNestedName(String taskName) {
int depth = taskStack.size();
StringBuilder prefix = new StringBuilder();
for (int i = 0; i < depth; i++) {
prefix.append(" ");
}
return prefix + taskName;
}
}
}
原文链接：https://juejin.cn/post/7610305771625726003
腾讯云面向开发者汇聚海量精品云计算使用和开发经验，营造开放的云计算技术生态圈。
更多推荐
8
0- 0
已为社区贡献4条内容
所有评论(0)