"If debugging is the process of removing software bugs, then programming must be the process of putting them in." - Edsger Dijkstra
「如果偵錯是消除軟體Bug的過程，那麼程式設計就是產出Bug的過程。」 —— 艾茲格·迪傑斯特拉
當你的應用程式同時處理多個使用者的請求時，你會看到紀錄檔檔案或者控制檯中的輸出通常都是交錯的，而非線性連續的。尤其是在分散式系統中，一個使用者請求可能包含了若干次的服務節點呼叫，它的紀錄檔也因此變得碎片化，如果缺乏一個用於歸類和關聯的標識，就會導致這筆交易難以被跟蹤和追查。
MDC(Mapped Diagnostic Context)是一種用於區分來自不同來源紀錄檔的工具。它的本質是一個由紀錄檔框架維護的Map儲存結構，應用程式可以向其中寫入鍵值對，並被紀錄檔框架存取。我們常用的紀錄檔門面SLF4J就對MDC的實現進行了抽象，由紀錄檔框架提供真正的實現。在SLF4J的檔案中寫道：
This class hides and serves as a substitute for the underlying logging system's MDC implementation.
If the underlying logging system offers MDC functionality, then SLF4J's MDC, i.e. this class, will delegate to the underlying system's MDC. Note that at this time, only two logging systems, namely log4j and logback, offer MDC functionality. For java.util.logging which does not support MDC, BasicMDCAdapter will be used. For other systems, i.e. slf4j-simple and slf4j-nop, NOPMDCAdapter will be used.
Thus, as a SLF4J user, you can take advantage of MDC in the presence of log4j, logback, or java.util.logging, but without forcing these systems as dependencies upon your users.
目前為止只有logback和log4j(log4j2)提供了較為完備的實現，其餘紀錄檔框架下會使用SLF4J內部實現的BasicMDCAdapter或者NOPMDCAdapter.
以logback為例，我們建立一個簡單的logback.xml組態檔：
<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="false">
<property name="log.pattern" value="[%thread][%level][%logger{42}][%X{traceId:--}] %msg%n%ex"/>
<appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
<layout class="ch.qos.logback.classic.PatternLayout">
<pattern>${log.pattern}</pattern>
</layout>
</appender>
<root level="INFO">
<appender-ref ref="stdout"/>
</root>
</configuration>
一個簡單的類用於測試，我們用一個迴圈來模擬使用者兩個獨立的請求：
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.util.UUID;
public class Main {
private static final Logger LOGGER = LoggerFactory.getLogger(Main.class);
public static void main(String[] args) {
for (int i = 0; i < 2; i++) {
try {
LOGGER.info("Empty MDC Before Putting Data.");
MDC.put("traceId", UUID.randomUUID().toString());
LOGGER.info("Hello MDC.");
LOGGER.info("GoodBye MDC.");
throw new RuntimeException("Test Exception");
} catch (RuntimeException e) {
LOGGER.error("Test MDC", e);
} finally {
MDC.clear();
LOGGER.info("Empty MDC After Clearing Data.");
}
}
}
}
執行之後，我們會得到類似這樣的紀錄檔輸出：
[main][INFO][com.example.Main][-] Empty MDC Before Putting Data.
[main][INFO][com.example.Main][9ed7cc12-3880-4a38-94d4-b7ba96f37234] Hello MDC.
[main][INFO][com.example.Main][9ed7cc12-3880-4a38-94d4-b7ba96f37234] GoodBye MDC.
[main][ERROR][com.example.Main][9ed7cc12-3880-4a38-94d4-b7ba96f37234] Test MDC
java.lang.RuntimeException: Test Exception
at com.example.Main.main(Main.java:19)
[main][INFO][com.example.Main][-] Empty MDC After Clearing Data.
[main][INFO][com.example.Main][-] Empty MDC Before Putting Data.
[main][INFO][com.example.Main][ab94804a-4f9a-4474-ba23-98542884d0ea] Hello MDC.
[main][INFO][com.example.Main][ab94804a-4f9a-4474-ba23-98542884d0ea] GoodBye MDC.
[main][ERROR][com.example.Main][ab94804a-4f9a-4474-ba23-98542884d0ea] Test MDC
java.lang.RuntimeException: Test Exception
at com.example.Main.main(Main.java:19)
[main][INFO][com.example.Main][-] Empty MDC After Clearing Data.
可以看到，兩次請求的traceId是不一樣的，這樣就能在紀錄檔中將它們區分和識別開來。通常來說，最好在請求完成後對MDC中的資料進行清理，尤其是使用了執行緒池的情況，由於執行緒是複用的，除非對原來的鍵值進行了覆蓋，否則它將保留上一次的值。
在CLI程式中，我們可以用上面的寫法來設定traceId，當時對於 Web 應用，由於Controller入口眾多，不可能每個控制器都這樣子寫，可以使用攔截器實現公共邏輯，避免對Controller的方法造成汙染。先增加一個簡單的Controller，它有兩個請求處理方法，一個同步，一個非同步：
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
import java.util.Map;
import java.util.concurrent.Callable;
@RestController
public class MDCController {
private static final Logger LOGGER = LoggerFactory.getLogger(MDCController.class);
@Configuration
public class WebMvcConfig implements WebMvcConfigurer {
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(new LogInterceptor()).addPathPatterns("/**");
}
}
@GetMapping("/syncMDC")
public String mdcSync() {
LOGGER.info("sync MDC test.");
return "syncMDC";
}
@GetMapping("/asyncMDC")
public Callable<String> mdcAsync() {
LOGGER.info("async MDC test.");
Map<String, String> mdcMap = MDC.getCopyOfContextMap();
return () -> {
try {
MDC.setContextMap(mdcMap);
LOGGER.info("非同步業務邏輯處理");
return "asyncMDC";
} finally {
MDC.clear();
}
};
}
}
然後是關鍵的MDC攔截器：
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.web.servlet.AsyncHandlerInterceptor;
import javax.servlet.DispatcherType;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.util.UUID;
/**
* 紀錄檔增強攔截器，給輸出紀錄檔加上鍊路跟蹤號
*
* @author YanFaBu
**/
public class LogInterceptor implements AsyncHandlerInterceptor {
private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) {
if (request.getDispatcherType() != DispatcherType.REQUEST) {
// 非 DispatcherType.REQUEST 分發型別，嘗試從 Attribute 獲取 LOG_TRACE_ID
MDC.put("traceId", (String) request.getAttribute("traceId"));
LOGGER.info("preHandle Non DispatcherType.REQUEST type with DispatcherType {}", request.getDispatcherType());
return true;
}
// 如果本次呼叫來自上游服務，那麼嘗試從請求頭獲取上游傳遞的 traceId
String traceId = request.getHeader("traceId");
if (traceId == null) {
// 本服務節點是起始服務節點，設定 traceId
traceId = UUID.randomUUID().toString();
}
MDC.put("traceId", traceId);
// 非同步處理會在內部進行 Request 轉發，通過 Attribute 攜帶 traceId
request.setAttribute("traceId", traceId);
LOGGER.info("preHandle DispatcherType.REQUEST type with DispatcherType {}", request.getDispatcherType());
return true;
}
@Override
public void afterConcurrentHandlingStarted(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
// 清理 MDC
LOGGER.info("afterConcurrentHandlingStarted Clearing MDC.");
MDC.clear();
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception exception) {
// 清理 MDC
LOGGER.info("afterCompletion Clearing MDC with DispatcherType {}", request.getDispatcherType());
MDC.clear();
}
}
分別存取這兩個Controller方法，應當看到類似這樣的紀錄檔輸出：
[http-nio-8080-exec-7][INFO][com.example.LogInterceptor][e828f77b-9c0d-42c5-83db-15f19153bf19] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-7][INFO][com.example.MDCController][e828f77b-9c0d-42c5-83db-15f19153bf19] sync MDC test.
[http-nio-8080-exec-7][INFO][com.example.LogInterceptor][e828f77b-9c0d-42c5-83db-15f19153bf19] afterCompletion Clearing MDC with DispatcherType REQUEST
[http-nio-8080-exec-8][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-8][INFO][com.example.MDCController][7dc0878c-c014-44de-97d4-92108873a030] async MDC test.
[http-nio-8080-exec-8][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] afterConcurrentHandlingStarted Clearing MDC.
[task-3][INFO][com.example.MDCController][7dc0878c-c014-44de-97d4-92108873a030] 非同步業務邏輯處理
[http-nio-8080-exec-9][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] preHandle Non DispatcherType.REQUEST type with DispatcherType ASYNC
[http-nio-8080-exec-9][INFO][com.example.LogInterceptor][7dc0878c-c014-44de-97d4-92108873a030] afterCompletion Clearing MDC with DispatcherType ASYNC
注意到非同步請求處理中的執行緒號的變化，請求受理-業務處理-請求應答歷經了3個不同的執行緒，凡是跨執行緒的處理邏輯，必然需要對MDC的傳遞進行處理，否則鏈路跟蹤會丟失。網上看到過很多例子，都忽略了對DispatcherType的處理，這樣就會導致非同步請求中，有一部分紀錄檔會失去追蹤，導致最終排查問題時鏈路不完整。通過Attribute傳遞不是唯一的方式，也可以藉助其他上下文來傳遞。
import okhttp3.OkHttpClient;
import okhttp3.Request;
import okhttp3.Response;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.io.IOException;
import java.util.Objects;
import java.util.UUID;
public class Client {
private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);
public static void main(String[] args) throws IOException {
okHttpSync();
}
public static void okHttpSync() throws IOException {
try {
String traceId = UUID.randomUUID().toString();
MDC.put("traceId", traceId);
LOGGER.info("okHttpSync request syncMDC");
OkHttpClient client = new OkHttpClient().newBuilder()
.build();
Request request = new Request.Builder()
.url("http://localhost:8080/syncMDC")
.method("GET", null)
.addHeader("traceId", traceId)
.build();
try (Response response = client.newCall(request).execute()) {
LOGGER.info("okHttpSync response：{}", Objects.requireNonNull(response.body()).string());
}
} finally {
MDC.clear();
}
}
}
import okhttp3.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import java.io.IOException;
import java.util.Map;
import java.util.Objects;
import java.util.UUID;
public class Client {
private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);
public static void main(String[] args) {
okHttpAsync();
}
public static void okHttpAsync() {
try {
String traceId = UUID.randomUUID().toString();
MDC.put("traceId", traceId);
LOGGER.info("okHttpAsync request syncMDC");
OkHttpClient client = new OkHttpClient().newBuilder()
.build();
Request request = new Request.Builder()
.url("http://localhost:8080/syncMDC")
.method("GET", null)
.addHeader("traceId", traceId)
.build();
Map<String, String> mdcMap = MDC.getCopyOfContextMap();
client.newCall(request).enqueue(new Callback() {
@Override
public void onFailure(Call call, IOException e) {
try {
MDC.setContextMap(mdcMap);
LOGGER.error("okHttpAsync error", e);
} finally {
MDC.clear();
}
}
@Override
public void onResponse(Call call, Response response) throws IOException {
try {
MDC.setContextMap(mdcMap);
LOGGER.info("okHttpAsync response：{}", Objects.requireNonNull(response.body()).string());
} finally {
MDC.clear();
}
}
});
} finally {
MDC.clear();
}
}
}
順利的話，在使用者端應該會得到類似下面的紀錄檔輸出（注意執行緒名稱的變化）：
[main][INFO][com.example.Client][53924455-0fcd-442b-a5aa-aaa33005d299] okHttpSync request syncMDC
[main][INFO][com.example.Client][53924455-0fcd-442b-a5aa-aaa33005d299] okHttpSync response：syncMDC
[main][INFO][com.example.Client][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] okHttpAsync request syncMDC
[OkHttp http://localhost:8080/...][INFO][com.example.Client][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] okHttpAsync response：syncMDC
在伺服器端對應的紀錄檔如下，可以看到traceId是一致的（如果不一致或者沒有看到traceId，應該檢查下上一章提到的攔截器是否有被正確實現）：
[http-nio-8080-exec-2][INFO][com.example.LogInterceptor][53924455-0fcd-442b-a5aa-aaa33005d299] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-2][INFO][com.example.MDCController][53924455-0fcd-442b-a5aa-aaa33005d299] sync MDC test.
[http-nio-8080-exec-2][INFO][com.example.LogInterceptor][53924455-0fcd-442b-a5aa-aaa33005d299] afterCompletion Clearing MDC with DispatcherType REQUEST
[http-nio-8080-exec-3][INFO][com.example.LogInterceptor][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-3][INFO][com.example.MDCController][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] sync MDC test.
[http-nio-8080-exec-3][INFO][com.example.LogInterceptor][5cb52293-c8ac-4bc5-87fc-dbeb1e727eba] afterCompletion Clearing MDC with DispatcherType REQUEST
處理思路都是通過HTTP Header攜帶traceId到下游服務，讓下游服務可以跟蹤來源。注意非同步請求時，請求處理和應答處理回撥執行緒不在同一個執行緒，需要對MDC的傳遞進行處理，否則鏈路跟蹤會丟失。其他的使用者端，如HttpClient、Unirest等 HTTP 請求庫原理與之相似，這裡就不一一列舉了。
與OkHttp非同步呼叫類似，注意要在Mono或者Flux的subscribe方法中傳遞MDC上下文。其實WebClient中有Context傳遞的概念，但是這塊資料比較少，非同步非阻塞的程式碼又看得頭痛，暫時不想去研究了。下面的程式碼出於演示目的使用，請勿直接使用：
import okhttp3.*;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.web.reactive.function.client.WebClient;
import java.io.IOException;
import java.util.Map;
import java.util.Objects;
import java.util.UUID;
import java.util.concurrent.CountDownLatch;
public class Client {
private static final Logger LOGGER = LoggerFactory.getLogger(LogInterceptor.class);
public static void main(String[] args) throws InterruptedException {
webClient();
}
public static void webClient() throws InterruptedException {
String traceId = UUID.randomUUID().toString();
MDC.put("traceId", traceId);
LOGGER.info("webClient request syncMDC");
WebClient client = WebClient.create("http://localhost:8080/syncMDC");
Map<String, String> mdcMap = MDC.getCopyOfContextMap();
CountDownLatch latch = new CountDownLatch(1);
client.get()
.uri("/")
.retrieve()
.bodyToMono(String.class)
.subscribe(result -> {
try {
MDC.setContextMap(mdcMap);
LOGGER.info("webClient response：{}", result);
} finally {
MDC.clear();
latch.countDown();
}
}, throwable -> {
try {
MDC.setContextMap(mdcMap);
LOGGER.error("webClient error", throwable);
} finally {
MDC.clear();
}
});
latch.await();
}
}
輸出紀錄檔如下，注意執行緒的變化：
[main][INFO][com.example.Client][8c984fa8-e3cd-4914-875e-ba333d31c7a9] webClient request syncMDC
[reactor-http-nio-2][INFO][com.example.Client][8c984fa8-e3cd-4914-875e-ba333d31c7a9] webClient response：syncMDC
與 HTTP 呼叫類似，基於Dubbo的 RPC 呼叫也是可以跟蹤的，利用Dubbo的Filter和SPI序號產生器制，我們可以增加自己的過濾器實現紀錄檔鏈路跟蹤：
import org.apache.dubbo.common.extension.Activate;
import org.apache.dubbo.rpc.*;
import org.slf4j.MDC;
import java.util.UUID;
/**
* 服務鏈路跟蹤過濾器
*/
@Activate
public class RpcTraceFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
RpcContext context = RpcContext.getContext();
boolean shouldRemove = false;
if (context.isProviderSide()) {
// 獲取消費端設定的引數
String traceId = context.getAttachment("traceId");
if (traceId == null || traceId.isEmpty()) {
traceId = MDC.get("traceId");
if (traceId == null || traceId.isEmpty()) {
traceId = UUID.randomUUID().toString();
shouldRemove = true;
}
}
// 設定 traceId
MDC.put("traceId", traceId);
// 繼續設定下游引數，供在提供方里面作為消費端時，其他服務提供方使用這些引數
context.setAttachment("traceId", traceId);
} else if (context.isConsumerSide()) {
// 如果連續呼叫多個服務，則會使用同個執行緒裡之前設定的traceId
String traceId = MDC.get("traceId");
if (traceId == null || traceId.isEmpty()) {
traceId = UUID.randomUUID().toString();
// 設定 traceId
MDC.put("traceId", traceId);
shouldRemove = true;
}
// 設定傳遞到提供端的引數
context.setAttachment("traceId", traceId);
}
try {
return invoker.invoke(invocation);
} finally {
// 呼叫完成後移除MDC屬性
if (shouldRemove) {
MDC.clear();
}
}
}
}
在需要用到的服務模組的resource/META-INF/dubbo/org.apache.dubbo.rpc.Filter檔案中註冊過濾器（注意路徑和名稱不能錯）：
rpcTraceFilter=com.example.RpcTraceFilter
SpringBoot的application.properties中增加設定（為了簡單驗證，這裡沒有使用註冊中心。如果你想更嚴謹地測試，建議在本地啟動兩個獨立的工程，並使用ZooKeeper進行服務註冊）：
dubbo.application.name=MDCExample
dubbo.scan.base-packages=com.example
dubbo.registry.address=N/A
# dubbo filter
dubbo.consumer.filter=rpcTraceFilter
dubbo.provider.filter=rpcTraceFilter
增加一個簡單的Dubbo服務：
import org.apache.dubbo.config.annotation.DubboService;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@DubboService
public class RpcService implements IRpcService {
private static final Logger LOGGER = LoggerFactory.getLogger(RpcService.class);
public String mdcRpc() {
LOGGER.info("Calling RPC service.");
return "mdcRpc";
}
}
在Controller中增加一個方法，進行驗證：
import org.apache.dubbo.config.annotation.DubboReference;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.context.annotation.Configuration;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurer;
import java.util.Map;
import java.util.concurrent.Callable;
@RestController
public class MDCController {
// ......（省略前面的程式碼）
@DubboReference
private IRpcService rpcService;
@GetMapping("/mdcRpc")
public String mdcRpc() {
LOGGER.info("rpc MDC test.");
return rpcService.mdcRpc();
}
}
存取Controller方法，應該能得到類似下面的輸出：
[http-nio-8080-exec-1][INFO][com.example.LogInterceptor][f003f750-2044-41ae-a041-8a76eb0c415b] preHandle DispatcherType.REQUEST type with DispatcherType REQUEST
[http-nio-8080-exec-1][INFO][com.example.MDCController][f003f750-2044-41ae-a041-8a76eb0c415b] rpc MDC test.
[http-nio-8080-exec-1][INFO][com.example.RpcService][f003f750-2044-41ae-a041-8a76eb0c415b] Calling RPC service.
[http-nio-8080-exec-1][INFO][com.example.LogInterceptor][f003f750-2044-41ae-a041-8a76eb0c415b] afterCompletion Clearing MDC with DispatcherType REQUEST
前面提到過跨執行緒呼叫時，需要自己處理MDC上下文的傳遞，如果是單個執行緒，可以手工進行處理，但如果是執行緒池，似乎就不能這麼幹了。執行緒池種類繁多，處理方式也有細微差別，這裡不可能全部列舉，以Spring專案中常用的 ThreadPoolTaskExecutor為例，我們可以利用它提供的setTaskDecorator方法對任務進行裝飾：
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
import org.springframework.context.annotation.Bean;
import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
import java.util.Map;
import java.util.UUID;
public class MDCExecutor {
private static final Logger LOGGER = LoggerFactory.getLogger(MDCExecutor.class);
public static void main(String[] args) {
MDC.put("traceId", UUID.randomUUID().toString());
ThreadPoolTaskExecutor executor = asyncTaskExecutor();
executor.initialize();
executor.submit(() -> LOGGER.info("MDC Executor"));
executor.shutdown();
}
@Bean
public static ThreadPoolTaskExecutor asyncTaskExecutor() {
ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
executor.setTaskDecorator(task -> {
Map<String, String> mdcMap = MDC.getCopyOfContextMap();
return () -> {
try {
if (mdcMap != null) {
MDC.setContextMap(mdcMap);
}
task.run();
} finally {
MDC.clear();
}
};
});
return executor;
}
}
對於其他執行緒池，通用的思路是覆寫其submit或者execute方法來實現MDC傳遞，比如我們下面提到的定時任務排程執行緒池。
除了Controller和 RPC 介面發起的呼叫，最常見的就是定時任務了。如果是定時任務作為業務發起源，可以在任務排程的時候對MDC進行處理。這塊處理比較複雜，暫時沒有找到比較優雅的切入點：
增加一個實現RunnableScheduledFuture介面的DecoratedFuture類：
import org.slf4j.MDC;
import java.util.Map;
import java.util.Optional;
import java.util.UUID;
import java.util.concurrent.*;
class DecoratedFuture<V> implements RunnableScheduledFuture<V> {
Runnable runnable;
Callable<V> callable;
final RunnableScheduledFuture<V> task;
public DecoratedFuture(Runnable r, RunnableScheduledFuture<V> task) {
this.task = task;
runnable = r;
}
public DecoratedFuture(Callable<V> c, RunnableScheduledFuture<V> task) {
this.task = task;
callable = c;
}
@Override
public boolean isPeriodic() {
return task.isPeriodic();
}
@Override
public void run() {
try {
Map<String, String> mdcMap = MDC.getCopyOfContextMap();
Optional.ofNullable(mdcMap).ifPresent(MDC::setContextMap);
String traceId = MDC.get("traceId");
if (traceId == null || traceId.isEmpty()) {
traceId = UUID.randomUUID().toString();
}
MDC.put("traceId", traceId);
task.run();
} finally {
MDC.clear();
}
}
@Override
public boolean cancel(boolean mayInterruptIfRunning) {
return task.cancel(mayInterruptIfRunning);
}
@Override
public boolean isCancelled() {
return task.isCancelled();
}
@Override
public boolean isDone() {
return task.isDone();
}
@Override
public V get() throws InterruptedException, ExecutionException {
return task.get();
}
@Override
public V get(long timeout, TimeUnit unit) throws InterruptedException, ExecutionException, TimeoutException {
return task.get(timeout, unit);
}
@Override
public long getDelay(TimeUnit unit) {
return task.getDelay(unit);
}
@Override
public int compareTo(Delayed o) {
return task.compareTo(o);
}
@Override
public int hashCode() {
return task.hashCode();
}
@Override
public boolean equals(Object o) {
if (this == o) {
return true;
}
if (o == null || getClass() != o.getClass()) {
return false;
}
DecoratedFuture<?> that = (DecoratedFuture<?>) o;
return this.task.equals(that.task);
}
public Runnable getRunnable() {
return runnable;
}
public RunnableScheduledFuture<V> getTask() {
return task;
}
public Callable<V> getCallable() {
return callable;
}
}
增加一個實現ThreadPoolTaskScheduler介面的DecoratedThreadPoolTaskScheduler類：
import org.slf4j.MDC;
import org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler;
import java.time.Duration;
import java.time.Instant;
import java.util.Map;
import java.util.Optional;
import java.util.concurrent.RejectedExecutionHandler;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.ScheduledFuture;
import java.util.concurrent.ThreadFactory;
class DecoratedThreadPoolTaskScheduler extends ThreadPoolTaskScheduler {
private static final long serialVersionUID = 1L;
static Runnable withTraceId(Runnable task) {
Map<String,String> mdcMap = MDC.getCopyOfContextMap();
return ()-> {
try {
Optional.ofNullable(mdcMap).ifPresent(MDC::setContextMap);
task.run();
} finally {
MDC.clear();
}
};
}
@Override
protected ScheduledExecutorService createExecutor(int poolSize, ThreadFactory threadFactory, RejectedExecutionHandler rejectedExecutionHandler) {
return new DecoratedScheduledThreadPoolExecutor(poolSize, threadFactory, rejectedExecutionHandler);
}
@Override
public ScheduledFuture<?> schedule(Runnable task, Instant startTime) {
return super.schedule(withTraceId(task), startTime);
}
@Override
public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, Instant startTime, Duration period) {
return super.scheduleAtFixedRate(withTraceId(task), startTime, period);
}
@Override
public ScheduledFuture<?> scheduleAtFixedRate(Runnable task, Duration period) {
return super.scheduleAtFixedRate(withTraceId(task), period);
}
@Override
public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Instant startTime, Duration delay) {
return super.scheduleWithFixedDelay(withTraceId(task), startTime, delay);
}
@Override
public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Duration delay) {
return super.scheduleWithFixedDelay(withTraceId(task), delay);
}
}
增加一個繼承ScheduledThreadPoolExecutor類的DecoratedScheduledThreadPoolExecutor類，覆寫它的兩個decorateTask方法：
import java.util.concurrent.*;
class DecoratedScheduledThreadPoolExecutor extends ScheduledThreadPoolExecutor {
public DecoratedScheduledThreadPoolExecutor(int poolSize, ThreadFactory threadFactory, RejectedExecutionHandler rejectedExecutionHandler) {
super(poolSize, threadFactory, rejectedExecutionHandler);
}
@Override
protected <V> RunnableScheduledFuture<V> decorateTask(Runnable runnable, RunnableScheduledFuture<V> task) {
return new DecoratedFuture<>(runnable, task);
}
@Override
protected <V> RunnableScheduledFuture<V> decorateTask(Callable<V> callable, RunnableScheduledFuture<V> task) {
return new DecoratedFuture<>(callable, task);
}
}
在定時任務Configuration中，建立DecoratedThreadPoolTaskScheduler作為排程執行緒池：
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.scheduling.annotation.EnableAsync;
import org.springframework.scheduling.annotation.EnableScheduling;
import org.springframework.scheduling.annotation.SchedulingConfigurer;
import org.springframework.scheduling.concurrent.ThreadPoolTaskScheduler;
import org.springframework.scheduling.config.ScheduledTaskRegistrar;
/**
* 定時排程設定
*/
@Configuration
@EnableAsync
@EnableScheduling
public class SchedulingConfiguration implements SchedulingConfigurer {
public static final String TASK_SCHEDULER = "taskScheduler";
@Override
public void configureTasks(ScheduledTaskRegistrar taskRegistrar) {
taskRegistrar.setTaskScheduler(taskScheduler());
}
@Bean(TASK_SCHEDULER)
public ThreadPoolTaskScheduler taskScheduler() {
return new DecoratedThreadPoolTaskScheduler();
}
}
新增一個簡單定時任務：
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.scheduling.annotation.Scheduled;
@SpringBootApplication
public class App {
private static final Logger LOGGER = LoggerFactory.getLogger(App.class);
public static void main(String[] args) {
SpringApplication.run(App.class, args);
}
@Scheduled(fixedDelay = 1500)
public void cronTaskConfigRefresh() {
LOGGER.info("MDC task scheduler.");
}
}
可以看到類似下面的輸出，說明就成功了：
[taskScheduler-1][INFO][com.example.App][0959d1a6-4680-4a95-a29b-b62694f0d348] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][8f034b1e-db40-44cb-9fc2-986eb8f0da6d] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][02428e88-53f8-4151-aba0-86e069c96462] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][fcd5d925-95e0-4e28-aa68-39e765668dde] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][b8ed50c6-0d6d-40c0-b170-976717fe7d22] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][9d173a26-41d4-43dc-beae-731a9f267288] MDC task scheduler.
[taskScheduler-1][INFO][com.example.App][0257c93a-9bec-40b7-9447-5a938bd2ce5f] MDC task scheduler.
在實際專案中，通過靈活組合上面的若干種手段，就可以實現輕量化的紀錄檔鏈路跟蹤，在大部分情況下基本上已經夠用了，當然你也可以引入SkyWalking或ZipKin等探針框架，它們提供的功能也更全面更豐富。如何選擇，需要根據具體專案自行權衡。