SpringCloudGateway使用Skywalking时日志打印traceId

环境信息

SpringCloudGateway 3.1.3
Skywalking Agent 8.10.0

环境配置

Agent

由于SpringCloudGateway是基于WebFlux来实现的，需要进到skywalking的agent目录，将optional-plugins目录底下的以下两个jar包复制到plugins目录

apm-spring-webflux-5.x-plugin-8.10.0.jar
apm-spring-cloud-gateway-3.x-plugin-8.10.0.jar

Maven依赖配置

<dependency>
  <groupId>org.apache.skywalking</groupId>
    <artifactId>apm-toolkit-log4j-2.x</artifactId>
    <version>${skywalking.version}</version>
</dependency>
<dependency>
    <groupId>org.apache.skywalking</groupId>
    <artifactId>apm-toolkit-trace</artifactId>
    <version>${skywalking.version}</version>
</dependency>

日志pattern配置

[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%traceId] [%logger{36}] [%thread] [%-5level] %msg%n

启动参数

新增启动参数

-javaagent:D:\work\skywalking-agent\skywalking-agent.jar=agent.service_name=xxx
-Dskywalking.collector.backend_service=xxx:11800

启动程序后，尝试通过网关进行接口调用，可以在Skywalking-ui上看到链路已经串起来了

调用链路

但是有个问题，日志里记录的日志始终不显示正确的TID

[2022-06-15 14:53:19.958] [TID: N/A]

问题处理过程

查看agent是怎么串联链路的

查看Skywalking-agent的源码，可以看到，在apm-spring-webflux-5.x-plugin-8.10.0.jar插件里，拦截了org.springframework.web.reactive.DispatcherHandler的handle方法
拦截器里往reactor的调用链路里，放入 < SKYWALKING_CONTEXT_SNAPSHOT - ContextSnapshot >

image.png

所以traceId可以从reactor的context里获取到

怎么让日志获取到traceId

网上找了下资料，在这里[https://github.com/reactor/reactor-core/blob/main/docs/asciidoc/faq.adoc#context.api]发现了相关信息

public static <T> Consumer<Signal<T>> logOnNext(Consumer<T> logStatement) {
    return signal -> {
        if (!signal.isOnNext()) return; (1)
        Optional<String> toPutInMdc = signal.getContext().getOrEmpty("CONTEXT_KEY"); (2)

        toPutInMdc.ifPresentOrElse(tpim -> {
            try (MDC.MDCCloseable cMdc = MDC.putCloseable("MDC_KEY", tpim)) { (3)
                logStatement.accept(signal.get()); (4)
            }
        },
        () -> logStatement.accept(signal.get())); (5)
    };
}

@GetMapping("/byPrice")
public Flux<Restaurant> byPrice(@RequestParam Double maxPrice, @RequestHeader(required = false, name = "X-UserId") String userId) {
    String apiId = userId == null ? "" : userId; (1)

    return restaurantService.byPrice(maxPrice))
               .doOnEach(logOnNext(r -> LOG.debug("found restaurant {} for ${}", (2)
                    r.getName(), r.getPricePerPerson())))
               .contextWrite(Context.of("CONTEXT_KEY", apiId)); (3)
}

获取不到traceId的时候，怎么显示默认值

https://logging.apache.org/log4j/2.x/manual/layouts.html#PatternLayout

equals{pattern}{test}{substitution}
equalsIgnoreCase{pattern}{test}{substitution}

完整例子

pattern改为 [%d{yyyy-MM-dd HH:mm:ss.SSS}] [TID: %equals{%X{traceId}}{}{N/A}] [%logger{36}] [%thread] [%-5level] %msg%n
注册onEachOperator的Hooks

@Component
public class LogHooks {
    
    private static final String KEY = "logMdc";
    
    @PostConstruct
    @SuppressWarnings("unchecked")
    public void setHook() {
        reactor.core.publisher.Hooks.onEachOperator(KEY,
                Operators.lift((scannable, coreSubscriber) -> new MdcSubscriber(coreSubscriber)));
    }
    
    @PreDestroy
    public void resetHook() {
        reactor.core.publisher.Hooks.resetOnEachOperator(KEY);
    }
    
}

public class MdcSubscriber implements CoreSubscriber {
    
    private static final String TRACE_ID = "traceId";
    
    private static final String SKYWALKING_CTX_SNAPSHOT = "SKYWALKING_CONTEXT_SNAPSHOT";
    
    private final CoreSubscriber<Object> actual;
    
    public MdcSubscriber(CoreSubscriber<Object> actual) {
        this.actual = actual;
    }
    
    @Override
    public void onSubscribe(Subscription s) {
        actual.onSubscribe(s);
    }
    
    @Override
    public void onNext(Object o) {
        Context c = actual.currentContext();
        Optional<String> traceIdOptional = Optional.empty();
        if (!c.isEmpty() && c.hasKey(SKYWALKING_CTX_SNAPSHOT)) {
            traceIdOptional = Optional.of(c.get(SKYWALKING_CTX_SNAPSHOT)).map(BeanUtil::beanToMap)
                    .map(t -> t.get(TRACE_ID)).map(BeanUtil::beanToMap).map(t -> t.get("id")).map(Object::toString);
        }
        try (MDC.MDCCloseable cMdc = MDC.putCloseable(TRACE_ID, traceIdOptional.orElse("N/A"))) {
            actual.onNext(o);
        }
    }
    
    @Override
    public void onError(Throwable throwable) {
        actual.onError(throwable);
    }
    
    @Override
    public void onComplete() {
        actual.onComplete();
    }
    
    @Override
    public Context currentContext() {
        return actual.currentContext();
    }
}

效果补充

如下图所示，可以看到，TID打印成功