@Component
@Slf4j
public class ApiTimeMonitorInterceptor extends HandlerInterceptorAdapter {private ThreadLocal<Stopwatch> stopwatchThreadLocal = new NamedThreadLocal<>("api_time_monitor");//外部使用public long getElapsedMs() {Stopwatch stopwatch = stopwatchThreadLocal.get();return stopwatchThreadLocal.get().elapsed(TimeUnit.MILLISECONDS);}//接口调用时进入方法前拦截处理@Overridepublic boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)throws Exception {stopwatchThreadLocal.set(Stopwatch.createStarted());return true;}//处理完返回值后的其他处理@Overridepublic void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex)throws Exception {try {String t = TraceUtils.getT();String code = TraceUtils.getBStatusCode();if (StringUtils.isEmpty(t)) {t = QPitcherUtils.buildT(request.getServletPath());}if (StringUtils.contains(t, "healthcheck.html")) {return;}String realT = QPitcherUtils.buildT(request.getServletPath());Stopwatch stopwatch = stopwatchThreadLocal.get().stop();long timeSpend = stopwatch.elapsed(TimeUnit.MILLISECONDS);Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + "request_Total");Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, "request_Total"));Monitor.recordQuantile(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, t, "_Total"), timeSpend);if (StringUtils.isNotBlank(realT)) {Monitor.recordQuantile(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, realT, "_Total"), timeSpend);log.info("{}_Total:{} ms", realT, timeSpend);}if (StringUtils.isNotBlank(code)) {if (StringUtils.equals("0", code)) {Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + "request_Success");Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, "request_Success"));Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + t + "_Success");Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, t, "_Success"));if (StringUtils.isNotBlank(realT)) {Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + realT + "_Success");Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, realT, "_Success"));}} else {Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + "request_Fail");Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, "request_Fail"));Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + t + "_Fail");Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, t, "_Fail"));Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + t + "_Fail_" + code);Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, t, "_Fail_", code));if (StringUtils.isNotBlank(realT)) {Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + realT + "_Fail");Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, realT, "_Fail"));Monitor.recordOne(ApiLogAdvice.API_MONITOR_PREFIX + realT + "_Fail_" + code);Monitor.recordOne(MonitorLogUtil.join(ApiLogAdvice.API_MONITOR_PREFIX, realT, "_Fail_", code));}}}log.info("{}_Total:{} ms", t, timeSpend);} finally {stopwatchThreadLocal.remove();TraceUtils.endTrace();}}
}
stopwatchThreadLocal 的使用方式
@ControllerAdvice
@Slf4j
public class ApiLogAdvice implements ResponseBodyAdvice {@Resourceprivate ApiTimeMonitorInterceptor apiTimeMonitorInterceptor;static final String API_MONITOR_PREFIX = "api_monitor_";private static final Logger RECOMMEND_LOGGER = LoggerFactory.getLogger("11111");@Overridepublic boolean supports(MethodParameter returnType, Class converterType) {return true;}@Overridepublic Object beforeBodyWrite(Object body, MethodParameter returnType, MediaType selectedContentType,Class selectedConverterType, ServerHttpRequest request, ServerHttpResponse response) {if (body instanceof ResponseVO) {ResponseVO responseVO = (ResponseVO) body;responseVO.setTraceId(String.valueOf(TraceUtils.getValue("qtraceid")));TraceUtils.setBStatusCode(String.valueOf(responseVO.getBstatus().getCode()));handleReturnValue(responseVO, request);String t = TraceUtils.getT();String realT = StringUtils.EMPTY;String servletPath = request.getURI().getPath();if (StringUtils.isNotBlank(servletPath)) {realT = QPitcherUtils.buildT(servletPath);}Monitor.recordOne(API_MONITOR_PREFIX + t + "_request");Monitor.recordOne(MonitorLogUtil.join(API_MONITOR_PREFIX, t, "_request"));if (StringUtils.isNotBlank(realT)) {Monitor.recordOne(API_MONITOR_PREFIX + realT + "_request");Monitor.recordOne(MonitorLogUtil.join(API_MONITOR_PREFIX, realT, "_request"));}}return body;}/*** 记录业务日志** @param responseVO*/private void handleReturnValue(ResponseVO responseVO, ServerHttpRequest request) {String resJson = JsonUtil.toJson(responseVO);RECOMMEND_LOGGER.info("time={}####uri={}####param={}####result:{}",apiTimeMonitorInterceptor.getElapsedMs(), request.getURI().getPath().replace("/", "_"),TraceUtils.getRequestParam(), resJson);Monitor.recordQuantile("handleReturnValue_time", apiTimeMonitorInterceptor.getElapsedMs());}
}
apiTimeMonitorInterceptor.getElapsedMs() 时发生空指针异常
排查路径:
1、确认调用 getElapsedMs 方法时位于 preHandle 方法和 afterCompletion 方法之间,
因为preHandle时setstart,再获取时先确认已经放入stopwatchThreadLocal 了
其次afterCompletion 有对stopwatchThreadLocal 的remove操作,因此需要确认是否再获取前被移除了
排查结果:确认调用 getElapsedMs 方法时位于 preHandle 方法和 afterCompletion 方法之间没有问题
2、调用时的线程是否再同一个线程内
排查结果:id都是38.但仍然无法获取到正确的 Stopwatch 实例
3、确认下拦截器的使用方式,时注入还是其他。以及所有涉及到改拦截器的配置
a、确认直接调用放是否时注入
b、确认拦截器配置是否是注入方式
排查解决:再配置拦截器的addInterceptors 方式里 使用的是new ApiTimeMonitorInterceptor ,改为注入方式
@Configuration
public class WebAdapter implements WebMvcConfigurer {@Resource(name = "apiTimeMonitorInterceptor")private ApiTimeMonitorInterceptor apiTimeMonitorInterceptor;/*** 拦截器注册* @param registry*/@Overridepublic void addInterceptors(InterceptorRegistry registry) {//众多的拦截器组成了一个拦截器链/*** 主要方法说明:* addPathPatterns 用于添加拦截规则* excludePathPatterns 用户排除拦截*/registry.addInterceptor(apiTimeMonitorInterceptor).addPathPatterns("/api/**").excludePathPatterns("/");}}
问题解决,感谢观看