为何WebFilter中foo日志无tracking id而bar日志存在该ID？

引用内容

运行以下WebFilter时，观察到如下现象：

• foo日志不包含tracking id
• bar日志包含tracking id

请问造成该差异的原因是什么？

@Slf4j
@Component
@Order(Ordered.HIGHEST_PRECEDENCE + 2)
class MyFilter implements WebFilter {
    @Override
    public Mono<Void> filter(final ServerWebExchange exchange, final WebFilterChain chain) {
        return Mono.just(exchange)
            .doOnNext(x -> log.debug("foo"))
            .flatMap(chain::filter)
            .doOnSuccess(x -> log.debug("bar"));
    }
}

核心原因是Spring Cloud Sleuth的Trace上下文传播时机和Reactor的执行顺序导致的：

• doOnNext中打印的foo日志，是在调用chain.filter()之前执行的。你的过滤器设置了Ordered.HIGHEST_PRECEDENCE + 2，优先级比Sleuth默认的WebFilter更高，此时Sleuth还没完成Trace上下文的初始化，当前Reactor上下文里没有tracking id，所以日志里不会显示。

• doOnSuccess中打印的bar日志，是在chain.filter()执行完成后触发的。chain.filter()会调用后续所有过滤器，其中就包含Sleuth的WebFilter——它已经完成了Trace上下文的初始化，并且通过Reactor的上下文传播机制把tracking id传递了下来。此时打印日志时，上下文已经包含tracking id，所以日志里会显示出来。

总结来说：foo在Sleuth初始化Trace上下文前执行，bar在之后执行，这就是两者日志差异的根源。

内容的提问来源于stack exchange，提问作者kokodyn