Springboot 同一次調用日志怎麼用ID串起來，友善最終查找

前言

從文章标題就知道，這篇文章是介紹些什麼。

這是我一位朋友的問題回報：

好像是的，确實這種現象是普遍存在的。

有時候一個業務調用鍊場景，很長，調了各種各樣的方法，看日志的時候，各個接口的日志穿插，确實讓人頭大。

模糊比對搜尋日志能解決嗎？能解決一點點。但是不能完全呈現出整個鍊路相關的日志。

那要做到友善，很顯然，我們需要的是把同一次的業務調用鍊上的日志串起來。

什麼效果？先看一個實作後的效果圖：

這樣下來，我們再配合模糊比對查找日志，效果不就剛剛的了。

cat -n info.log |grep "a415ad50dbf84e99b1b56a31aacd209c"

或者

grep -10 'a415ad50dbf84e99b1b56a31aacd209c' info.log （10是指上下10行）

不多說，開整。

正文

慣例，先看一眼這次實戰最終工程的結構：

①pom.xml 依賴

<dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
        </dependency>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-logging</artifactId>
        </dependency>
        <!--lombok配置-->
        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <version>1.16.10</version>
        </dependency>
    </dependencies>

②整合logback，列印日志，logback-spring.xml (簡單配置下)

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="false">
    <!--日志存儲路徑-->
    <property name="log" value="D:/test/log" />
    <!-- 控制台輸出 -->
    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <!--輸出格式化-->
            <pattern>[%X{TRACE_ID}]  %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
    </appender>
    <!-- 按天生成日志檔案 -->
    <appender name="file" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <!--日志檔案名-->
            <FileNamePattern>${log}/%d{yyyy-MM-dd}.log</FileNamePattern>
            <!--保留天數-->
            <MaxHistory>30</MaxHistory>
        </rollingPolicy>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>[%X{TRACE_ID}]  %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{50} - %msg%n</pattern>
        </encoder>
        <!--日志檔案最大的大小-->
        <triggeringPolicy class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy">
            <MaxFileSize>10MB</MaxFileSize>
        </triggeringPolicy>
    </appender>

    <!-- 日志輸出級别 -->
    <root level="INFO">
        <appender-ref ref="console" />
        <appender-ref ref="file" />
    </root>
</configuration>

application.yml

server:
  port: 8826
logging:
  config: classpath:logback-spring.xml

③自定義日志攔截器 LogInterceptor.java

用途：每一次鍊路，線程次元，添加最終的鍊路ID TRACE_ID。

import org.slf4j.MDC;
import org.springframework.lang.Nullable;
import org.springframework.util.StringUtils;
import org.springframework.web.servlet.HandlerInterceptor;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.UUID;

/**
 * @Author: JCccc
 * @Date: 2022-5-30 10:45
 * @Description:
 */
public class LogInterceptor implements HandlerInterceptor {

    private static final String TRACE_ID = "TRACE_ID";

    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
        String tid = UUID.randomUUID().toString().replace("-", "");
        //可以考慮讓用戶端傳傳入連結路ID，但需保證一定的複雜度唯一性；如果沒使用預設UUID自動生成
        if (!StringUtils.isEmpty(request.getHeader("TRACE_ID"))){
            tid=request.getHeader("TRACE_ID");
        }
        MDC.put(TRACE_ID, tid);
        return true;
    }

    @Override
    public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler,
                                @Nullable Exception ex) {
        MDC.remove(TRACE_ID);
    }

}

MDC(Mapped Diagnostic Context)診斷上下文映射，是@Slf4j提供的一個支援動态列印日志資訊的工具。

WebConfigurerAdapter.java 添加攔截器

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;

/**
 * @Author: JCccc
 * @Date: 2022-5-30 10:47
 * @Description:
 */
@Configuration
public class WebConfigurerAdapter implements WebMvcConfigurer {
    @Bean
    public LogInterceptor logInterceptor() {
        return new LogInterceptor();
    }

    @Override
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(logInterceptor());
        //可以具體制定哪些需要攔截，哪些不攔截，其實也可以使用自定義注解更靈活完成
//                .addPathPatterns("/**")
//                .excludePathPatterns("/testxx.html");
    }
}

ps: 其實這個攔截的部分改為使用自定義注解+aop也是很靈活的。

到這時候，其實已經完成，就是這麼簡單。

我們寫個測試接口，看下效果：

@PostMapping("doTest")
    public String doTest(@RequestParam("name") String name) throws InterruptedException {
        log.info("入參 name={}",name);
        testTrace();
        log.info("調用結束 name={}",name);
        return "Hello,"+name;
    }
    private void testTrace(){
        log.info("這是一行info日志");
        log.error("這是一行error日志");
        testTrace2();
    }
    private void testTrace2(){
        log.info("這也是一行info日志");

    }

效果（OK的）：

還沒完。

接下來看一個場景，使用子線程的場景：

故意寫一個異步線程，加入這個調用裡面：

再次執行看開效果，顯然子線程丢失了trackId：

是以我們需要針對子線程使用情形，做調整，思路：将父線程的trackId傳遞下去給子線程即可。

①ThreadPoolConfig.java 定義線程池，交給spring管理

import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.scheduling.annotation.EnableAsync;
import java.util.concurrent.Executor;

/**
 * @Author: JCccc
 * @Date: 2022-5-30 11:07
 * @Description:
 */
@Configuration
@EnableAsync
public class ThreadPoolConfig {
    /**
     * 聲明一個線程池
     *
     * @return 執行器
     */
    @Bean("MyExecutor")
    public Executor asyncExecutor() {
        MyThreadPoolTaskExecutor executor = new MyThreadPoolTaskExecutor();
        //核心線程數5：線程池建立時候初始化的線程數
        executor.setCorePoolSize(5);
        //最大線程數5：線程池最大的線程數，隻有在緩沖隊列滿了之後才會申請超過核心線程數的線程
        executor.setMaxPoolSize(5);
        //緩沖隊列500：用來緩沖執行任務的隊列
        executor.setQueueCapacity(500);
        //允許線程的空閑時間60秒：當超過了核心線程出之外的線程在空閑時間到達之後會被銷毀
        executor.setKeepAliveSeconds(60);
        //線程池名的字首：設定好了之後可以友善我們定位處理任務所在的線程池
        executor.setThreadNamePrefix("asyncJCccc");
        executor.initialize();
        return executor;
    }
}

② MyThreadPoolTaskExecutor.java 是我們自己寫的，重寫了一些方法：

import org.slf4j.MDC;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;

import java.util.concurrent.Callable;
import java.util.concurrent.Future;

/**
 * @Author: JCccc
 * @Date: 2022-5-30 11:13
 * @Description:
 */
public final class MyThreadPoolTaskExecutor  extends ThreadPoolTaskExecutor  {
    public MyThreadPoolTaskExecutor() {
        super();
    }
    
    @Override
    public void execute(Runnable task) {
        super.execute(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }


    @Override
    public <T> Future<T> submit(Callable<T> task) {
        return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }

    @Override
    public Future<?> submit(Runnable task) {
        return super.submit(ThreadMdcUtil.wrap(task, MDC.getCopyOfContextMap()));
    }
}

③ThreadMdcUtil.java

import org.slf4j.MDC;

import java.util.Map;
import java.util.UUID;
import java.util.concurrent.Callable;

/**
 * @Author: JCccc
 * @Date: 2022-5-30 11:14
 * @Description:
 */
public final class ThreadMdcUtil {
    private static final String TRACE_ID = "TRACE_ID";

    // 擷取唯一性辨別
    public static String generateTraceId() {
        return UUID.randomUUID().toString();
    }

    public static void setTraceIdIfAbsent() {
        if (MDC.get(TRACE_ID) == null) {
            MDC.put(TRACE_ID, generateTraceId());
        }
    }

    /**
     * 用于父線程向線程池中送出任務時，将自身MDC中的資料複制給子線程
     *
     * @param callable
     * @param context
     * @param <T>
     * @return
     */
    public static <T> Callable<T> wrap(final Callable<T> callable, final Map<String, String> context) {
        return () -> {
            if (context == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(context);
            }
            setTraceIdIfAbsent();
            try {
                return callable.call();
            } finally {
                MDC.clear();
            }
        };
    }

    /**
     * 用于父線程向線程池中送出任務時，将自身MDC中的資料複制給子線程
     *
     * @param runnable
     * @param context
     * @return
     */
    public static Runnable wrap(final Runnable runnable, final Map<String, String> context) {
        return () -> {
            if (context == null) {
                MDC.clear();
            } else {
                MDC.setContextMap(context);
            }
            setTraceIdIfAbsent();
            try {
                runnable.run();
            } finally {
                MDC.clear();
            }
        };
    }
}

OK，重新開機服務，再看看效果：

Springboot 同一次調用日志怎麼用ID串起來，友善最終查找

前言

正文

繼續閱讀

Android的前後端互動架構搭建（okhhtp+springboot+mysql完整版）

解決eclipse中logcat不顯示log的問題

start to use skywalkingInstall JDK8Install ESInstall skywalkingRun Springboot JAR

關于Springboot中JSCH使用說明1. JSCH簡介2. JSCH依賴3. 使用方法4. 使用連接配接池

路徑錯誤Maven：Non-resolvable parent POM: Failure to find錯誤

jsch連接配接伺服器執行指令傳回的資料中文亂碼問題問題分析解決

springboot項目時間不一緻解決方案一、springboot項目時間不一緻解決方案

spring mvc 頁面傳遞數組背景接收方式spring mvc 頁面傳遞數組背景接收方式

Swagger-UI的使用一、添加依賴二、建立配置類三、注解

将swagger-ui中的接口導入postman

聊一聊Swagger-UI的那些事情軟體簡介Swagger 原生Bootstrap-ui Bootstrap的UIKnife4j Bootstrap的更新版的UI

springboot使用 swagger-ui 2.10.5 有關版本更新帶來的問題

Spring Cloud整合Sleuth，當請求完成後，Zipkin沒有鍊路資訊

微服務-性能壓測\緩存redis和分布式鎖redisson和SpringCache

java 8 Lamda 求 List 中 Bigdecimal類型的各種值求最大值求最小值求和求平均值

(SpringBoot)日志種類：log、monitor、access、out、gc、backup