【Logback+Spring-Aop】實現全面生態化的全鏈路紀錄檔追蹤系統服務外掛「Logback-MDC篇」
2022-11-20 15:03:50
紀錄檔追蹤
紀錄檔追蹤對於功能問題的排查和資料流轉的路徑分析時非常重要的，有了全鏈路紀錄檔追蹤體系機制可以非常有效且快速的定位問題，但在多執行緒環境中，若沒有相關成熟的框架的支援，想要實現紀錄檔追蹤，就需要手動將主執行緒中的紀錄檔引數傳遞給子執行緒，接下來就線上程池場景下藉助MDC實現了traceId引數的透傳。
候選方案
-
方案1：解決辦法是採用自定義的紀錄檔格式，把使用者的資訊採用某種方式編碼在紀錄檔記錄中。這種方式的問題在於要求在每個使用紀錄檔記錄器的類中，都可以存取到使用者相關的資訊。這樣才可能在記錄紀錄檔時使用。這樣的條件通常是比較難以滿足的，MDC的作用是解決這個問題。
-
方案2： MDC（Mapped Diagnostic Context，對映偵錯上下文） 是slf4j提供的一種輕量級的紀錄檔跟蹤工具，Log4j、Logback或者Log4j2等紀錄檔中最常見區分同一個請求的方式是通過執行緒名/執行緒ID，但是而如果請求量大，執行緒名/執行緒ID會在相鄰的時間內出現多次重複的列印，因此引出了trace-id，即在接收到的時候生成唯一的請求id，在整個執行鏈路中帶上此唯一id。
Sl4fj的MDC模式的介紹
Sl4fj的MDC的原始碼
public class MDC {
static final String NULL_MDCA_URL = "http://www.slf4j.org/codes.html#null_MDCA";
static final String NO_STATIC_MDC_BINDER_URL = "http://www.slf4j.org/codes.html#no_static_mdc_binder";
static MDCAdapter mdcAdapter;
private MDC() {
}
private static MDCAdapter bwCompatibleGetMDCAdapterFromBinder() throws NoClassDefFoundError {
try {
return StaticMDCBinder.getSingleton().getMDCA();
} catch (NoSuchMethodError var1) {
return StaticMDCBinder.SINGLETON.getMDCA();
}
}
public static void put(String key, String val) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key parameter cannot be null");
} else if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA");
} else {
mdcAdapter.put(key, val);
}
}
public static MDCCloseable putCloseable(String key, String val) throws IllegalArgumentException {
put(key, val);
return new MDCCloseable(key);
}
public static String get(String key) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key parameter cannot be null");
} else if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA");
} else {
return mdcAdapter.get(key);
}
}
public static void remove(String key) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key parameter cannot be null");
} else if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA");
} else {
mdcAdapter.remove(key);
}
}
public static void clear() {
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA");
} else {
mdcAdapter.clear();
}
}
public static Map<String, String> getCopyOfContextMap() {
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA");
} else {
return mdcAdapter.getCopyOfContextMap();
}
}
public static void setContextMap(Map<String, String> contextMap) {
if (mdcAdapter == null) {
throw new IllegalStateException("MDCAdapter cannot be null. See also http://www.slf4j.org/codes.html#null_MDCA");
} else {
mdcAdapter.setContextMap(contextMap);
}
}
public static MDCAdapter getMDCAdapter() {
return mdcAdapter;
}
static {
try {
mdcAdapter = bwCompatibleGetMDCAdapterFromBinder();
} catch (NoClassDefFoundError var2) {
mdcAdapter = new NOPMDCAdapter();
String msg = var2.getMessage();
if (msg == null || !msg.contains("StaticMDCBinder")) {
throw var2;
}
Util.report("Failed to load class \"org.slf4j.impl.StaticMDCBinder\".");
Util.report("Defaulting to no-operation MDCAdapter implementation.");
Util.report("See http://www.slf4j.org/codes.html#no_static_mdc_binder for further details.");
} catch (Exception var3) {
Util.report("MDC binding unsuccessful.", var3);
}
}
public static class MDCCloseable implements Closeable {
private final String key;
private MDCCloseable(String key) {
this.key = key;
}
public void close() {
MDC.remove(this.key);
}
}
}
Sl4fj的MDC模式主要的門面類是MDC.java，但是最核心的類是MDCAdapter，可由下面的程式碼觀測出。
對應而定實現載入所有相關的MDCAdapter的類就在這裡，而程式碼裡面的功能展示資訊也是我們經常會遇見的，如果出現錯誤的時候，經常會列印再紀錄檔的最開始部分。
Sl4fj的MDCAdapter的原始碼
大家可以觀察到對應的MDCAdapter的實現類有一下這幾種，基本上是會交由第三方去實現的。
而對於Sl4j本身不提供傳遞traceId的能力，真正提供能力的是MDCAdapter介面的實現。
Logback使用的是LogbackMDCAdapter。比如Log4j的是Log4jMDCAdapter，Logback的是LogbackMDCAdapter。其內部自己的MDCAdapter屬於空實現的NOPMDCAdapter類和BasicMDCAdapter，第三方的OPMDCAdapter，不太瞭解。
MDC的實現原理
- MDC可以看成是每個執行緒內部都進行頂一個所屬私有的容器（也可以理解為雜湊表），我們可以通過程式往其中新增鍵值對。
- MDC內的資料可以被當前執行緒的程式碼所存取，當前執行緒所產生的子執行緒也會繼承其父執行緒中的MDC的資料，當需要記錄紀錄檔時，只需要從MDC中獲取所需的資訊即可。
- MDC 的內容則由程式在適當的時候儲存進去。對於一個 Web 應用來說，通常是在請求被處理的最開始儲存這些資料。
Sl4j的MDCAdapter的實現機制
public class BasicMDCAdapter implements MDCAdapter {
private InheritableThreadLocal<Map<String, String>> inheritableThreadLocal = new InheritableThreadLocal<Map<String, String>>() {
protected Map<String, String> childValue(Map<String, String> parentValue) {
return parentValue == null ? null : new HashMap(parentValue);
}
};
public BasicMDCAdapter() {
}
public void put(String key, String val) {
if (key == null) {
throw new IllegalArgumentException("key cannot be null");
} else {
Map<String, String> map = (Map)this.inheritableThreadLocal.get();
if (map == null) {
map = new HashMap();
this.inheritableThreadLocal.set(map);
}
((Map)map).put(key, val);
}
}
public String get(String key) {
Map<String, String> map = (Map)this.inheritableThreadLocal.get();
return map != null && key != null ? (String)map.get(key) : null;
}
public void remove(String key) {
Map<String, String> map = (Map)this.inheritableThreadLocal.get();
if (map != null) {
map.remove(key);
}
}
public void clear() {
Map<String, String> map = (Map)this.inheritableThreadLocal.get();
if (map != null) {
map.clear();
this.inheritableThreadLocal.remove();
}
}
public Set<String> getKeys() {
Map<String, String> map = (Map)this.inheritableThreadLocal.get();
return map != null ? map.keySet() : null;
}
public Map<String, String> getCopyOfContextMap() {
Map<String, String> oldMap = (Map)this.inheritableThreadLocal.get();
return oldMap != null ? new HashMap(oldMap) : null;
}
public void setContextMap(Map<String, String> contextMap) {
this.inheritableThreadLocal.set(new HashMap(contextMap));
}
}
Logback的MDC模式
- LogbackMDCAdapter類實現MDCAdapter介面，實現 put、get、remove等方法。
- copyOnThreadLocal：儲存每個執行緒的多個變數
當在logback.xml中設定了%X{key} 或 SiftingAppender的
的 。，在需要輸出紀錄檔的時候，從MDC中獲取對應的key值，然後append到紀錄檔字串中或生成檔案路徑，然後輸出
LogbackMDCAdapter的原始碼分析
public class LogbackMDCAdapter implements MDCAdapter {
final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal();
private static final int WRITE_OPERATION = 1;
private static final int MAP_COPY_OPERATION = 2;
final ThreadLocal<Integer> lastOperation = new ThreadLocal();
public LogbackMDCAdapter() {
}
private Integer getAndSetLastOperation(int op) {
Integer lastOp = (Integer)this.lastOperation.get();
this.lastOperation.set(op);
return lastOp;
}
private boolean wasLastOpReadOrNull(Integer lastOp) {
return lastOp == null || lastOp == 2;
}
private Map<String, String> duplicateAndInsertNewMap(Map<String, String> oldMap) {
Map<String, String> newMap = Collections.synchronizedMap(new HashMap());
if (oldMap != null) {
synchronized(oldMap) {
newMap.putAll(oldMap);
}
}
this.copyOnThreadLocal.set(newMap);
return newMap;
}
public void put(String key, String val) throws IllegalArgumentException {
if (key == null) {
throw new IllegalArgumentException("key cannot be null");
} else {
Map<String, String> oldMap = (Map)this.copyOnThreadLocal.get();
Integer lastOp = this.getAndSetLastOperation(1);
if (!this.wasLastOpReadOrNull(lastOp) && oldMap != null) {
oldMap.put(key, val);
} else {
Map<String, String> newMap = this.duplicateAndInsertNewMap(oldMap);
newMap.put(key, val);
}
}
}
public void remove(String key) {
if (key != null) {
Map<String, String> oldMap = (Map)this.copyOnThreadLocal.get();
if (oldMap != null) {
Integer lastOp = this.getAndSetLastOperation(1);
if (this.wasLastOpReadOrNull(lastOp)) {
Map<String, String> newMap = this.duplicateAndInsertNewMap(oldMap);
newMap.remove(key);
} else {
oldMap.remove(key);
}
}
}
}
public void clear() {
this.lastOperation.set(1);
this.copyOnThreadLocal.remove();
}
public String get(String key) {
Map<String, String> map = (Map)this.copyOnThreadLocal.get();
return map != null && key != null ? (String)map.get(key) : null;
}
public Map<String, String> getPropertyMap() {
this.lastOperation.set(2);
return (Map)this.copyOnThreadLocal.get();
}
public Set<String> getKeys() {
Map<String, String> map = this.getPropertyMap();
return map != null ? map.keySet() : null;
}
public Map<String, String> getCopyOfContextMap() {
Map<String, String> hashMap = (Map)this.copyOnThreadLocal.get();
return hashMap == null ? null : new HashMap(hashMap);
}
public void setContextMap(Map<String, String> contextMap) {
this.lastOperation.set(1);
Map<String, String> newMap = Collections.synchronizedMap(new HashMap());
newMap.putAll(contextMap);
this.copyOnThreadLocal.set(newMap);
}
主要問題是針對於Collections.synchronizedMap(new HashMap())，建立HashMap的安全模式進行構建容器物件，所以是執行緒安全的問題控制。
final ThreadLocal<Map<String, String>> copyOnThreadLocal = new ThreadLocal();
某些應用程式採用多執行緒的方式來處理多個使用者的請求。在一個使用者的使用過程中，可能有多個不同的執行緒來進行處理。典型的例子是Web應用伺服器。當用戶存取某個頁面時，應用伺服器可能會建立一個新的執行緒來處理該請求，也可能從執行緒池中複用已有的執行緒。
MDC的簡單使用方式
新增traceId
MDC.put(「trace-id」, traceId);
移除traceId
MDC.remove(「trace-id」);
在紀錄檔組態檔中
<?xml version="1.0" encoding="UTF-8"?>
<configuration>
<appender name="console" class="ch.qos.logback.core.ConsoleAppender">
<encoder charset="UTF-8">
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%trace-id] %-5level %logger{36} - %msg%n</pattern>
</encoder>
</appender>
<logger name="com.XXX" level = "INFO">
<appender-ref ref="console"/>
</logger>
</configuration>
此外logback 中也可以使用預留位置%X{ }來佔位，替換到對應的 MDC 中 key 的值
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<layout>
<Pattern>%X{trace-id}- %m%n</Pattern>
</layout>
</appender>
MDC的難點功課實戰
多執行緒情況下的MDC實現問題
當我們處於多個執行緒之間進行傳遞traceId的時候，可能就會存在ThreadLocal的問題了。那麼如果要破除ThreadLocal只對當前執行緒有線的方法：
- （針對於跨執行緒傳遞的問題）可以採用JDK自帶的、ThreadLocal的擴充套件類InheritableThreadLocal，子執行緒會拷貝父執行緒中的變數值
- （針對於執行緒池執行緒複用的問題）引入alibaba包的TransmittableThreadLocal實現
- （針對於執行緒池執行緒複用的問題）自己封裝一個執行緒池去處理執行緒池所存在的問題。
針對於跨執行緒傳遞的問題
針對於跨執行緒傳遞traceId的問題，主要通過InheritableThreadLocal的方式進行拷貝傳遞即可，需要注意的是，如果沒有采用執行緒池的場景的化，基本上不會出現什麼問題，但是如果村子啊執行緒池的場景下那麼就只能我們自己手動實現和處理了，如果採用TransmittableThreadLocal的話大家可以自行百度了，在這裡我們主要實現的是自己去通過幾種方式實現功能傳遞。
針對於執行緒池執行緒複用的問題
如果使用的是Spring的執行緒池ThreadPoolTaskExecutor
那麼就可以採用TaskDecorator的執行緒任務裝飾器方式為執行緒池的執行緒提供traceId的傳遞操作，例如以下程式碼。
定義執行緒裝飾器
此處我採用的是log back，如果是log4j或者log4j2還是有一些區別的，比如說MDC.getCopyOfContextMap()。
public class MDCTaskDecorator implements TaskDecorator {
@Override
public Runnable decorate(Runnable runnable) {
// 此時獲取的是父執行緒的上下文資料
Map<String, String> contextMap = MDC.getCopyOfContextMap();
return () -> {
try {
if (contextMap != null) {
// 內部為子執行緒的領域範圍，所以將父執行緒的上下文儲存到子執行緒上下文中，而且每次submit/execute呼叫都會更新為最新的上 // 下文物件
MDC.setContextMap(contextMap);
}
runnable.run();
} finally {
// 清除子執行緒的，避免記憶體溢位，就和ThreadLocal.remove()一個原因
MDC.clear();
}
};
}
}
定義執行緒池
@Bean("taskExecutor")
public Executor taskExecutor() {
ThreadPoolTaskExecutor executor = new ThreadPoolTaskExecutor();
//設定核心執行緒數
executor.setCorePoolSize(5);
//設定最大執行緒數
executor.setMaxPoolSize(10);
//設定佇列大小
executor.setQueueCapacity(100);
//設定執行緒池中的執行緒的名稱字首
executor.setThreadNamePrefix("mdc-trace-");
// 非同步MDC
executor.setTaskDecorator(new MDCTaskDecorator());
//執行初始化
executor.initialize();
return executor;
}
這樣就是先了traceId傳遞到執行緒池中了。
我們自定義執行緒裝飾器
與上面的不同我們如果用的不是spring的執行緒池那麼無法實現TaskDecorator介面，那麼就無法實現他的功能了，此時我們就會定義我們自身的執行緒裝配器。
public class MDCTaskDecorator {
public static <T> Callable<T> buildCallable(final Callable<T> callable, final Map<String, String> context) {
return () -> {
if (CollectionUtils.isEmpty(context)) {
MDC.clear();
} else {
//MDC.put("trace_id", IdUtil.objectId());
MDC.setContextMap(context);
}
try {
return callable.call();
} finally {
// 清除子執行緒的，避免記憶體溢位，就和ThreadLocal.remove()一個原因
MDC.clear();
}
};
}
public static Runnable buildRunnable(final Runnable runnable, final Map<String, String> context) {
return () -> {
if (CollectionUtils.isEmpty(context)) {
MDC.clear();
} else {
//MDC.put("trace_id", IdUtil.objectId());
MDC.setContextMap(context);
}
try {
runnable.run();
} finally {
// 清除子執行緒的，避免記憶體溢位，就和ThreadLocal.remove()一個原因
MDC.clear();
}
};
}
}
清除子執行緒的，避免記憶體溢位，就和ThreadLocal.remove()一個原因
自定義執行緒池進行封裝包裝操作（普通執行緒池）
主執行緒中，如果使用了執行緒池，會導致執行緒池中丟失MDC資訊；解決辦法：需要我們自己重寫執行緒池，在呼叫執行緒跳動run之前，獲取到主執行緒的MDC資訊，重新put到子執行緒中的。
public class ThreadPoolMDCExecutor extends ThreadPoolTaskExecutor {
@Override
public void execute(Runnable task) {
super.execute(MDCTaskDecorator.buildRunnable(task, MDC.getCopyOfContextMap()));
}
@Override
public Future<?> submit(Runnable task) {
return super.submit(MDCTaskDecorator.buildRunnable(task, MDC.getCopyOfContextMap()));
}
@Override
public <T> Future<T> submit(Callable<T> task) {
return super.submit(MDCTaskDecorator.buildCallable(task, MDC.getCopyOfContextMap()));
}
}
自定義執行緒池進行封裝包裝操作（任務排程執行緒池）
public class ThreadPoolMDCScheduler extends ThreadPoolTaskScheduler {
@Override
public ScheduledFuture<?> scheduleWithFixedDelay(Runnable task, Date startTime, long delay) {
return super.scheduleWithFixedDelay(MDCTaskDecorator.buildRunnable(task), startTime, delay);
}
@Override
public ScheduledFuture<?> schedule(Runnable task, Date startTime) {
return super.schedule(MDCTaskDecorator.buildRunnable(task), startTime);
}
}
同理，即使你使用ExecutorCompletionService實現多執行緒呼叫，也是相同的方案和思路機制。
特殊場景-CompletableFuture實現多執行緒呼叫
使用CompletableFuture實現多執行緒呼叫，其中收集CompletableFuture執行結果，也可以手動使用相似的思路進行填充上下文資訊資料，但是別忘記了清理clear就好。
private CompletableFuture<Result> test() {
Map<String, String> copyOfContextMap = MDC.getCopyOfContextMap();
return CompletableFuture.supplyAsync(() -> {
MDC.setContextMap(copyOfContextMap);
//執行業務操作
MDC.clear();
return new Result();
}, threadPoolExecutor).exceptionally(new Function<Throwable, Result>() {
@Override
public Result apply(Throwable throwable) {
log.error("執行緒[{}]發生了異常[{}], 繼續執行其他執行緒", Thread.currentThread().getName(), throwable.getMessage());
MDC.clear();
return null;
}
});
}
最後總結說明
後續的它的姊妹篇【Logback+Spring-Aop】實現全面生態化的全鏈路紀錄檔追蹤系統服務外掛「SpringAOP整合篇」，會進行分析通過SpringAOP模式將Logback的MDC模式與SpringAOP結合形成一個較為體系化的元件，從而減少了很多開發過程中的程式碼和問題。
極限就是為了超越而存在的