brave.Tracer.currentSpan()返回null的问题

问题说明

在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);
    }
}