线程级耗时统计工具类TimeWatcher

先看效果

假设我们的业务代码逻辑是这样的

那么最终的日志打印效果为（注：此为美化输出，也可设置为常规一行输出，还可自定义）

2024-11-08T23:48:53.390+08:00  INFO 31472 --- [nio-8080-exec-1] c.i.c.filter.TimeWatcherFilter           : consume time -> 
1....................................987ms @ request-uri -> /user-info
|--1.1...............................964ms @ TestController#userInfo
|--|--1.1.1..........................961ms @ 查询用户
|--|--|--1.1.1.1.....................158ms @ 查询用户基本信息
|--|--|--1.1.1.2......................84ms @ 查询用户安全信息
|--|--|--1.1.1.3.....................171ms @ 查询用户拥有的角色
|--|--|--1.1.1.4.....................206ms @ 根据角色查询api权限
|--|--|--|--1.1.1.4.1.................53ms @ 查询角色关联的菜单
|--|--|--|--1.1.1.4.2................152ms @ 查询菜单关联的api权限
|--|--|--1.1.1.5.....................125ms @ 查询用户直接关联的api权限
|--|--|--1.1.1.6.....................156ms @ 组装数据
|--|--|--1.1.1.7......................56ms @ 加密数据

工具类获取方式一：使用作者的常用工具包

提示：如果你不想引入作者的工具包，那么你可以直接看获取方式二

第一步：引入作者的常用工具包

<!-- 作者常用工具包 -->
<dependency><groupId>com.idea-aedi</groupId><artifactId>common-spring</artifactId><version>2100.10.7.LTS17</version> <!--jdk17--><!--<version>2100.10.7.LTS8</version>--> <!--jdk8-->
</dependency><!-- aop（因为作者还封装了个注解进行支持，要用注解的话需要引入aop） -->
<dependency><groupId>org.springframework.boot</groupId><artifactId>spring-boot-starter-aop</artifactId>
</dependency>

第二步：启用耗时统计器

/*** 开启耗时监控* <pre>* 注：默认情况下，会：*    1.对所有被{@link WatchTime}注解标注的方法进行耗时统计*    2.对所有Controller类下的方法进行耗时统计*    *    当然这些你都可以在这里通过指定{@link TimeWatcher}注解的相关属性来进行修改* </pre>*/
@EnableFeature(enableTimeWatcher = @TimeWatcher 
)
@SpringBootApplication
public class StartUp {public static void main(String[] args) {SpringApplication.run(StartUp.class, args);}
}

第三步：使用耗时器统计器

使用方式一：通过注解（示例）

 @WatchTime(taskName = "查询用户拥有的角色")public Collection<Long> queryRole(Long userId) {...}

使用方式二：使用工具类（示例）

// 示例一
try {WatchTimeUtil.start("查询用户基本信息");mockLogic();
} finally {WatchTimeUtil.stop();
}// 示例二
WatchTimeUtil.voidWatch("查询用户安全信息", () -> mockLogic()); // 方法无返回值
//Object returnVal = WatchTimeUtil.watch("查询用户安全信息", () -> mockLogic()); // 方法有返回值

获取方式二：直接使用工具类

第一步：复制此核心工具类进自己的项目

import com.alibaba.fastjson2.JSON;
import org.apache.commons.lang3.StringUtils;import javax.annotation.Nonnull;
import java.util.ArrayList;
import java.util.LinkedList;
import java.util.List;
import java.util.Objects;
import java.util.function.Consumer;
import java.util.function.Function;/*** 耗时统计工具** @author <font size = "20" color = "#3CAA3C"><a href="https://gitee.com/JustryDeng">JustryDeng</a></font> <img* src="https://gitee.com/JustryDeng/shared-files/raw/master/JustryDeng/avatar.jpg" />* @since 2100.10.7.LTS17*/
public final class WatchTimeUtil {/** 初始化标识 */private static final ThreadLocal<Boolean> initThreadLocal = ThreadLocal.withInitial(() -> false);/** 存放执行中任务的ThreadLocal */private static final ThreadLocal<LinkedList<TaskInfo>> runningTaskThreadLocal = new ThreadLocal<>();/** 存放已结束任务的ThreadLocal */private static final ThreadLocal<LinkedList<TaskInfo>> endTaskThreadLocal = new ThreadLocal<>();/** 存放最大序号的ThreadLocal */private static final ThreadLocal<String> maxTaskNoThreadLocal = new ThreadLocal<>();/*** 管理器*/public static class Manager {/*** 初始化*/public static void init() {if (initThreadLocal.get()) {throw new IllegalStateException("It has already been initialized, please do not initialize it repeatedly.");}initThreadLocal.set(true);runningTaskThreadLocal.set(new LinkedList<>());endTaskThreadLocal.set(new LinkedList<>());}/*** 初始化*/public static void initSilence() {if (initThreadLocal.get()) {return;}initThreadLocal.set(true);runningTaskThreadLocal.set(new LinkedList<>());endTaskThreadLocal.set(new LinkedList<>());}/*** 所有耗时统计任务当前是否都已结束*/public static boolean currIsEnd() {LinkedList<TaskInfo> list = runningTaskThreadLocal.get();return list == null || list.size() == 0;}/*** 获取已完成的任务集合*/public static List<TaskInfo> getEndTaskList() {return new ArrayList<>(endTaskThreadLocal.get());}/*** 获取进行中的任务集合*/public static List<TaskInfo> getIngTaskList() {return new ArrayList<>(runningTaskThreadLocal.get());}/*** 清空*/public static void clear() {runningTaskThreadLocal.remove();endTaskThreadLocal.remove();maxTaskNoThreadLocal.remove();initThreadLocal.remove();}/*** 获取下一个执行序号*/public static String nextNo() {TaskInfo taskInfo = runningTaskThreadLocal.get().peekFirst();String maxNo = maxTaskNoThreadLocal.get();String nextNo;if (taskInfo == null) {if (maxNo == null) {nextNo = "1";} else {nextNo = String.valueOf(Long.parseLong(maxNo.split("\\.")[0]) + 1);}} else {Objects.requireNonNull(maxNo, "maxNo should not be null.");String parentNo = taskInfo.getTaskNo();String[] parentNoArr = parentNo.split("\\.");String[] maxNoArr = maxNo.split("\\.");long subNo;if (maxNoArr.length > parentNoArr.length) {subNo = Long.parseLong(maxNoArr[parentNoArr.length]) + 1;} else {subNo = 1;}nextNo = parentNo + "." + subNo;}return nextNo;}/*** 按照任务序号排序*/public static void sortByTaskNo(List<TaskInfo> taskInfoList) {if (taskInfoList == null) {return;}taskInfoList.sort((x, y) -> {String xNo = x.getTaskNo();String yNo = y.getTaskNo();String[] xNoArr = xNo.split("\\.");String[] yNoArr = yNo.split("\\.");int minLength = Math.min(xNoArr.length, yNoArr.length);for (int i = 0; i < minLength; i++) {long xVal = Long.parseLong(xNoArr[i]);long yVal = Long.parseLong(yNoArr[i]);if (xVal < yVal) {return -1;}if (xVal > yVal) {return 1;}}return Integer.compare(xNoArr.length, yNoArr.length);});}/*** 耗时信息*/public static String prettyResult(@Nonnull List<TaskInfo> endTaskList) {StringBuilder sb = new StringBuilder();int size = endTaskList.size();if (size == 0) {sb.append("no tasks time info.");return sb.toString();}if (size == 1) {TaskInfo taskInfo = endTaskList.get(0);long consumeMilli = (taskInfo.getEndTime() - taskInfo.getStartTime()) / 1000000;return consumeMilli + "ms @ " + taskInfo.getTaskName();}Manager.sortByTaskNo(endTaskList);for (TaskInfo taskInfo : endTaskList) {String no = taskInfo.getTaskNo();String[] noArr = no.split("\\.");sb.append("\n");sb.append(StringUtils.rightPad("|--".repeat(Math.max(0, noArr.length - 1)) + no, 34, "."));long consumeMilli = (taskInfo.getEndTime() - taskInfo.getStartTime()) / 1000000;sb.append(StringUtils.leftPad(consumeMilli + "", 6, ".")).append("ms").append(" @ ").append(taskInfo.getTaskName());}return sb.toString();}/*** 耗时信息*/public static String result(@Nonnull List<TaskInfo> endTaskList) {int size = endTaskList.size();if (size == 0) {return "no tasks time info.";}if (size == 1) {TaskInfo taskInfo = endTaskList.get(0);long consumeMilli = (taskInfo.getEndTime() - taskInfo.getStartTime()) / 1000000;return consumeMilli + "ms @ " + taskInfo.getTaskName();}Manager.sortByTaskNo(endTaskList);List<String> list = new ArrayList<>();for (TaskInfo taskInfo : endTaskList) {StringBuilder sb = new StringBuilder();String no = taskInfo.getTaskNo();sb.append("taskNo: ");sb.append(no);sb.append(", ");long consumeMilli = (taskInfo.getEndTime() - taskInfo.getStartTime()) / 1000000;sb.append("consumeTime: ");sb.append(consumeMilli).append("ms, ").append("taskName: ").append(taskInfo.getTaskName());list.add(sb.toString());}return JSON.toJSONString(list);}}/*** 开始统计* <pre>* 若计时器尚未初始化，则会静默忽略当前操作* </pre>** @param taskName 任务名*/public static void start(String taskName) {if (!initThreadLocal.get()) {return;}TaskInfo taskInfo = new TaskInfo();String no = Manager.nextNo();taskInfo.setTaskNo(no);taskInfo.setTaskName(taskName);taskInfo.setStartTime(System.nanoTime());runningTaskThreadLocal.get().addFirst(taskInfo);maxTaskNoThreadLocal.set(no);}/*** 结束统计* <pre>* 若计时器尚未初始化，则会静默忽略当前操作* </pre>*/public static void stop() {if (!initThreadLocal.get()) {return;}LinkedList<TaskInfo> runningTaskDeque = runningTaskThreadLocal.get();if (runningTaskDeque.size() == 0) {return;}TaskInfo taskInfo = runningTaskDeque.pollFirst();taskInfo.setEndTime(System.nanoTime());endTaskThreadLocal.get().addLast(taskInfo);}/*** 执行** @param taskName 任务名* @param function 业务逻辑块* @param param 参数** @return 逻辑执行结果*/public static <P, R> R watch(@Nonnull String taskName, Function<P, R> function, P param) {try {start(taskName);return function.apply(param);} finally {stop();}}/*** 执行** @param taskName 任务名* @param function 业务逻辑块** @return 执行结果*/public static <R> R watch(@Nonnull String taskName, InnerNoArgFunction<R> function) {try {start(taskName);return function.apply();} finally {stop();}}/*** 执行** @param taskName 任务名* @param consumer 业务逻辑块* @param param 参数*/public static <P> void voidWatch(@Nonnull String taskName, Consumer<P> consumer, P param) {try {start(taskName);consumer.accept(param);} finally {stop();}}/*** 执行** @param taskName 任务名* @param consumer 业务逻辑块*/public static void voidWatch(@Nonnull String taskName, InnerNoArgConsumer consumer) {try {start(taskName);consumer.accept();} finally {stop();}}/*** 耗时信息*/public static String prettyResult() {if (!initThreadLocal.get()) {throw new IllegalStateException("Not initialized yet. You could do it by 'TimeWatchUtil.Manager.init()', "+ "and don't forget to clear him last by 'TimeWatchUtil.Manager.clear()'");}if (!Manager.currIsEnd()) {throw new IllegalStateException("There are also running tasks. " + Manager.getIngTaskList());}List<TaskInfo> endTaskList = Manager.getEndTaskList();return Manager.prettyResult(endTaskList);}/*** 耗时信息*/public static String result() {if (!initThreadLocal.get()) {throw new IllegalStateException("Not initialized yet. You could do it by 'TimeWatchUtil.Manager.init()', "+ "and don't forget to clear him last by 'TimeWatchUtil.Manager.clear()'");}if (!Manager.currIsEnd()) {throw new IllegalStateException("There are also running tasks. " + Manager.getIngTaskList());}List<TaskInfo> endTaskList = Manager.getEndTaskList();return Manager.result(endTaskList);}/*** 任务信息*/public static class TaskInfo {/** 执行序号（格式形如：xxx.xxx.xxx） */private String taskNo;/** 任务名 */private String taskName;/** 开始时间（纳秒） */private long startTime;/** 结束时间（纳秒） */private long endTime;public String getTaskNo() {return taskNo;}public void setTaskNo(String taskNo) {this.taskNo = taskNo;}public String getTaskName() {return taskName;}public void setTaskName(String taskName) {this.taskName = taskName;}public long getStartTime() {return startTime;}public void setStartTime(long startTime) {this.startTime = startTime;}public long getEndTime() {return endTime;}public void setEndTime(long endTime) {this.endTime = endTime;}@Overridepublic String toString() {return "TaskInfo{" +"no='" + taskNo + '\'' +", taskName='" + taskName + '\'' +", startTime=" + startTime +", endTime=" + endTime +'}';}}/*** (non-javadoc)*/@FunctionalInterfacepublic interface InnerNoArgFunction<R> {R apply();}/*** (non-javadoc)*/@FunctionalInterfacepublic interface InnerNoArgConsumer {void accept();}}

第二步：配置总开关过滤器（示例）

@Component
public class TimeWatcherDemoFilter implements Filter {private final boolean prettyResult = true;@Overridepublic void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException,ServletException {HttpServletRequest httpServletRequest = null;if (request instanceof HttpServletRequest) {httpServletRequest = (HttpServletRequest)request;}try {WatchTimeUtil.Manager.init();String requestUri = "";if (httpServletRequest != null) {requestUri = httpServletRequest.getRequestURI();}WatchTimeUtil.start("request-uri -> " + requestUri);chain.doFilter(request, response);} finally {try {WatchTimeUtil.stop();if (log.isInfoEnabled()) {log.info("consume time -> {}", prettyResult ? WatchTimeUtil.prettyResult() : WatchTimeUtil.result());}} catch (Exception e) {log.warn("WatchTimeUtil.stop occur exception. e.getMessage() -> {}", e.getMessage());}WatchTimeUtil.Manager.clear();}}
}

第三步（可选）：自定义aop注解

// 这里仅给出切面类核心逻辑demotry {String taskName;if (useDefaultAnnoValue || StringUtils.isBlank(annotation.value())) {taskName = clazzSimpleName + "#" + methodName;} else {taskName = annotation.value();}WatchTimeUtil.start(taskName);obj = methodInvocation.proceed();} finally {WatchTimeUtil.stop();}

第四步：使用耗时器统计器

使用方式一：通过注解（假设你自定义的注解名为@WatchTime）

 @WatchTime(taskName = "查询用户拥有的角色")public Collection<Long> queryRole(Long userId) {...}

使用方式二：使用工具类（示例）

// 示例一
try {WatchTimeUtil.start("查询用户基本信息");mockLogic();
} finally {WatchTimeUtil.stop();
}// 示例二
WatchTimeUtil.voidWatch("查询用户安全信息", () -> mockLogic()); // 方法无返回值
//Object returnVal = WatchTimeUtil.watch("查询用户安全信息", () -> mockLogic()); // 方法有返回值