問題説明

在Spring Cloud Gateway模塊中定義了LogTraceFilter(完整代碼參考文章末尾), 用於獲取traceId(關鍵代碼： tracer.currentSpan())並放入slf4j的MDC日誌上下文， 但是該方法一直返回null。

環境和版本

jdk 17
<spring-cloud-starter-sleuth.version>3.13</spring-cloud-starter-sleuth>
<spring-boot.version>2.7.0</spring-boot.version>
<spring-cloud.version>2021.0.3</spring-cloud.version>
<spring-cloud-alibaba.version>2021.0.1.0</spring-cloud-alibaba.version>
<spring-cloud-starter-oauth2.version>2.2.5.RELEASE</spring-cloud-starter-oauth2.version>

解決方案

調整TraceWebFilter的執行順序即可:

spring:
  # 將TraceWebFilter放在LogTraceFilter前一個, LogTraceFilter是2
  sleuth:
    web:
      filter-order: 1

解決思路

1. 分析tracer.currentSpan()方法, 查找取值位置:
   Tracer.java

    @Nullable public Span currentSpan() {
    # context一直返回null
    TraceContext context = currentTraceContext.get();
    if (context == null) return null;
        // Returns a lazy span to reduce overhead when tracer.currentSpan() is invoked just to see if
        // one exists, or when the result is never used.
        return new LazySpan(this, context);
     }

   currentTraceContext對應實現類為ThreadLocalCurrentTraceContext.java

     # 通過ThreadLocal對象存儲TraceContext
     final ThreadLocal<TraceContext> local;
   
     # 取值
     @Override public TraceContext get() {
        return local.get();
     }
   
     # 賦值
     @Override public Scope newScope(@Nullable TraceContext currentSpan) {
        final TraceContext previous = local.get();
        local.set(currentSpan);
        Scope result = previous != null ? new RevertToPreviousScope(local, previous) : revertToNull;
        return decorateScope(currentSpan, result);
     }

2. 分析newScope, 查找賦值位置
   通過debug filterChain最終定位到TraceWebFilter.$MonoWebFilterTrace的subscribe方法

   @Override
   public void subscribe(CoreSubscriber<? super Void> subscriber) {
        Context context = contextWithoutInitialSpan(subscriber.currentContext());
        Span span = findOrCreateSpan(context);
        # 下面這行會調用newScope, 初始化TraceContext
        try (CurrentTraceContext.Scope scope = this.currentTraceContext.maybeScope(span.context())) {
            this.source.subscribe(new WebFilterTraceSubscriber(subscriber, context, span, this));
        }
   }

3. 分析原因
   3.1 過濾器鏈執行順序正常
   確定執行順序是否是TraceWebFilter->LogTraceFilter Debug查看過濾器鏈順序:
   
   確認執行順序沒有問題。

   3.2 兩個過濾器不在一個線程中！！！
   經過Debug發現兩個Filer對應的線程名不同， 分別是：

   TraceWebFilter對應的線程是: reactor-http-nio-2
   LogTraceFilter對應的線程是: parallel-4

   原因是較新版本的SpringMVC中， WebFileterChainProxy開啓了新的線程執行後續Filter， 導致前面設置的ThreadLocal值在後面的Filter中無法取到。

4. 修復方案
   將TraceWebFilter移到WebFilterChianProxy之後、LogTraceFilter之前執行:
   調整過濾器執行順序後
   
   配置修改:

   spring:
     // 日誌跟蹤， 放在LogTraceFilter前一個, LogTraceFilter是2
     sleuth:
    web:
      filter-order: 1

附件

LogTraceFilter

package com.micro.exchange.filter;

import brave.Span;
import brave.Tracer;
import brave.propagation.TraceContext;
import com.micro.exchange.common.enums.LogTraceEnum;
import lombok.RequiredArgsConstructor;
import lombok.extern.slf4j.Slf4j;
import org.springframework.core.Ordered;
import org.springframework.http.HttpHeaders;
import org.springframework.stereotype.Component;
import org.springframework.web.server.ServerWebExchange;
import org.springframework.web.server.WebFilter;
import org.springframework.web.server.WebFilterChain;
import reactor.core.publisher.Mono;

import java.util.Optional;

@Slf4j
@Component
@RequiredArgsConstructor
public class LogTraceFilter implements WebFilter, Ordered {

    private final Tracer tracer;

    /*@Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        TraceWebFilter traceWebFilter;
        HttpHeaders headers = exchange.getResponse().getHeaders();
        if(!headers.containsKey(LogTraceEnum.TRACE_ID.headerName)) {
            String traceId = null;
            if(tracer != null) {
                traceId = Optional.ofNullable(tracer.currentSpan())
                        .map(Span::context)
                        .map(TraceContext::traceIdString)
                        .orElse("null");
            }
            headers.set(LogTraceEnum.TRACE_ID.headerName, traceId);
        }

        return chain.filter(exchange);
    }*/

    @Override
    public int getOrder() {
        return 2;
    }

    @Override
    public Mono<Void> filter(ServerWebExchange exchange, WebFilterChain chain) {
        // TraceWebFilter traceWebFilter;
        HttpHeaders headers = exchange.getResponse().getHeaders();
        if(!headers.containsKey(LogTraceEnum.TRACE_ID.headerName)) {
            String traceId = null;
            if(tracer != null) {
                traceId = Optional.ofNullable(tracer.currentSpan())
                        .map(Span::context)
                        .map(TraceContext::traceIdString)
                        .orElse("null");
            }
            headers.set(LogTraceEnum.TRACE_ID.headerName, traceId);
        }

        return chain.filter(exchange);
    }
}