《Java 编程实战》13.2 追踪：OpenTelemetry 与 W3C traceparent

本节目标：让 libraryd 的每个请求都产生可导出的 SERVER span，能从上游 traceparent 接上父上下文，把新的 traceparent 写回响应，并让日志里的 traceId、指标里的请求维度与追踪数据能互相对照。
适用版本：JDK 25（Temurin 25.0.5）、OpenTelemetry 1.67.0、Javalin 7.2.4、SLF4J 2.0.20、Logback 1.6.6。

只有 requestId，跨服务就断了

12.2 给 libraryd 加了 requestId：每个请求进来先生成或读取 X-Request-Id，放进 MDC，日志每一行都带着它。单进程排查很好用，但一旦请求跨服务，它立刻露出三个缺口。

第一，requestId 只保证「同一个入口的这次请求」在日志里能串起来。上游网关生成 req-A，转发给 libraryd 时如果改了头，libraryd 会生成 req-B，两边日志就对不上。第二，requestId 没有层级。一次借阅里查了图书、查了会员、写了借阅记录，日志只能按时间排序，看不出哪一段是数据库、哪一段是缓存。第三，requestId 不携带采样决定，无法让上游和下游对「这次要不要记录链路」达成一致。

追踪用三个坐标补上这些缺口：整条链共享的 traceId、每段操作自己的 spanId、指向上游 span 的 parent span id。三者都进入 W3C traceparent 头，跨进程传递时不会丢层级。

trace、span 与 traceparent：一条调用链的三层坐标

先统一名词，后面的代码和输出都围绕这四个值。

一个合法的 traceparent 形如：

00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01

按连字符拆开是四段：

• 00：版本号。当前 W3C Trace Context 的版本是 00；ff 是非法版本。
• 4bf92f3577b34da6a3ce929d0e0e4736：trace-id，32 位小写十六进制，不能全为 0。
• 00f067aa0ba902b7：调用方的 span-id，16 位小写十六进制，不能全为 0。
• 01：trace-flags，最低位表示 sampled。01 表示上游要求采样，00 表示不采样。

服务端收到这个头后，不会复用调用方的 span-id，而是以它为 parent 创建自己的 span。于是响应里的 traceparent 会变成「同一个 trace-id + 服务端新生成的 span-id + 采样标志」。下一个服务再以这个新 span-id 为 parent，链路就一环一环接下去。

libraryd 的 TracingMiddleware 只处理 W3C 格式，不处理 Jaeger 的 uber-trace-id 或 B3 的 X-B3-TraceId。这不是遗漏：入口网关应该统一做协议转换，应用内部只认一种。若同时启用多个 propagator，提取顺序和响应头数量都会变得难以预测。

Telemetry：把 SDK、资源与导出器装起来

Telemetry 在 13.1 已经出现过，当时关注的是 PrometheusMeterRegistry。追踪相关的部分集中在构造函数的后半段：

Resource resource = Resource.getDefault().merge(
        Resource.create(Attributes.builder()
                .put("service.name", "libraryd")
                .put("service.version", "1.0.0")
                .build()));
this.tracerProvider = SdkTracerProvider.builder()
        .addSpanProcessor(SimpleSpanProcessor.create(LoggingSpanExporter.create()))
        .setResource(resource)
        .build();
this.openTelemetry = OpenTelemetrySdk.builder()
        .setTracerProvider(tracerProvider)
        .build();
this.tracer = openTelemetry.getTracer("com.plume.library", "1.0.0");

逐行看：

• Resource 是「这些 span 是谁产生的」。service.name=libraryd 会进入每个 span，后端按它分组。没有它，所有服务的 span 混在一起，trace 页面只能看到一串匿名操作。
• SdkTracerProvider 是 span 的工厂和生命周期管理者。addSpanProcessor 决定 span 结束后去哪里。
• SimpleSpanProcessor 在 span.end() 时同步调用 exporter。写日志、写本地文件够用，但它占的是请求线程；生产环境接 OTLP 时应换成 BatchSpanProcessor，让后台线程批量发送。
• LoggingSpanExporter 把 span 打到 JUL（java.util.logging），不是 Logback。这个细节在 12 章的 JSON 日志里看不到，后面会单独说。
• openTelemetry.getTracer("com.plume.library", "1.0.0") 里的两个参数是 instrumentation scope 的名称和版本。它们会出现在导出结果里，便于区分「这个 span 是哪个库/模块产生的」。

参考工程没有暴露采样配置，SdkTracerProvider.builder() 使用默认采样器。OpenTelemetry SDK 的默认值是 parentBased(alwaysOn)：有父上下文时跟随父上下文的 sampled 标志，没有父上下文时全采样。要在 libraryd 里改采样比例，改动点在 SdkTracerProvider.builder() 这一行，例如：

this.tracerProvider = SdkTracerProvider.builder()
        .setSampler(Sampler.parentBased(Sampler.traceIdRatioBased(0.1)))
        .addSpanProcessor(SimpleSpanProcessor.create(LoggingSpanExporter.create()))
        .setResource(resource)
        .build();

这是明确的改动点，不是参考工程现存的配置项。Sampler 来自 io.opentelemetry.sdk.trace.samplers.Sampler，traceIdRatioBased(0.1) 表示按 trace-id 的哈希取 10%。外层再包 parentBased，才能保证上游说不采样时下游不反悔。

TracingMiddleware：一次请求的 span 生命周期

TracingMiddleware 只有两个公开方法：start 在请求进入时创建 span，finish 在响应写出前补状态、回写头并结束 span。先看 start：

public void start(io.javalin.http.Context context) {
    if (tracer == null) {
        return;
    }
    Map<String, String> headers = context.headerMap();
    Context parent = propagator.extract(Context.root(), headers, MapGetter.INSTANCE);
    Span span = tracer.spanBuilder(context.method().name() + " " + context.path())
            .setParent(parent)
            .setSpanKind(SpanKind.SERVER)
            .startSpan();
    span.setAttribute("http.request.method", context.method().name());
    span.setAttribute("url.path", context.path());
    span.setAttribute("request.id", RequestContext.requestId(context));
    context.attribute(SPAN_ATTRIBUTE, span);
    MDC.put("traceId", span.getSpanContext().getTraceId());
}

关键点在 extract 和 setParent：

• Context.root() 是一个空上下文，表示「暂时没有父 span」。propagator.extract 会从请求头里找 traceparent，找到就还原成带父 span 的上下文；找不到或格式非法就返回空上下文。
• tracer.spanBuilder(...) 只创建 builder，不创建 span。setParent(parent) 明确指定父子关系，setSpanKind(SpanKind.SERVER) 告诉后端「这是服务端接收请求的 span」。
• span 名称由 HTTP 方法加路径组成。参考工程用的是 context.path()，也就是真实路径 /api/books/9787111213826。这会让每个 ISBN 变成一个独立的 operation name，后端的按名称聚合会迅速膨胀。更稳的写法是用路由模板，后文会给出替换方式。
• context.attribute(SPAN_ATTRIBUTE, span) 把 span 挂在请求对象上，finish 才能取回它。Javalin 的 Context 在同一个请求内是同一个对象，这是安全的；不要把它放到静态字段或 ThreadLocal 里。
• MDC.put("traceId", ...) 让后续日志行带上 trace-id。这个 MDC 的清理在 RequestContext.clear 里完成，不是在 finish 里。

再看 finish：

public void finish(io.javalin.http.Context context) {
    if (tracer == null) {
        return;
    }
    Span span = context.attribute(SPAN_ATTRIBUTE);
    if (span == null) {
        return;
    }
    int status = context.statusCode();
    span.setAttribute("http.response.status_code", status);
    if (status >= 500) {
        span.setStatus(StatusCode.ERROR);
    }
    Map<String, String> carrier = new LinkedHashMap<>();
    propagator.inject(Context.current().with(span), carrier, MapSetter.INSTANCE);
    carrier.forEach(context::header);
    span.end();
}

finish 做四件事。第一，把响应状态码写进 span 属性；第二，只有 5xx 才标记 ERROR，4xx 保持 UNSET。这符合 OpenTelemetry 对服务端 span 的语义：客户端传错参数不是服务端故障，把它标红会让错误率失真。第三，用 Context.current().with(span) 把当前 span 放进上下文，再让 propagator 注入 traceparent，最后逐项写到响应头。第四，span.end() 触发 exporter。

注意 inject 的第一个参数不是裸的 Context.current()。如果只写 Context.current()，注入的是「当前线程的上下文」，而 start 里并没有调用 makeCurrent()，当前线程上下文可能还是空的。with(span) 显式把 span 放进去，保证注入的是这个请求的 span。这个写法也解释了为什么中间件可以在不改变线程上下文的情况下完成响应头注入。

MapGetter 和 MapSetter 是两个枚举单例，分别实现 TextMapGetter 和 TextMapSetter：

private enum MapGetter implements TextMapGetter<Map<String, String>> {
    INSTANCE;
    @Override
    public String get(Map<String, String> carrier, String key) {
        return carrier.get(key);
    }
}

private enum MapSetter implements TextMapSetter<Map<String, String>> {
    INSTANCE;
    @Override
    public void set(Map<String, String> carrier, String key, String value) {
        carrier.put(key, value);
    }
}

TextMapGetter.keys() 在 1.67.0 里已经标了 deprecated，W3C propagator 只需要按已知键读取，所以参考工程没有覆写它。自己实现 getter 时不要依赖 keys() 做遍历，否则升级时会遇到编译警告甚至行为差异。

接入顺序：requestId 先于 traceId

中间件本身不会自动执行，接入点在 LibraryApi 的 before 和 after：

private void before(Context context) {
    RequestContext.begin(context);
    tracing.start(context);
}

private void after(Context context) {
    try {
        httpMetrics.record(context, RequestContext.elapsedNanos(context));
    } finally {
        tracing.finish(context);
        RequestContext.clear(context);
    }
}

顺序不是随意的：

• RequestContext.begin 先设置 requestId，tracing.start 才能把它写进 request.id 属性。如果反过来，RequestContext.requestId(context) 返回 null，span 属性会缺失，排障时少一个关联字段。
• after 里先记指标，再在 finally 里结束 span 并清理 MDC。指标记录即使抛异常，也不能阻止 span 结束；否则 span 永远不导出。
• RequestContext.clear 同时删除 requestId 和 traceId。Javalin 的线程池会复用线程，不清理就会把上一个请求的 trace-id 带给下一个请求。12.2 已经用一个 MDC 泄漏实验展示过这种串味，这里只是把 traceId 也纳入清理范围。
• tracing.finish 必须在 clear 之前。虽然 finish 不读 MDC，但保持「先结束资源、再清理上下文」的顺序，后续要在 finish 里补日志时不会拿到空 traceId。

TracingMiddleware 允许 tracer == null，这时 start 和 finish 都直接返回。构造函数传入 null 就能关闭追踪，HTTP 指标和 requestId 不受影响。这种「可空依赖」在测试里很有用，但生产环境不要靠它做开关：关闭后响应里不会有 traceparent，上游可能因此断开链路。

父上下文、采样与响应头：三个容易误判的现象

第一段代码验证「有父上下文时，trace-id 保持不变，span-id 重新生成」。本机用 TracingDemo 构造一个上游 traceparent，提取后创建 SERVER span，再注入响应头：

incoming traceId=4bf92f3577b34da6a3ce929d0e0e4736
incoming spanId=00f067aa0ba902b7
new spanId=213e59e062f7ab34
sampled=true
response traceparent=00-4bf92f3577b34da6a3ce929d0e0e4736-213e59e062f7ab34-01

这段是本机输出，环境为 JDK 25.0.5 + OpenTelemetry 1.67.0。可以看到 trace-id 原样保留，span-id 换成了新值，flags 仍是 01。spanId 每次运行都会变，不要把它当成固定值写进断言；测试应该断言 trace-id 相等、span-id 不相等、flags 保持。

第二段是真实 HTTP 请求。给运行中的 libraryd 发一个带 traceparent 的请求：

HTTP/1.1 200 OK
X-Request-Id: trace-demo-1
traceparent: 00-11111111111111111111111111111111-29c343ea4eef50f0-01

同一请求的日志行：

INFO [JettyServerThreadPool-46] com.plume.library.web.HttpMetrics requestId=trace-demo-1 traceId=11111111111111111111111111111111 - http_request method=GET path=/api/books/9787111213826 status=200 duration_ms=28

响应头和日志里的 trace-id 都是上游给的 1111...，说明中间件确实提取了父上下文，而不是自己新生成一个。X-Request-Id 也保留了调用方传入的 trace-demo-1，两个关联维度同时可用。

第三段是未采样父上下文。发一个 flags 为 00 的请求：

traceparent: 00-33333333333333333333333333333333-a8224ef0d14c1666-00

日志仍然有 traceId=3333...，但 exporter 没有输出这一条 span：

INFO [JettyServerThreadPool-46] com.plume.library.web.HttpMetrics requestId=unsampled-1 traceId=33333333333333333333333333333333 - http_request method=GET path=/api/books/9787111213826 status=200 duration_ms=2

这是默认 parentBased(alwaysOn) 的正确行为：父上下文说「不采样」，子 span 就继承不采样。trace-id 仍然生成并传播，只是不导出。不要把「没看到 span」误判成「中间件没工作」；先看响应头和日志里的 trace-id 是否连续，再看 flags。

如果显式把采样器设成 Sampler.traceIdRatioBased(0.0)，结果更直接：

sampled=false
recording=false
exported spans above? (none means sampler dropped it)

isRecording() 为 false 表示这个 span 不会记录属性、事件，也不会导出。但 span.getSpanContext().getTraceId() 仍然是合法的 32 位十六进制，响应头也仍然可以带 traceparent。采样状态是「要不要记录」，不是「请求是否有效」。

业务子 span：makeCurrent 不是可选项

中间件创建的 SERVER span 只覆盖「请求进入」到「响应写出」。真正耗时的数据库查询、Redis 访问、外部调用，需要在业务代码里创建子 span。正确写法是先 makeCurrent()，再创建子 span：

Span server = tracer.spanBuilder("POST /api/loans")
        .setSpanKind(SpanKind.SERVER)
        .startSpan();
try (Scope ignored = server.makeCurrent()) {
    Span child = tracer.spanBuilder("loan.borrow").startSpan();
    try (Scope childScope = child.makeCurrent()) {
        child.setAttribute("book.isbn", "9787111213826");
        child.setAttribute("member.id", "m-001");
        sleep(20);
    } finally {
        child.end();
    }
} finally {
    server.end();
}

本机运行后，两条导出的 span 共享同一个 trace-id：

'loan.borrow' : 011a6e2ff74a29b8cb4a191530eca9e4 7c627d49f72641d2 INTERNAL [tracer: com.plume.library:1.0.0] AttributesMap{data={member.id=m-001, book.isbn=9787111213826}, capacity=128, totalAddedValues=2}
'POST /api/loans' : 011a6e2ff74a29b8cb4a191530eca9e4 171e7fa3aac34322 SERVER [tracer: com.plume.library:1.0.0] {}

LoggingSpanExporter 的输出只显示 trace-id 和当前 span-id，不显示 parent span-id，所以肉眼看不到父子关系；后端存的是完整 SpanData，trace 页面会按 parent 画树。两条记录的 trace-id 相同，已经能证明子 span 没有另起一条链。

把 makeCurrent() 去掉，结果立刻不同：

server trace=6b2ce5d7b0b2291e41a73ae50e68d7c5
child  trace=c1638ef1f27401910ceb272e4ffb6a07

spanBuilder("loan.borrow").startSpan() 默认从 Context.current() 取父上下文。没有 makeCurrent() 时，当前线程的上下文还是 root，于是子 span 变成了一条全新 trace 的根。这个错误在日志里表现为「同一个请求有两组 traceId」，在 trace 后端表现为「两个互不相连的短链」。

几条使用规则：

• Scope 必须 close()，否则当前线程一直挂在这个 span 上，后续操作会错误地成为它的子节点。用 try-with-resources 最稳。
• 先结束子 span，再结束父 span。父 span 先结束时，子 span 仍可创建，但时间线会倒挂，后端可能丢弃。
• 不要把 Scope 传给另一个线程。跨线程要传 Context，在目标任务里重新 makeCurrent()；MDC 也不会自动跟着线程走，需要 MDC.getCopyOfContextMap() 复制。
• 子 span 名称用低基数、可聚合的操作名，例如 loan.borrow、db.book.findByIsbn，不要把 ISBN、会员号拼进名称。
• 属性里不要放密码、token、完整身份证号。book.isbn 和 member.id 是否算敏感数据取决于业务合规要求，至少要做访问控制。

常见错误与排查清单

其中两个细节值得展开。

Telemetry.close() 的实现是：

public void close() {
    openTelemetry.close();
    tracerProvider.close();
    registry.close();
}

OpenTelemetrySdk.close() 内部会关闭它持有的 SdkTracerProvider，再调用一次 tracerProvider.close() 就是重复关闭。本机运行 TracingDemo 时能看到：

信息: Calling shutdown() multiple times.

这条消息来自 JUL，不会进入 Logback 的 JSON 日志，所以很容易在测试环境被忽略。它通常无害，但说明关闭路径有重复；如果以后在 close() 里加了 flush 或连接释放，重复关闭可能变成真实问题。

另一个是 span 名称的基数。参考工程写的是：

tracer.spanBuilder(context.method().name() + " " + context.path())

context.path() 是真实路径，GET /api/books/9787111213826 和 GET /api/books/9787110300917 会成为两个不同的 operation。图书数量有多少，operation 就可能有多少。改进方式是取 Javalin 匹配到的路由模板：

String route = context.endpoints().matchedHttpEndpoint() == null
        ? "unmatched"
        : context.endpoints().matchedHttpEndpoint().path();
Span span = tracer.spanBuilder(context.method().name() + " " + route)
        .setParent(parent)
        .setSpanKind(SpanKind.SERVER)
        .startSpan();

matchedHttpEndpoint() 在 404 时可能为 null，所以要有 unmatched 兜底。这个写法与 13.1 给 HTTP Timer 打 route tag 用的是同一个 API，指标和追踪的维度可以保持一致。改完后 url.path 属性仍保留真实路径，既能聚合，也能定位具体资源。

小结

• trace 是一条请求的全局身份，span 是链路里的单段操作，parent span id 把段与段连成树。
• W3C traceparent 由版本、32 位 trace-id、16 位 parent-id、2 位 flags 组成；服务端保留 trace-id，换用新的 span-id 继续传播。
• Telemetry 用 Resource 标注 service.name，用 SimpleSpanProcessor + LoggingSpanExporter 做最小可用导出；生产应换批量处理器和 OTLP。
• TracingMiddleware.start 提取父上下文、创建 SERVER span、写属性并把 trace-id 放进 MDC；finish 补状态码、注入响应头、结束 span。
• makeCurrent() 决定子 span 能不能接上父上下文；没有它，子 span 会另起一条 trace。
• 采样是「记录与否」，不是「请求有效与否」；默认 parentBased(alwaysOn) 会尊重上游的 flags，自定义比例时要用 Sampler.parentBased(...)。
• span 名称用路由模板，属性放低基数、非敏感字段；真实路径留给 url.path。

追踪回答「这一次请求慢在哪一段」，健康检查回答「这个实例现在能不能接流量」。下一节把 /health 拆成存活与就绪两个视角，并处理依赖超时、探针频率和重启风暴。

阅读导航：上一节：13.1 Micrometer：计数器、计时器与 Prometheus · 下一节：13.3 健康检查：依赖探测与就绪/存活 。