SpringCloudGateway使用Skywalking時(shí)日志打印traceId

環(huán)境信息

SpringCloudGateway 3.1.3
Skywalking Agent 8.10.0

環(huán)境配置

Agent

由于SpringCloudGateway是基于WebFlux來(lái)實(shí)現(xiàn)的宪睹，需要進(jìn)到skywalking的agent目錄巾腕，將optional-plugins目錄底下的以下兩個(gè)jar包復(fù)制到plugins目錄

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

Maven依賴(lài)配置

<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

啟動(dòng)參數(shù)

新增啟動(dòng)參數(shù)

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

啟動(dòng)程序后吻谋，嘗試通過(guò)網(wǎng)關(guān)進(jìn)行接口調(diào)用膳音，可以在Skywalking-ui上看到鏈路已經(jīng)串起來(lái)了

調(diào)用鏈路

但是有個(gè)問(wèn)題，日志里記錄的日志始終不顯示正確的TID

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

問(wèn)題處理過(guò)程

查看agent是怎么串聯(lián)鏈路的

查看Skywalking-agent的源碼蚪缀，可以看到砰蠢，在apm-spring-webflux-5.x-plugin-8.10.0.jar插件里磅网，攔截了org.springframework.web.reactive.DispatcherHandler的handle方法
攔截器里往reactor的調(diào)用鏈路里婆咸，放入 < SKYWALKING_CONTEXT_SNAPSHOT - ContextSnapshot >

image.png

所以traceId可以從reactor的context里獲取到

怎么讓日志獲取到traceId

網(wǎng)上找了下資料竹捉，在這里[https://github.com/reactor/reactor-core/blob/main/docs/asciidoc/faq.adoc#context.api]發(fā)現(xiàn)了相關(guān)信息

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的時(shí)候，怎么顯示默認(rèn)值

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
注冊(cè)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();
    }
}

效果補(bǔ)充

如下圖所示尚骄，可以看到块差，TID打印成功