记录一次stopwatchThreadLocal为空的问题及解法

@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);
    }

    //接口调用时进入方法前拦截处理
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler)
            throws Exception {
        stopwatchThreadLocal.set(Stopwatch.createStarted());
        return true;
    }
    //处理完返回值后的其他处理
    @Override
    public 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 {

    @Resource
    private ApiTimeMonitorInterceptor apiTimeMonitorInterceptor;

    static final String API_MONITOR_PREFIX = "api_monitor_";

    private static final Logger RECOMMEND_LOGGER = LoggerFactory.getLogger("11111");

    @Override
    public boolean supports(MethodParameter returnType, Class converterType) {
        return true;
    }

    @Override
    public 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
     */
    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        //众多的拦截器组成了一个拦截器链
        /**
         * 主要方法说明：
         * addPathPatterns 用于添加拦截规则
         * excludePathPatterns 用户排除拦截
         */
        registry.addInterceptor(apiTimeMonitorInterceptor).addPathPatterns("/api/**").excludePathPatterns("/");

    }

}

问题解决，感谢观看