基于SpringBoot實現讓日志像詩一樣有韻律
前言
在傳統系統中，如果能夠提供日志輸出，基本上已經能夠滿足需求的。但一旦將系統拆分成兩套及以上的系統，再加上負載均衡等，調用鏈路就變得復雜起來。
特別是進一步向微服務方向演化，如果沒有日志的合理規劃、鏈路追蹤，那么排查日志將變得異常困難。
比如系統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中進行日志輸出的配置即可。這里不貼全部代碼了，只貼出來相關日志輸出格式部分，以控制臺輸出為例：
在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的請求攔截器等。如果感興趣，每個都可以發散一下，學習到更多的知識點。
