一、背景
開發排查系統問題用得最多的手段就是查看系統日志,在分布式環境中一般使用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<String, String> mdcContext = MDC.getCopyOfContextMap();
super.execute(() -> run(runnable, mdcContext));
}
@Override
public <T> Future<T> submit(Callable<T> task) {
Map<String, String> mdcContext = MDC.getCopyOfContextMap();
return super.submit(() -> call(task, mdcContext));
}
/**
* 子線程委托的執行方法
* @param runnable {@link Runnable}
* @param mdcContext 父線程MDC內容
*/
private void run(Runnable runnable, String tenantId, Map<String, String> mdcContext) {
// 將父線程的MDC內容傳給子線程
if (mdcContext != null) {
MDC.setContextMap(mdcContext);
}
try {
// 執行異步操作
runnable.run();
} finally {
// 清空MDC內容
MDC.clear();
}
}
/**
* 子線程委托的執行方法
* @param task {@link Callable}
* @param mdcContext 父線程MDC內容
*/
private <T> T call(Callable<T> task, Map<String, String> 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
的值,在日志中心中詢該請求的所有日志信息
五、源碼下載
附上我的開源微服務框架(包含本文中的代碼),歡迎 star 關注
https://gitee.com/zlt2000/microservices-platform