不會為每個請求新增獨一無二的id？輕鬆改造spring專案

架構師是我發表於2020-10-12
Spring

前言-為什麼要新增id？

1.新建專案

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
</dependency>
<!--lombok-->
<dependency>
    <groupId>org.projectlombok</groupId>
    <artifactId>lombok</artifactId>
    <optional>true</optional>
</dependency>

除了spring的web依賴包外，新增一個lombok，方便編碼。

2.編寫controller方法

@RestController
public class TestController {
    @GetMapping("hello")
    public String hello(){        
        log.info("this is hello 1");
        log.info("this is hello 2");
        log.info("this is hello 3");
        return "hello";
    }}

這個時候一個簡單的rest介面已經完成了，我們可以先看看日誌的效果。

2019-10-23 10:45:10.917  INFO 1146 --- [nio-8080-exec-1] c.e.demo.controller.TestController       : this is hello 1
2019-10-23 10:45:10.917  INFO 1146 --- [nio-8080-exec-1] c.e.demo.controller.TestController       : this is hello 2
2019-10-23 10:45:10.917  INFO 1146 --- [nio-8080-exec-1] c.e.demo.controller.TestController       : this is hello 3

從這個日誌中，我們根本無法區分單獨的請求。如果同一時間有2到3個請求過來的話，那麼你還能分得清哪個對哪個麼？所以這就是今天要改造的地方。

改造思路

其實要改造的話其實很簡單，我們可以在每個controller入口處，生成唯一的uuid，並傳遞下去。這樣的話缺點就是對程式碼干擾太大，每個方法都要多加一個引數。

那麼我們能不能把這個引數存在一個統一的地方，需要列印日誌的時候，直接去取呢？大家應該可以想到了，用ThreadLocal類。其實到這兒思路已經對了，不過日誌框架也想到了這個問題，他們已經封裝好了現成的功能，就是日誌框架中的MDC

1.首先將日誌的id新增進MDC中

@Component
public class TraceIdInterceptor extends HandlerInterceptorAdapter {
    @Override
    public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
        String traceId = getTraceId(request);        MDC.put("traceId", traceId);
        //將traceId新增進響應頭
        response.addHeader("traceId",traceId);
        return true;
    }
    private String getTraceId(HttpServletRequest request){
        return String.format("%s - %s",request.getRequestURI(), UUID.randomUUID());
    }
}
@Component
public class GlobalWebMvcConfigurer implements WebMvcConfigurer {
    @Autowired
    private TraceIdInterceptor traceIdInterceptor;
    @Override
    /*
      traceId 攔截器需要在最開始執行
     */
    public void addInterceptors(InterceptorRegistry registry) {
        registry.addInterceptor(traceIdInterceptor).order(0);
    }
}

我們使用一下Spring的攔截器功能。在請求開始之前，將請求id新增進MDC。

2.修改日誌的配置檔案

新建一個logback-spring.xml檔案新增如下內容

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="LOG_PATTERN"
              value="%d{yyyy-MM-dd} %d{HH:mm:ss.SSS} [%-5level] [%X{traceId}] [%thread] %logger{36} %F.%L %msg%n">
    </property>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
        <!-- 控制檯列印INFO及以上級別的日誌 -->
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
    </appender>
    <root>
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

在日誌的格式LOG_PATTERN中，新增%X{traceId} ，這樣日誌在列印的時候便會去MDC中取出traceid，放在這兒。現在我們可以看看效果。

2019-10-23 11:02:46.649 [INFO ] [/hello - 79ec561a-ef5e-4dc5-91cc-b2143fa3dbd3] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.18 this is hello 1
2019-10-23 11:02:46.649 [INFO ] [/hello - 79ec561a-ef5e-4dc5-91cc-b2143fa3dbd3] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.19 this is hello 2
2019-10-23 11:02:46.650 [INFO ] [/hello - 79ec561a-ef5e-4dc5-91cc-b2143fa3dbd3] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.20 this is hello 3
2019-10-23 11:02:47.612 [INFO ] [/hello - 2ac7450f-40f5-441c-8e10-9b937c006484] [http-nio-8080-exec-2] c.e.demo.controller.TestController TestController.java.18 this is hello 1
2019-10-23 11:02:47.612 [INFO ] [/hello - 2ac7450f-40f5-441c-8e10-9b937c006484] [http-nio-8080-exec-2] c.e.demo.controller.TestController TestController.java.19 this is hello 2
2019-10-23 11:02:47.612 [INFO ] [/hello - 2ac7450f-40f5-441c-8e10-9b937c006484] [http-nio-8080-exec-2] c.e.demo.controller.TestController TestController.java.20 this is hello 3

可以看到，兩個請求通過traceId可以很清楚的區分開了。這樣我們在排查問題的時候，可以通過響應頭裡面的traceId，直接查詢到相關日誌，非常方便。

進階版traceId

之前說過traceId的實現思路是通過ThreadLocal來實現的。使用ThreadLocal有一個前提就是一個請求進來始終是一個執行緒在處理。如果用到spring中的非同步方法，traceId就會失效了。

我們可以做個實驗

//編寫一個service類
public class Service {    @Async    public void run(){        log.info("this is service run!");
    }}//在hello方法中呼叫service的run方法@GetMapping("hello")
public String hello(){    log.info("this is hello 1");
    log.info("this is hello 2");
    log.info("this is hello 3");
    service.run();    return "hello";
}

可以看的列印出來的日誌

2019-10-23 11:12:23.265 [INFO ] [/hello - 96b31833-e8e6-46c5-8459-d423309d1488] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.22 this is hello 1
2019-10-23 11:12:23.266 [INFO ] [/hello - 96b31833-e8e6-46c5-8459-d423309d1488] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.23 this is hello 2
2019-10-23 11:12:23.267 [INFO ] [/hello - 96b31833-e8e6-46c5-8459-d423309d1488] [http-nio-8080-exec-1] c.e.demo.controller.TestController TestController.java.24 this is hello 3
2019-10-23 11:12:23.278 [INFO ] [] [task-1] com.example.demo.controller.Service Service.java.17 this is service run!

其實也很簡單，只要對非同步執行緒池跑的物件稍作封裝即可。

@EnableAsync
@Configuration
public class AsyncConfiguration {
    @Autowired
    private AppConfig config;
    @Bean("async")
    public Executor taskExecutor() {
        ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
        //設定核心執行緒數量
        executor.setCorePoolSize(config.getAsync().getCorePoolSize());
        //設定最大執行緒數量
        executor.setMaxPoolSize(config.getAsync().getMaxPoolSize());
        //設定佇列最大長度
        executor.setQueueCapacity(config.getAsync().getQueueCapacity());
        //設定執行緒空閒時間
        executor.setKeepAliveSeconds(config.getAsync().getKeepLiveSeconds());
        //設定執行緒字首
        executor.setThreadNamePrefix("async-");
        //設定拒絕策略
        executor.setRejectedExecutionHandler(new ThreadPoolExecutor.CallerRunsPolicy());
        //設定執行緒裝飾器
        executor.setTaskDecorator(runnable -> ThreadMdcUtils.wrapAsync(runnable, MDC.getCopyOfContextMap()));
        return executor;
    }
}
public class ThreadMdcUtils {
    public static Runnable wrapAsync(Runnable task, Map<String,String> context){
        return () -> {
            if(context==null){
                MDC.clear();
            }else {
                MDC.setContextMap(context);
            }
            if(MDC.get(Constant.TraceId)==null){
                MDC.put(Constant.TraceId,UUIDUtils.randomUUID());
            }
            try {
                task.run();
            }finally {
                MDC.clear();
            }
        };
    }
}

這樣的話，即便呼叫非同步方法，也能獲得統一的日誌id。

相關文章