使用 Logback MDC 进行 Spring Boot ErrorController 日志记录

Posted 2023-02-27

【中文标题】使用 Logback MDC 进行 Spring Boot ErrorController 日志记录

【英文标题】：Spring Boot ErrorController logging with Logback MDC

【发布时间】：2021-06-26 03:10:50

【问题描述】：

（更新：我的问题似乎与this one相同，但没有有效的答案。）

我正在尝试登录 Spring Boot ErrorController，但它的日志没有 MDC 值。

@Controller
@RequestMapping("/error")
@RequiredArgsConstructor
@Slf4j
public class MyErrorController implements ErrorController 

    private final ErrorAttributes errorAttributes;

    @Override
    public String getErrorPath() 
        return null;
    

    @RequestMapping
    @ResponseBody
    public Map<String, String> error(final HttpServletRequest request) 
        final ServletWebRequest webRequest = new ServletWebRequest(request);
        final Throwable th = errorAttributes.getError(webRequest);

        if (th != null) 
            // **Logged without "requestId" value**
            log.error("MyErrorController", th);
        

        return Map.of("result", "error");
    

// http://logback.qos.ch/manual/mdc.html#autoMDC
public class MDCFilter extends OncePerRequestFilter 

    @Override
    protected void doFilterInternal(final HttpServletRequest request, final HttpServletResponse response,
        final FilterChain filterChain)
        throws ServletException, IOException 

        final String requestId = UUID.randomUUID().toString();

        MDC.put("requestId", requestId);

        try 
            filterChain.doFilter(request, response);
         finally 
            MDC.remove("requestId");
        
    

@Configuration
public class MyConfig 

    @Bean
    public FilterRegistrationBean<MDCFilter> mdcFilter() 
        final FilterRegistrationBean<MDCFilter> bean = new FilterRegistrationBean<>();
        bean.setFilter(new MDCFilter());
        bean.addUrlPatterns("/*");
        bean.setOrder(Ordered.HIGHEST_PRECEDENCE);
        return bean;
    

logback-spring.xml:

<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <!-- encoders are assigned the type
         ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
        <encoder>
            <pattern>%dHH:mm:ss.SSS [%thread] requestId:%XrequestId %-5level %logger36 - %msg%n</pattern>
        </encoder>
    </appender>

    <root level="debug">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

结果（requestId 值没有出现）：

18:15:13.705 [http-nio-8080-exec-1] requestId: ERROR c.e.l.MyErrorController - MyErrorController
java.lang.RuntimeException: Error occured.
...

Here is complete code.

我认为我需要在DispatcherServlet之前适应MDCFilter，但我不知道该怎么做。

【问题讨论】：

您的代码适用于我 08:10:40.089 [http-nio-8080-exec-2] MY_MDC_VALUE 错误 c.e.loggingwithmdcdemo.MyController - MyController

【参考方案1】：

删除 ServletRequestListener#requestDestroyed() 上而不是 Filter 上的 MDC 数据。

在 Tomcat 上，StandardHostValve 在 ErrorController 执行后触发 RequestDestroyEvent。

            // Look for (and render if found) an application level error page
            if (response.isErrorReportRequired()) 
                // If an error has occurred that prevents further I/O, don't waste time
                // producing an error report that will never be read
                AtomicBoolean result = new AtomicBoolean(false);
                response.getCoyoteResponse().action(ActionCode.IS_IO_ALLOWED, result);
                if (result.get()) 
                    if (t != null) 
                        throwable(request, response, t); // *ErrorController is executed*
                     else 
                        status(request, response);
                    
                
            

            if (!request.isAsync() && !asyncAtStart) 
                context.fireRequestDestroyEvent(request.getRequest()); // *RequestDestroyEvent is fired*
            

所以，实现以下：

public class MDCClearListener implements ServletRequestListener 

    @Override
    public void requestDestroyed(final ServletRequestEvent sre) 
        MDC.remove("requestId");
    

    @Bean
    public ServletListenerRegistrationBean<MDCClearListener> mdcClearListener() 
        final ServletListenerRegistrationBean<MDCClearListener> bean = new ServletListenerRegistrationBean<>();
        bean.setListener(new MDCClearListener());
        bean.setOrder(Ordered.HIGHEST_PRECEDENCE);
        return bean;
    

（具体代码存在于solution branch。）

---

关于相关问题的回答

This answer 不适合我。因为：

第一种方式没有使用ErrorController而是@ExceptionHandler，所以无法捕获Spring Security Filter抛出的异常。 （试试answer/exceptionhandler-with-springsecurity branch 代码。）

第二种方式将 UUID 放在拦截器上，因此记录了 MyController 和 MyErrorController 之间的不同 requestId。这不是“请求”ID。 （试试answer/interceptor branch 代码。）

【参考方案2】：

一切都按预期进行。

这是记录的行：

08:19:34.204 [http-nio-8080-exec-2] MY_MDC_VALUE DEBUG o.s.web.servlet.DispatcherServlet - Failed to complete request: java.lang.RuntimeException: Error occured.

您发布的是来自 MyErroController 的日志

08:19:34.209 [http-nio-8080-exec-2]  ERROR c.e.l.MyErrorController - MyErrorController

正如你所说的那样

MDC.clear();

执行此日志语句时，MDC 为空。

【讨论】：

是的，我当前的实现在记录之前清除了 MDC，所以应该修改它。但是我不知道该怎么做...

很抱歉我解释得不够清楚。实际上MY_MDC 是请求范围的信息，所以我关注了Example 7.5。

我不明白你的问题？