日誌排查問題困難?分散式日誌鏈路跟蹤來幫你
作者:朱樂陶,軟體架構師,具備多年Java開發及架構設計經驗,擅長微服務領域
作者部落格:https://blog.csdn.net/zlt2000
背景
開發排查系統問題用得最多的手段就是檢視系統日誌,在分散式環境中一般使用ELK來統一收集日誌,但是在併發大時使用日誌定位問題還是比較麻煩,由於大量的其他使用者/其他執行緒的日誌也一起輸出穿行其中導致很難篩選出指定請求的全部相關日誌,以及下游執行緒/服務對應的日誌。
解決思路
每個請求都使用一個唯一標識來追蹤全部的鏈路顯示在日誌中,並且不修改原有的列印方式(程式碼無入侵)使用Logback的MDC機制日誌模板中加入traceId標識,取值方式為%X{traceId}
MDC(Mapped Diagnostic Context,對映除錯上下文)是 log4j 和 logback 提供的一種方便在多執行緒條件下記錄日誌的功能。MDC 可以看成是一個與當前執行緒繫結的Map,可以往其中新增鍵值對。MDC 中包含的內容可以被同一執行緒中執行的程式碼所訪問。當前執行緒的子執行緒會繼承其父執行緒中的 MDC 的內容。當需要記錄日誌時,只需要從 MDC 中獲取所需的資訊即可。MDC 的內容則由程式在適當的時候儲存進去。對於一個 Web 應用來說,通常是在請求被處理的最開始儲存這些資料。
方案實現
由於MDC內部使用的是ThreadLocal所以只有本執行緒才有效,子執行緒和下游的服務MDC裡的值會丟失;所以方案主要的難點是解決值的傳遞問題,主要包括以幾下部分:
- API閘道器中的MDC資料如何傳遞給下游服務
- 服務如何接收資料,並且呼叫其他遠端服務時如何繼續傳遞
- 非同步的情況下(執行緒池)如何傳給子執行緒
修改日誌模板
logback配置檔案模板格式新增標識%X{traceId}
閘道器新增過濾器
生成traceId並通過header傳遞給下游服務
@Component
public class TraceFilter extends ZuulFilter {
@Autowired
private TraceProperties traceProperties;
@Override
public String filterType() {
return FilterConstants.PRE_TYPE;
}
@Override
public int filterOrder() {
return FORM_BODY_WRAPPER_FILTER_ORDER - 1;
}
@Override
public boolean shouldFilter() {
//根據配置控制是否開啟過濾器
return traceProperties.getEnable();
}
@Override
public Object run() {
//鏈路追蹤id
String traceId = IdUtil.fastSimpleUUID();
MDC.put(CommonConstant.LOG_TRACE_ID,traceId);
RequestContext ctx = RequestContext.getCurrentContext();
ctx.addZuulRequestHeader(CommonConstant.TRACE_ID_HEADER,traceId);
return null;
}
}
複製程式碼
下游服務增加spring攔截器
接收並儲存traceId的值攔截器
public class TraceInterceptor implements HandlerInterceptor {
@Override
public boolean preHandle(HttpServletRequest request,HttpServletResponse response,Object handler) {
String traceId = request.getHeader(CommonConstant.TRACE_ID_HEADER);
if (StrUtil.isNotEmpty(traceId)) {
MDC.put(CommonConstant.LOG_TRACE_ID,traceId);
}
return true;
}
}
複製程式碼
註冊攔截器
public class DefaultWebMvcConfig extends WebMvcConfigurationSupport {
@Override
protected void addInterceptors(InterceptorRegistry registry) {
//日誌鏈路追蹤攔截器
registry.addInterceptor(new TraceInterceptor()).addPathPatterns("/**");
super.addInterceptors(registry);
}
}
複製程式碼
下游服務增加feign攔截器
繼續把當前服務的traceId值傳遞給下游服務
public class FeignInterceptorConfig {
@Bean
public RequestInterceptor requestInterceptor() {
RequestInterceptor requestInterceptor = template -> {
//傳遞日誌traceId
String traceId = MDC.get(CommonConstant.LOG_TRACE_ID);
if (StrUtil.isNotEmpty(traceId)) {
template.header(CommonConstant.TRACE_ID_HEADER,traceId);
}
};
return requestInterceptor;
}
}
複製程式碼
解決父子執行緒傳遞問題
主要針對業務會使用執行緒池(非同步、並行處理),並且spring自己也有@Async註解來使用執行緒池,要解決這個問題需要以下兩個步驟
重寫logback的LogbackMDCAdapter
由於logback的MDC實現內部使用的是ThreadLocal不能傳遞子執行緒,所以需要重寫替換為阿里的TransmittableThreadLocal
TransmittableThreadLocal 是Alibaba開源的、用於解決 “在使用執行緒池等會快取執行緒的元件情況下傳遞ThreadLocal” 問題的 InheritableThreadLocal 擴充套件。若希望 TransmittableThreadLocal 線上程池與主執行緒間傳遞,需配合 TtlRunnable 和 TtlCallable 使用。
TtlMDCAdapter類
package org.slf4j;
import com.alibaba.ttl.TransmittableThreadLocal;
import org.slf4j.spi.MDCAdapter;
public class TtlMDCAdapter implements MDCAdapter {
/**
* 此處是關鍵
*/
private final ThreadLocal<Map<String,String>> copyOnInheritThreadLocal = new TransmittableThreadLocal<>();
private static TtlMDCAdapter mtcMDCAdapter;
static {
mtcMDCAdapter = new TtlMDCAdapter();
MDC.mdcAdapter = mtcMDCAdapter;
}
public static MDCAdapter getInstance() {
return mtcMDCAdapter;
}複製程式碼
其他程式碼與ch.qos.logback.classic.util.LogbackMDCAdapter一樣,只需改為呼叫copyOnInheritThreadLocal變數
TtlMDCAdapterInitializer類用於程式啟動時載入自己的mdcAdapter實現
public class TtlMDCAdapterInitializer implements ApplicationContextInitializer<ConfigurableApplicationContext> {
@Override
public void initialize(ConfigurableApplicationContext applicationContext) {
//載入TtlMDCAdapter例項
TtlMDCAdapter.getInstance();
}
}
複製程式碼
擴充套件執行緒池實現
增加TtlRunnable和TtlCallable擴充套件實現TTL
public class CustomThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {
@Override
public void execute(Runnable runnable) {
Runnable ttlRunnable = TtlRunnable.get(runnable);
super.execute(ttlRunnable);
}
@Override
public <T> Future<T> submit(Callable<T> task) {
Callable ttlCallable = TtlCallable.get(task);
return super.submit(ttlCallable);
}
@Override
public Future<?> submit(Runnable task) {
Runnable ttlRunnable = TtlRunnable.get(task);
return super.submit(ttlRunnable);
}
@Override
public ListenableFuture<?> submitListenable(Runnable task) {
Runnable ttlRunnable = TtlRunnable.get(task);
return super.submitListenable(ttlRunnable);
}
@Override
public <T> ListenableFuture<T> submitListenable(Callable<T> task) {
Callable ttlCallable = TtlCallable.get(task);
return super.submitListenable(ttlCallable);
}
}
複製程式碼
場景測試
測試程式碼如下
api閘道器列印的日誌
閘道器生成traceId值為13d9800c8c7944c78a06ce28c36de670
請求跳轉到檔案服務時列印的日誌
顯示的traceId與閘道器相同,這裡特意模擬發生異常的場景
ELK聚合日誌通過traceId查詢整條鏈路日誌
當系統出現異常時,可直接通過該異常日誌的traceId的值,在日誌中心中詢該請求的所有日誌資訊
原始碼下載
附上我的開源微服務框架(包含本文中的程式碼),歡迎 star 關注
https://gitee.com/zlt2000/microservices-platform
掃一掃,支援下作者吧
(轉載本站文章請註明作者和出處 方誌朋的部落格)