一、背景
開發排查系統問題用得最多的手段就是查看系統日誌，在分佈式環境中一般使用ELK來統一收集日誌，但是在併發大時使用日誌定位問題還是比較麻煩，由於大量的其他用戶/其他線程的日誌也一起輸出穿行其中導致很難篩選出指定請求的全部相關日誌，以及下游線程/服務對應的日誌。
二、解決思路
- 每個請求都使用一個唯一標識來追蹤全部的鏈路顯示在日誌中，並且不修改原有的打印方式(代碼無入侵)
- 使用Logback的MDC機制日誌模板中加入traceId標識，取值方式為%X{traceId}
MDC（Mapped Diagnostic Context，映射調試上下文）是 log4j 和 logback 提供的一種方便在多線程條件下記錄日誌的功能。MDC 可以看成是一個與當前線程綁定的Map，可以往其中添加鍵值對。MDC 中包含的內容可以被同一線程中執行的代碼所訪問。當前線程的子線程會繼承其父線程中的 MDC 的內容。當需要記錄日誌時，只需要從 MDC 中獲取所需的信息即可。MDC 的內容則由程序在適當的時候保存進去。對於一個 Web 應用來說，通常是在請求被處理的最開始保存這些數據。
三、方案實現
由於MDC內部使用的是ThreadLocal所以只有本線程才有效，子線程和下游的服務MDC裡的值會丟失；所以方案主要的難點是解決值的傳遞問題。
3.1. 修改日誌模板
logback配置文件模板格式添加標識%X{traceId}
3.2. 網關添加過濾器
生成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; } }
3.3. 下游服務增加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);
}
}
3.4. 下游服務增加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;
}
}
3.5. 擴展線程池
主要針對業務會使用線程池(異步、並行處理)，並且spring自己也有@Async註解來使用線程池，所以需要擴展ThreadPoolTaskExecutor線程池實現將父線程的MDC內容複製給子線程
public class CustomThreadPoolTaskExecutor extends ThreadPoolTaskExecutor {
/**
* 把父線程的MDC內容賦值給子線程
* @param runnable
*/
@Override
public void execute(Runnable runnable) {
Map mdcContext = MDC.getCopyOfContextMap();
super.execute(() -> run(runnable, mdcContext));
}
@Override
public Future submit(Callable task) {
Map mdcContext = MDC.getCopyOfContextMap();
return super.submit(() -> call(task, mdcContext));
}
/**
* 子線程委託的執行方法
* @param runnable {@link Runnable}
* @param mdcContext 父線程MDC內容
*/
private void run(Runnable runnable, String tenantId, Map mdcContext) {
// 將父線程的MDC內容傳給子線程
if (mdcContext != null) {
MDC.setContextMap(mdcContext);
}
try {
// 執行異步操作
runnable.run();
} finally {
// 清空MDC內容
MDC.clear();
}
}
/**
* 子線程委託的執行方法
* @param task {@link Callable}
* @param mdcContext 父線程MDC內容
*/
private T call(Callable task, Map mdcContext) throws Exception {
// 將父線程的MDC內容傳給子線程
if (mdcContext != null) {
MDC.setContextMap(mdcContext);
}
try {
// 執行異步操作
return task.call();
} finally {
// 清空MDC內容
MDC.clear();
}
}
}
四、場景測試
4.1. 測試代碼如下
4.2. api網關打印的日誌
網關生成traceId值為
13d9800c8c7944c78a06ce28c36de670
4.3. 請求跳轉到文件服務時打印的日誌
顯示的traceId與網關相同，這裡特意模擬發生異常的場景
4.4. ELK聚合日誌通過traceId查詢整條鏈路日誌
當系統出現異常時，可直接通過該異常日誌的traceId的值，在日誌中心中詢該請求的所有日誌信息
關注、轉發、評論頭條號每天分享java 知識，私信回覆“java”贈送Spring源碼分析、Dubbo、Redis、Netty、zookeeper、Spring cloud、分佈式資料
