前言

在傳統系統中，如果能夠提供日誌輸出，基本上已經能夠滿足需求的。但一旦將系統拆分成兩套及以上的系統，再加上負載均衡等，呼叫鏈路就變得複雜起來。

特別是進一步向微服務方向演化，如果沒有日誌的合理規劃、鏈路追蹤，那麼排查日誌將變得異常困難。

比如系統A、B、C，呼叫鏈路為A -> B -> C，如果每套服務都是雙活，則呼叫路徑有2的三次方種可能性。如果系統更多，服務更多，呼叫鏈路則會成指數增長。

因此，無論是幾個簡單的內部服務呼叫，還是複雜的微服務系統，都需要通過一個機制來實現日誌的鏈路追蹤。讓你係統的日誌輸出，像詩一樣有形式美，又有和諧的韻律。

日誌追蹤其實已經有很多現成的框架了，比如Sleuth、Zipkin等元件。但這不是我們要講的重點，本文重點基於Spring Boot、LogBack來手寫實現一個簡單的日誌呼叫鏈路追蹤功能。基於此實現模式，大家可以更細粒度地去實現。

Spring Boot中整合Logback

Spring Boot本身就內建了日誌功能，這裡使用logback日誌框架，並對輸出結果進行格式化。先來看一下SpringBoot對Logback的內建整合，依賴關係如下。當專案中引入了：

<dependency>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-starter-web</artifactId>
</dependency>

spring-boot-starter-web中間接引入了：

<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-starter</artifactId>
</dependency>

spring-boot-starter又引入了logging的starter：

<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-starter-logging</artifactId>
</dependency>

在logging中真正引入了所需的logback包：

<dependency>
  <groupId>ch.qos.logback</groupId>
  <artifactId>logback-classic</artifactId>
</dependency>
<dependency>
  <groupId>org.apache.logging.log4j</groupId>
  <artifactId>log4j-to-slf4j</artifactId>
</dependency>
<dependency>
  <groupId>org.slf4j</groupId>
  <artifactId>jul-to-slf4j</artifactId>
</dependency>

因此，我們使用時，只需將logback-spring.xml配置檔案放在resources目錄下即可。理論上配置檔案命名為logback.xml也是支援的，但Spring Boot官網推薦使用的名稱為：logback-spring.xml。

然後，在logback-spring.xml中進行日誌輸出的配置即可。這裡不貼全部程式碼了，只貼出來相關日誌輸出格式部分，以控制檯輸出為例：

<property name="CONSOLE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %contextName [%thread] %-5level [%X{requestId}] %logger{36} - %msg%n"/>

在value屬性的表示式中，我們新增了自定義的變數值requestId，通過“[%X{requestId}]”的形式來展示。

這個requestId便是我們用來追蹤日誌的唯一標識。如果一個請求，從頭到尾都使用了同一個requestId便可以把整個請求鏈路串聯起來。如果系統還基於EKL等日誌蒐集工具進行統一收集，就可以更方便地檢視整個日誌的呼叫鏈路了。

那麼，這個requestId變數是如何來的，又儲存在何處呢？要了解這個，我們要先來了解一下日誌框架提供的MDC功能。

什麼是MDC？

MDC(Mapped Diagnostic Contexts) 是一個執行緒安全的存放診斷日誌的容器。MDC是slf4j提供的適配其他具體日誌實現包的工具類，目前只有logback和log4j支援此功能。

MDC是執行緒獨立、執行緒安全的，通常無論是HTTP還是RPC請求，都是在各自獨立的執行緒中完成的，這與MDC的機制可以很好地契合。

在使用MDC功能時，我們主要使用是put方法，該方法間接的呼叫了MDCAdapter介面的put方法。

看一下介面MDCAdapter其中一個實現類BasicMDCAdapter中的程式碼來：

public class BasicMDCAdapter implements MDCAdapter {

    private InheritableThreadLocal<Map<String, String>> inheritableThreadLocal = new InheritableThreadLocal<Map<String, String>>() {
        @Override
        protected Map<String, String> childValue(Map<String, String> parentValue) {
            if (parentValue == null) {
                return null;
            }
            return new HashMap<String, String>(parentValue);
        }
    };

    public void put(String key, String val) {
        if (key == null) {
            throw new IllegalArgumentException("key cannot be null");
        }
        Map<String, String> map = inheritableThreadLocal.get();
        if (map == null) {
            map = new HashMap<String, String>();
            inheritableThreadLocal.set(map);
        }
        map.put(key, val);
    }
    // ...
}

通過原始碼可以看出內部持有一個InheritableThreadLocal的例項，該例項中通過HashMap來儲存context資料。

此外，MDC提供了put/get/clear等幾個核心介面，用於操作ThreadLocal中儲存的資料。而在logback.xml中，可在layout中通過宣告“%X{requestId}”這種形式來獲得MDC中儲存的資料，並進行列印此資訊。

基於MDC的這些特性，因此它經常被用來做日誌鏈路跟蹤、動態配置使用者自定義資訊（比如requestId、sessionId等）等場景。

實戰使用

上面瞭解了一些基礎的原理知識，下面我們就來看看如何基於日誌框架的MDC功能實現日誌的追蹤。

工具類準備

首先定義一些工具類，這個強烈建議大家將一些操作通過工具類的形式進行實現，這是寫出優雅程式碼的一部分，也避免後期修改時每個地方都需要改。

TraceID（我們定義引數名為requestId）的生成類，這裡採用UUID進行生成，當然可根據你的場景和需要，通過其他方式進行生成。

public class TraceIdUtils {

    /**
     * 生成traceId
     *
     * @return TraceId 基於UUID
     */
    public static String getTraceId() {
        return UUID.randomUUID().toString().replace("-", "");
    }
}

對Context內容的操作工具類TraceIdContext：

public class TraceIdContext {

    public static final String TRACE_ID_KEY = "requestId";

    public static void setTraceId(String traceId) {
        if (StringLocalUtil.isNotEmpty(traceId)) {
            MDC.put(TRACE_ID_KEY, traceId);
        }
    }

    public static String getTraceId() {
        String traceId = MDC.get(TRACE_ID_KEY);
        return traceId == null ? "" : traceId;
    }

    public static void removeTraceId() {
        MDC.remove(TRACE_ID_KEY);
    }

    public static void clearTraceId() {
        MDC.clear();
    }

}

通過工具類，方便所有服務統一使用，比如requestId可以統一定義，避免每處都不一樣。這裡不僅提供了set方法，還提供了移除和清理的方法。

需要注意的是，MDC.clear()方法的使用。如果所有的執行緒都是通過new Thread方法建立的，執行緒消亡之後，儲存的資料也隨之消亡，這倒沒什麼。但如果採用的是執行緒池的情況時，執行緒是可以被重複利用的，如果之前執行緒的MDC內容沒有清除掉，再次從執行緒池中獲取這個執行緒，會取出之前的資料(髒資料)，會導致一些不可預期的錯誤，所以當前執行緒結束後一定要清掉。

Filter攔截

既然我們要實現日誌鏈路的追蹤，最直觀的思路就是在訪問的源頭生成一個請求ID，然後一路傳下去，直到這個請求完成。這裡以Http為例，通過Filter來攔截請求，並將資料通過Http的Header來儲存和傳遞資料。涉及到系統之間呼叫時，呼叫方設定requestId到Header中，被呼叫方從Header中取即可。

Filter的定義：

public class TraceIdRequestLoggingFilter extends AbstractRequestLoggingFilter {

    @Override
    protected void beforeRequest(HttpServletRequest request, String message) {
        String requestId = request.getHeader(TraceIdContext.TRACE_ID_KEY);
        if (StringLocalUtil.isNotEmpty(requestId)) {
            TraceIdContext.setTraceId(requestId);
        } else {
            TraceIdContext.setTraceId(TraceIdUtils.getTraceId());
        }
    }

    @Override
    protected void afterRequest(HttpServletRequest request, String message) {
        TraceIdContext.removeTraceId();
    }
}

在beforeRequest方法中，從Header中獲取requestId，如果獲取不到則視為“源頭”，生成一個requestId，設定到MDC當中。當這個請求完成時，將設定的requestId移除，防止上面說到的執行緒池問題。系統中每個服務都可以通過上述方式實現，整個請求鏈路就串起來了。

當然，上面定義的Filter是需要進行初始化的，在Spring Boot中例項化方法如下：

@Configuration
public class TraceIdConfig {

    @Bean
    public TraceIdRequestLoggingFilter traceIdRequestLoggingFilter() {
        return new TraceIdRequestLoggingFilter();
    }
}

針對普通的系統呼叫，上述方式基本上已經能滿足了，實踐中可根據自己的需要在此基礎上進行擴充套件。這裡使用的是Filter，也可以通過攔截器、Spring的AOP等方式進行實現。

微服務中的Feign

如果你的系統是基於Spring Cloud中的Feign元件進行呼叫，則可通過實現RequestInterceptor攔截器來達到新增requestId效果。具體實現如下：

@Configuration
public class FeignConfig implements RequestInterceptor {

    @Override
    public void apply(RequestTemplate requestTemplate) {
        requestTemplate.header(TraceIdContext.TRACE_ID_KEY, TraceIdContext.getTraceId());
    }

}

結果驗證

當完成上述操作之後，對一個Controller進行請求，會列印如下的日誌：

2021-04-13 10:58:31.092 cloud-sevice-consumer-demo [http-nio-7199-exec-1] INFO  [ef76526ca96242bc8e646cdef3ab31e6] c.b.demo.controller.CityController - getCity
2021-04-13 10:58:31.185 cloud-sevice-consumer-demo [http-nio-7199-exec-1] WARN  [ef76526ca96242bc8e646cdef3ab31e6] o.s.c.o.l.FeignBlockingLoadBalancerClient -

可以看到requestID已經被成功新增。當我們排查日誌時，只需找到請求的關鍵資訊，然後根據關鍵資訊日誌中的requestId值就可以把整個日誌串聯起來。

小結

最後，我們來回顧一下日誌追蹤的整個過程：當請求到達第一個伺服器，服務檢查requestId是否存在，如果不存在，則建立一個，放入MDC當中；服務呼叫其他服務時，再通過Header將requestId進行傳遞；而每個服務的logback配置requestId的輸出。從而達到從頭到尾將日誌串聯的效果。

在學習本文，如果你只學到了日誌追蹤，那是一種損失，因為文中還涉及到了SpringBoot對logback的整合、MDC的底層實現及坑、過濾器的使用、Feign的請求攔截器等。如果感興趣，每個都可以發散一下，學習到更多的知識點。

原文連結：http://mp.weixin.qq.com/s?__biz=MzI0NDAzMzIyNQ==&mid=2654070846&idx=1&sn=8bb1843d238e9c9830b6baf734dbc343&utm_source=tuicool&utm_medium=referral

如果覺得本文對你有幫助，可以關注一下我公眾號，回覆關鍵字【面試】即可得到一份Java核心知識點整理與一份面試大禮包！另有更多技術乾貨文章以及相關資料共享，大家一起學習進步！