PAYATHON 2026

Spring Boot 4 中 Logbook 4 异步响应日志缺少 trace-id,如何修复?

数据小许

结论

应重点检查 Logbook 的 Servlet 异步完成回调。记录响应日志时,原请求的 tracing context 可能已经不在当前线程上。将 Mono<T> 换成 CompletableFuture<T>,仍会经过这条共同的 Servlet 回调路径。

一种修复方式是升级到提供 AsyncOnCompleteListenerWrapper 扩展点的 Logbook 版本,在注册回调时捕获上下文,并在执行回调时恢复。Logbook 4.2.0 的发布记录已包含该扩展点。由于默认实现不恢复上下文,升级后还需要配置 wrapper。Logbook 发布记录、扩展点说明

现有材料不足以认定这是 Micrometer Tracing 或 Spring Boot 某一版本的回归,也不能仅凭日志缺少 trace-id 判断整个 trace 没有生成。

为什么已有配置没有解决问题?

Logbook 4.0.4 的 LogbookFilter 检测到异步请求后,会直接注册 LogbookAsyncListener,通过完成回调写出响应日志。这段代码没有包裹 Micrometer 的上下文捕获与恢复逻辑。Logbook 4.0.4 源码

需要分别检查请求处理线程、异步业务执行位置,以及最终写响应日志的完成回调。业务代码能拿到 trace-id,不代表完成回调也能拿到。

问题中尝试的两种配置作用范围不同:

  • ContextPropagatingTaskDecorator 包装交给相应 TaskExecutor 执行的任务。即便装饰器已经应用到执行器,也不会因此自动包装 Servlet 容器调用的所有 AsyncListener 回调。Spring API 文档
  • Hooks.enableAutomaticContextPropagation() 针对 Reactor 中的上下文传播,不能据此推断 Servlet 完成回调也会恢复上下文。改用 CompletableFuture<T> 后问题仍然复现,也提示需要检查共同的 Servlet 完成阶段。

Spring MVC 支持 controller 返回 Mono,并将这类单值异步结果适配为类似 DeferredResult 的处理方式。这并不意味着应用使用了 WebFlux 服务端栈。Spring MVC 异步处理文档

此处实际使用的是 jakarta.servlet.AsyncListener,原问题中的 javax.servlet.AsyncListener 是旧命名空间。Logbook 4.0.4 的 Servlet 实现使用 jakarta.servlet。

升级后如何配置上下文恢复?

先将相关 Logbook 模块统一升级到 4.2.0,并检查该版本与现有配置的兼容性。如果使用 logbook-spring-boot-starter,可以声明以下 bean:

import io.micrometer.context.ContextRegistry;
import io.micrometer.context.ContextSnapshot;
import io.micrometer.context.ContextSnapshotFactory;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.zalando.logbook.servlet.AsyncOnCompleteListenerWrapper;

@Configuration(proxyBeanMethods = false)
public class LogbookTracingConfiguration {

    @Bean
    AsyncOnCompleteListenerWrapper tracingCompletionWrapper() {
        ContextSnapshotFactory snapshots = ContextSnapshotFactory.builder()
                .contextRegistry(ContextRegistry.getInstance())
                .build();

        return completion -> {
            ContextSnapshot captured = snapshots.captureAll();
            return asyncEvent -> {
                try (ContextSnapshot.Scope restored = captured.setThreadLocals()) {
                    completion.onComplete(asyncEvent);
                }
            };
        };
    }
}

captureAll() 必须在注册回调时执行,setThreadLocals() 必须覆盖实际写日志的回调。不能等进入 onComplete 后才捕获上下文,因为那时原请求的上下文可能已经不可见。

try-with-resources 会在回调结束后恢复线程原有的 ThreadLocal 状态,避免复用线程时残留其他请求的上下文。这是 Micrometer Context Propagation 支持的使用方式。Micrometer 示例

该示例有以下前提:

  • classpath 中包含 io.micrometer:context-propagation。缺少时应使用 Spring Boot 管理的兼容版本补充依赖。
  • 所用 ContextRegistry 已注册需要传播的 tracing/observation 对应的 ThreadLocalAccessor。
  • wrapper 捕获快照时,当前线程仍处于原请求的 tracing scope 内。快照无法捕获已经退出的上下文。

Spring Boot starter 会将这个 wrapper bean 应用于 logbookFilter 和 secureLogbookFilter。如果应用手工创建过滤器,需要在创建时显式调用 withAsyncOnCompleteListenerWrapper(wrapper)。Logbook 配置说明

必须保留 Logbook 4.0.4 时怎么办?

4.0.4 没有上述扩展点,不能直接复制新版 bean 配置。该版本的 LogbookFilter 是 final 类,也无法通过继承覆盖回调注册逻辑。

如果暂时无法升级,可以维护一个基于 4.0.4 实现的自定义过滤器,在原有的监听器注册位置增加以下逻辑:

  1. 注册监听器前捕获当前请求的 ContextSnapshot。
  2. 在完成回调中打开 snapshot scope。
  3. 在 scope 内调用原有的响应写日志逻辑,结束后关闭 scope。

这需要替换实际生效的原过滤器注册,并保留原实现对请求包装、异步分派和响应写出的处理,避免重复记录或遗漏日志。项目的相关 issue 也说明了旧版本缺少此扩展点的限制。Logbook issue #2283

如何确认修复位置正确?

建议通过真实 Servlet 容器发起一次异步请求,比较 controller 执行时、wrapper 捕获快照时,以及完成回调恢复前后的 Tracer.currentSpan() 和 MDC.get("traceId")。

  • 如果捕获快照时 currentSpan() 就为空,应检查 tracing 是否启用,以及过滤器顺序是否让 Logbook 的捕获位置处于 tracing scope 内。
  • 如果捕获时有 span、恢复后没有,应检查使用的 ContextRegistry 和已注册的 accessor。
  • 如果恢复后 span 存在,但日志仍没有 trace-id,应继续检查 MDC 关联和日志格式。日志展示字段可能叫 trace-id,而 MDC 键通常是 traceId,两者需要对应。

仅有 controller 单元测试不足以证明容器完成回调的行为。验证时还应比较并发请求的 trace-id,确认上下文没有串到其他请求。Logbook 自身用于关联请求与响应的 correlation id,也不能直接当作分布式 tracing 的 trace-id。

备注:内容仅供参考。