日誌排查問題困難？分佈式日誌鏈路跟蹤來幫你

時間 2019-11-08

原文原文鏈接

做者：朱樂陶，軟件架構師，具有多年Java開發及架構設計經驗，擅長微服務領域
做者博客： https://blog.csdn.net/zlt2000

背景

開發排查系統問題用得最多的手段就是查看系統日誌，在分佈式環境中通常使用ELK來統一收集日誌，可是在併發大時使用日誌定位問題仍是比較麻煩，因爲大量的其餘用戶/其餘線程的日誌也一塊兒輸出穿行其中致使很難篩選出指定請求的所有相關日誌，以及下游線程/服務對應的日誌。git

解決思路

每一個請求都使用一個惟一標識來追蹤所有的鏈路顯示在日誌中，而且不修改原有的打印方式(代碼無入侵)
使用Logback的MDC機制日誌模板中加入traceId標識，取值方式爲%X{traceId}spring

MDC（Mapped Diagnostic Context，映射調試上下文）是 log4j 和 logback 提供的一種方便在多線程條件下記錄日誌的功能。MDC 能夠當作是一個與當前線程綁定的Map，能夠往其中添加鍵值對。MDC 中包含的內容能夠被同一線程中執行的代碼所訪問。當前線程的子線程會繼承其父線程中的 MDC 的內容。當須要記錄日誌時，只須要從 MDC 中獲取所需的信息便可。MDC 的內容則由程序在適當的時候保存進去。對於一個 Web 應用來講，一般是在請求被處理的最開始保存這些數據。

方案實現

因爲MDC內部使用的是ThreadLocal因此只有本線程纔有效，子線程和下游的服務MDC裏的值會丟失；因此方案主要的難點是解決值的傳遞問題，主要包括以幾下部分：segmentfault

API網關中的MDC數據如何傳遞給下游服務
服務如何接收數據，而且調用其餘遠程服務時如何繼續傳遞
異步的狀況下(線程池)如何傳給子線程

修改日誌模板

logback配置文件模板格式添加標識%X{traceId}api

網關添加過濾器

生成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註解來使用線程池，要解決這個問題須要如下兩個步驟app

重寫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/mic...

<div>

<p align="center">
    <img src="https://www.fangzhipeng.com/img/avatar.jpg" width="258" height="258"/>
    <br>
    掃一掃，支持下做者吧
</p>
<p align="center" style="margin-top: 15px; font-size: 11px;color: #cc0000;">
    <strong>（轉載本站文章請註明做者和出處 <a href="https://www.fangzhipeng.com">方誌朋的博客</a>）</strong>
</p>

</div>