NullPointerException日志丢失MappedLoggingContext信息求助

问题描述 #

我编写了如下用于设置MappedLoggingContext的过滤器代码：

@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
        throws ServletException, IOException {
    ContentCachingRequestWrapper req = new ContentCachingRequestWrapper(request);
    ContentCachingResponseWrapper res = new ContentCachingResponseWrapper(response);
    contentTrace = new ContentTrace();
    contentTrace.setTimestamp(DateUtils.currentTimestamp());
    try {
        MappedLoggingContext.clearContext();
        String traceId = request.getHeader("***");
        MappedLoggingContext.setAPIDetails(request.getRequestURI(), request.getMethod());
        MappedLoggingContext.setTraceId(traceId);
        super.doFilterInternal(req, res, filterChain);
    } finally {
        MappedLoggingContext.clearContext();
    }
}

但发现当请求处理抛出NullPointerException时，MappedLoggingContext设置的traceId、API路径等上下文信息并未出现在错误日志中，典型错误日志如下：

{   
    "app": "**",   
    "ts": "2022-11-20T11:35:36.269Z",   
    "logger": "org.apache.catalina.core.ContainerBase.[Tomcat].[localhost].[/].[dispatcherServlet]",
    "level": "ERROR",   
    "class": "org.apache.juli.logging.DirectJDKLog",
    "method": "log",   
    "file": "DirectJDKLog.java",   
    "line": 175,
    "thread": "http-nio-5000-exec-5",   
    "stack": "java.lang.NullPointerException: null\n",   
    "msg": "Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.NullPointerException] with root cause" 
}

排查线索与解决方案 #

1. 核心原因：上下文清理时机过早 #

过滤器的finally块会在请求处理流程（包括后续的Servlet、Controller逻辑）执行完成后立即清空MappedLoggingContext，但Tomcat的dispatcherServlet捕获异常并打印日志的动作，是在过滤器链全部执行完毕后才触发的——此时上下文已经被清空，自然无法在日志中输出相关信息。

2. 调整上下文清理时机 #

可以通过以下方式延迟上下文清理，确保日志打印完成后再清空：

方式一：利用异步监听回调清理

如果项目支持异步请求，可以添加AsyncListener，在请求彻底完成后再清理上下文：

@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
        throws ServletException, IOException {
    ContentCachingRequestWrapper req = new ContentCachingRequestWrapper(request);
    ContentCachingResponseWrapper res = new ContentCachingResponseWrapper(response);
    contentTrace = new ContentTrace();
    contentTrace.setTimestamp(DateUtils.currentTimestamp());

    MappedLoggingContext.clearContext();
    String traceId = request.getHeader("***");
    MappedLoggingContext.setAPIDetails(request.getRequestURI(), request.getMethod());
    MappedLoggingContext.setTraceId(traceId);

    // 注册异步监听，请求完成后清理上下文
    if (req.isAsyncSupported()) {
        req.startAsync().addListener(new AsyncListener() {
            @Override
            public void onComplete(AsyncEvent event) throws IOException {
                MappedLoggingContext.clearContext();
                // 确保响应内容写入客户端
                res.copyBodyToResponse();
            }

            @Override
            public void onTimeout(AsyncEvent event) throws IOException {}
            @Override
            public void onError(AsyncEvent event) throws IOException {}
            @Override
            public void onStartAsync(AsyncEvent event) throws IOException {}
        });
    }

    try {
        super.doFilterInternal(req, res, filterChain);
    } finally {
        // 非异步请求，在响应写入后清理上下文
        if (!req.isAsyncStarted()) {
            res.copyBodyToResponse();
            MappedLoggingContext.clearContext();
        }
    }
}

方式二：全局异常处理器中保留上下文

在Spring的全局异常处理器（@RestControllerAdvice）中，重新绑定上下文信息，确保日志打印时上下文有效：

@RestControllerAdvice
public class GlobalExceptionHandler {
    private static final Logger logger = LoggerFactory.getLogger(GlobalExceptionHandler.class);

    @ExceptionHandler(NullPointerException.class)
    public ResponseEntity<String> handleNPE(NullPointerException e, HttpServletRequest request) {
        // 重新设置上下文
        String traceId = request.getHeader("***");
        MappedLoggingContext.setAPIDetails(request.getRequestURI(), request.getMethod());
        MappedLoggingContext.setTraceId(traceId);
        
        logger.error("请求处理异常", e);
        
        // 清理上下文（根据线程池复用情况决定是否保留）
        MappedLoggingContext.clearContext();
        return ResponseEntity.status(HttpStatus.INTERNAL_SERVER_ERROR).body("服务器异常");
    }
}

3. 确认Logback配置是否正确 #

请提供你的logback-spring.xml内容，需重点确认两点：

• 日志编码器（encoder）中是否配置了MappedLoggingContext对应的上下文字段，例如：

  <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
      <layout class="ch.qos.logback.classic.PatternLayout">
          <pattern>{"traceId":"%X{traceId}","requestURI":"%X{requestURI}","msg":"%msg"}</pattern>
      </layout>
  </encoder>
  

• MappedLoggingContext是否将上下文数据同步到了Logback的MDC（映射诊断上下文）中，若它是自定义实现，需确保内部使用MDC.put()存储字段。

4. 修复ContentCachingResponseWrapper的使用 #

你的代码中使用了ContentCachingResponseWrapper但未调用copyBodyToResponse()，这会导致响应内容无法正常返回给客户端，同时可能影响请求完成的时机判断，务必在合适的时机调用该方法。

内容的提问来源于stack exchange，提问作者ishallwin