Spring中使用MDC和traceId實現日誌鏈路追蹤

大列巴同学發表於2024-10-25
Spring

前言

在系統出現問題時，我們常需要對日誌進行分析，而如果日誌列印時沒有明確的標識，且日誌內容不同執行緒很多時，很難找出哪段日誌是我們需要的。針對這一問題，我們可以考慮使用MDC來實現日誌鏈路追蹤，迅速找到所需要的日誌資訊。當然，這也十分適合當下流行的微服務，特別是上下游節點有多個時，透過一個traceId來串聯起整個鏈路流程。

一、MDC是什麼？

MDC（Mapped Diagnostic Context，對映除錯上下文）是Java中用於日誌跟蹤的一個工具，它主要被整合在日誌框架中，如Log4j、Logback等。MDC提供了一種機制，允許開發者在多執行緒環境下關聯和傳遞特定的上下文資訊，這些資訊對於日誌的追蹤、診斷和除錯非常有用。

1、執行緒本地：MDC是基於執行緒本地變數（ThreadLocal）實現的，這意味著每個執行緒都有自己獨立的MDC儲存空間，執行緒之間不會相互干擾。

2、可維護：MDC中的資訊可以被設定、獲取和清除，這為日誌的上下文管理提供了極大的靈活性。

3、可傳遞：在分散式系統中，MDC資訊可以隨著請求在多個服務或節點之間傳遞，幫助開發者追蹤請求的完整處理流程。

二、使用MDC實現日誌追蹤

1. 新增TraceIdUtil工具類：

package com.neo.util;

import org.slf4j.MDC;

import java.util.UUID;

public class TraceIdUtil {

    public static final String KEY_TRACE_ID = "traceId";

    public static final String HEADER_TRACE_ID = "x-traceId";

    public static String generateTraceId() {
        return UUID.randomUUID().toString().replace("-", "");
    }

    public static String getTraceId() {
        return MDC.get(KEY_TRACE_ID);
    }

    public static void setTraceId(String traceId) {
        MDC.put(KEY_TRACE_ID, traceId);
    }

    public static void clear() {
        MDC.clear();
    }

}

2. 在攔截器中設定traceId

有些同學可能要問，為什麼在攔截器設定？因為請求在進入controller之前會先經過設定的攔截器（如果uri匹配到）。當然在filter過濾器中也可以，設定和清除的方式是相同的。

package com.neo.interceptor;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import com.neo.util.TraceIdUtil;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.util.StringUtils;
import org.springframework.web.servlet.HandlerInterceptor;
  
@Component
public class TraceIdInterceptor implements HandlerInterceptor {

    private static final Logger logger = LoggerFactory.getLogger(TraceIdInterceptor.class);
  
    @Override  
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        logger.info("TraceIdInterceptor preHandle");

        // 從請求頭中獲取traceId，如果沒有則生成一個
        String headerTraceId = request.getHeader(TraceIdUtil.HEADER_TRACE_ID);
        String traceId = StringUtils.isEmpty(headerTraceId) ? TraceIdUtil.generateTraceId() : headerTraceId;
        TraceIdUtil.setTraceId(traceId);

        // TODO 業務邏輯處理

        return true;
    }  
  
    @Override  
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
        logger.info("TraceIdInterceptor afterCompletion");

        // 請求處理完成後，清除MDC中的traceId，以免造成記憶體洩漏
        TraceIdUtil.clear();
    }
}

此處解釋下為什麼要先從header中獲取，如果沒有再重新生成。因為考慮到如今很多專案採用微服務架構或上下游節點很多時，為了全流程的日誌追蹤，建議保持traceId一致，這樣更方便日誌排查。如果微服務專案中使用了Skywalking或ELK等日誌系統時，就可以透過一個traceId拉出整個上下游節點日誌，一目瞭然！

需要注意，如果專案中有多個攔截器，最好在第一個攔截器中設定traceId，否則有可能前置的攔截器直接攔截了請求，而你在後置的攔截器設定的traceId，日誌就不會列印traceId了。如下，則需要在loginInterceptor中設定：

package com.neo.controller.config;

import com.neo.interceptor.LoginInterceptor;
import com.neo.interceptor.TraceIdInterceptor;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.context.annotation.Configuration;  
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;  
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;  
  
@Configuration  
public class WebConfig implements WebMvcConfigurer {  
  
    @Autowired  
    private TraceIdInterceptor traceIdInterceptor;

    @Autowired
    private LoginInterceptor loginInterceptor;
  
    @Override  
    public void addInterceptors(InterceptorRegistry registry) {
        // addPathPatterns 用於新增攔截規則
        // excludePathPatterns 用於排除攔截規則

        registry.addInterceptor(loginInterceptor)
                .addPathPatterns("/**")
                .excludePathPatterns("/static/**", "/css/**", "/js/**", "/images/**");

        registry.addInterceptor(traceIdInterceptor)
                .addPathPatterns("/**") // 攔截所有請求
                .excludePathPatterns("/static/**", "/css/**", "/js/**", "/images/**"); // 排除靜態資源
    }
}

！！！一定要注意，因為MDC底層使用的是ThreadLocal， 一定要記得在最後清除掉，防止出現記憶體洩漏！！！

3. 根據你當前的日誌框架來加入列印traceId

(1). 如果專案中使用的是logback（springboot預設的日誌框架）

<configuration>  
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">  
        <encoder>  
            <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %X{traceId} - %msg%n</pattern>  
        </encoder>  
    </appender>  
  
    <root level="debug">  
        <appender-ref ref="STDOUT" />  
    </root>  
</configuration>

(2). 如果專案中使用的是log4j2

<Configuration>  
    <Appenders>  
        <Console name="Console" target="SYSTEM_OUT">  
            <PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss} [%t] %-5level %logger{36} - %X{traceId} - %msg%n"/>  
        </Console>  
    </Appenders>  
    <Loggers>  
        <Root level="debug">  
            <AppenderRef ref="Console"/>  
        </Root>  
    </Loggers>  
</Configuration>

啟動專案，發起任意請求，請求經過攔截器，我們就可以在日誌中列印出traceId了，如下：

4. 在不同的服務間傳遞traceId

不管你是使用httpUtil還是restTemplate還是feign等工具呼叫其他系統服務，都可以在請求header中設定traceId，類似如下：

request.getHeaders().add(TraceIdUtil.HEADER_TRACE_ID, TraceIdUtil.getTraceId());

下游系統再如上所述進行日誌改造即可達成鏈路！

5. 多執行緒時MDC的跨執行緒解決方案

聰明的你可能要問了，文中說MDC底層是threadLocal，如果請求的鏈路有環節使用了多執行緒，如果不進行特殊設定，是不是無法正常列印出traceId了，這時候該怎麼解決呢？
我們一般直接使用spring提供的執行緒池類，即ThreadPoolTaskExecutor，對其進行改造，如下：
先自定義TaskDecorator類

package com.neo.config;

import org.slf4j.MDC;
import org.springframework.core.task.TaskDecorator;

import java.util.Map;

public class MdcTaskDecorator implements TaskDecorator {
    @Override
    public Runnable decorate(Runnable runnable) {
        // 獲取主執行緒的MDC
        Map<String, String> copyOfContextMap = MDC.getCopyOfContextMap();
        return () -> {
            try {
                // 將主執行緒的MDC設定到子執行緒中
                if (copyOfContextMap != null) {
                    MDC.setContextMap(copyOfContextMap);
                }
                runnable.run();
            } finally {
                // 清除MDC
                MDC.clear();
            }
        };
    }
}

定義好spring的執行緒池配置類

package com.neo.config;

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.scheduling.annotation.EnableAsync;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

import java.util.concurrent.ThreadPoolExecutor;

@Configuration
@EnableAsync
public class ThreadPoolConfig {

    @Bean("taskExecutor")
    public ThreadPoolTaskExecutor taskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        executor.setCorePoolSize(10);
        executor.setMaxPoolSize(20);
        executor.setQueueCapacity(200);
        executor.setKeepAliveSeconds(60);
        executor.setThreadNamePrefix("taskExecutor-");
        executor.setWaitForTasksToCompleteOnShutdown(true);
        executor.setAwaitTerminationSeconds(60);
        executor.setTaskDecorator(new MdcTaskDecorator());
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        return executor;
    }

}

測試請求程式碼如下：

package com.neo.controller;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
import org.springframework.web.bind.annotation.*;

@RestController
public class HelloController {

    private static final Logger logger = LoggerFactory.getLogger(HelloController.class);

    @Autowired
    private ThreadPoolTaskExecutor taskExecutor;

    @GetMapping("/test")
    public String test() {
        logger.info("you can see traceId in log");
        // 使用自定義的執行緒池，模擬多執行緒
        for (int i = 0; i < 10; i++) {
            taskExecutor.execute(() -> {
                logger.info("this is a async task");
            });
        }
        return "success";
    }

}

原文連結：https://blog.csdn.net/zzs1067632338/article/details/141723736

相關文章