深入 Play E06:OpenTelemetry,从上下文到真实接收证据
请求返回200,Collector可能一条span也没有收到;Collector返回200,也不代表订单已经提交。遥测链路和业务链路拥有不同的队列、超时与终态,接入OpenTelemetry需要分别验证这两条路径。
在Play中,Java Action、独立执行器、Scala Future、WS回调和Pekko流会改变代码执行的位置。一个traceId出现在几行日志里,只能说明字符串相同。父子关系还需要检查每个span的parentSpanId,传播需要查看真实下游请求头,导出需要看到真实接收器解析出的span。
固定组合与实际生效的插桩
实验工程位于 examples/play-electives/e06-otel,不修改系列累计应用。生产模式只加载Java agent,并使用OpenTelemetry API补充业务阶段;SDK构造仅出现在独立JUnit进程中。
| 组件 | 冻结值及核验方式 |
|---|---|
| Play / Scala / sbt | 3.0.6 / 2.13.15 / 1.10.7,实际stage包 |
| Java | Corretto21.0.11,Java21 |
| Java agent | 2.10.0,jar SHA-256 d05f6e36fac8db629263a6aaec2841cc934d064d7b19bfe38425b604b8b54926 |
| API / SDK | 1.44.1;API为应用依赖,agent内sdk.version也为1.44.1 |
| Collector | 官方0.113.0原生发行,实际执行版本命令并启动接收器 |
| OTLP | HTTP/protobuf,实际Content-Type与Collector返回值均记录 |
agent源码固定到 0ca120d1b5e66dec6c5d2637fbb8c70b337718f8。其中Pekko HTTP的muzzle配置包含 org.apache.pekko:pekko-http_2.13;Play MVC和WS的muzzle构件范围仍使用 com.typesafe.play。
muzzle描述构建时的兼容性校验范围,不能当成按Maven groupId决定运行时开关的规则。这个冻结组合的真实Collector记录包含三个自动插桩scope:io.opentelemetry.pekko-http-1.0、io.opentelemetry.play-mvc-2.6 和 io.opentelemetry.play-ws-2.1,scope版本均为2.10.0-alpha。它们确实在这次Play3.0.6运行中产生span。
这些记录证明当前组合的具体行为,不构成整个Play3版本线的兼容承诺。升级Play、WS或agent之后,仍需重跑父子关系、异常路径和取消场景。固定muzzle源码与真实scope读回分别保留在证据目录里,二者回答的问题不同。
API、SDK与agent的所有权
API提供Tracer、Span、Context与传播器等调用入口。SDK负责采样、span处理器、队列和导出。agent在应用启动前配置SDK并安装自动插桩,应用通过 GlobalOpenTelemetry.getTracer 取得入口。
生产应用没有调用 OpenTelemetrySdk.builder().buildAndRegisterGlobal(),也没有再创建一个全局SDK。若agent与应用同时争夺全局实例,手工span和自动span可能使用不同的配置、生命周期与导出路径。这个实验把SDK实现依赖限制在Test作用域,并核对stage包里没有额外的opentelemetry-sdk构件。
不加载agent时,应用仍能启动,API调用保持合法,业务返回值仍是ok;span的recording为false。这是无遥测对照。它不说明应用完全没有分配对象或没有任何CPU开销,只说明同一业务契约可以在API不记录span时运行。
下面的结构图区分了业务线程、遥测队列和接收器。
flowchart LR
H["HTTP请求"] --> P["Pekko server span"]
P --> A["自动Action span"]
A --> M["手动业务span"]
M --> W["有界业务执行器"]
W --> S["Scala Future"]
W --> C["WS请求"]
M --> Q["agent BatchSpanProcessor"]
S --> Q
C --> Q
Q --> O["OTLP HTTP/protobuf"]
O --> R["真实Collector receiver"]
R --> D["debug exporter证据"]
Java线程与Scala Future边界
work() 在当前请求上下文下创建 manual.controller,把该span放入一个Context,然后将 context.wrap(runnable) 提交到两个线程、16个排队位置的业务执行器。包装后的任务执行时建立相应Scope,任务退出时恢复原来的线程上下文。
Scope描述某段同步代码中“当前Context是什么”。它不是一个可跨线程传递、最后再随便关闭的全局变量。跨线程传递的是Context;每个执行片段在自己的线程中打开和关闭Scope。把Action线程创建的Scope留到WS回调中关闭,会破坏线程局部状态的恢复关系。
业务线程创建 manual.worker。Scala对象 ScalaBoundary 接收明确的父Context和Executor,使用该Executor建立ExecutionContext,再在Future体内部打开Scope,创建 manual.scala-future。Java端等待Scala产生的CompletionStage与WS结果都完成后形成响应。这个步骤包含真实Scala Future,不把Java线程池测试冒充跨语言测试。
测试进程还单独构造一个非全局SdkTracerProvider,用内存exporter检查父子关系。一个测试在父Context下提交工作,断言子span的traceId与parentSpanId都匹配;它不依赖agent自动传播,因此能单独验证显式Context传递的实现。
下面的完整Java21程序只使用API和Context。Span.wrap携带固定的有效SpanContext,程序验证执行器中的上下文,未创建SDK、未导出span。
1 | |
WS调用不能重复计算为两次下游业务
业务执行器内创建的 manual.ws 使用INTERNAL类型,表示应用定义的WS业务阶段。调用 WSRequest.get() 时临时使它成为当前Context,因此agent生成的自动CLIENT span成为它的子节点。手动阶段和自动客户端调用代表不同层次,不能把两者都计为一次独立的外部请求。
WS请求还通过全局传播器注入头部。最终到达下游的traceparent由实际HTTP服务器记录;自动插桩可能更新spanId,因此不能只比较应用最初准备的字符串。驱动取下游收到的spanId,回到Collector记录中找到对应CLIENT span,再检查它的parentSpanId确实为手动WS阶段。
第一条实际请求的traceId为 b21801fcfe0841e7b819bafa88002df4,部分节点如下。完整数据保存在 run-final/spans.json 和 scope-lineage.json。
| 节点 | spanId | parentSpanId |
|---|---|---|
| Pekko SERVER | e6d2f6dc593ff737 | 2222222222222222 |
| 自动Action | af15745ef2932bbd | e6d2f6dc593ff737 |
| 手动controller | 5ccd6c910634e37e | af15745ef2932bbd |
| 手动worker | 7cd5d6f15f08c232 | 5ccd6c910634e37e |
| 手动WS阶段 | 30a52859f86c6bab | 7cd5d6f15f08c232 |
| 自动WS CLIENT | 14964615753a0484 | 30a52859f86c6bab |
| Scala Future | 052d4317ad064208 | 7cd5d6f15f08c232 |
相同traceId只确定这些节点属于同一条trace;表中的parentSpanId才确定嵌套关系。三个请求分别使用不同的合成traceId,驱动逐条检查,避免把别的请求的span误拼入当前链路。
这个例子没有数据库事务,ok只表示本地计算与一次WS响应都完成。即使某个span名称含有“订单”或“提交”,名称本身也不能作为数据库终态证据。
流取消与span结束
流端点创建 manual.stream,保存它对应的Context,返回持续产生SSE数据的Source。真正结束span的位置在 watchTermination 回调;回调在自己的线程中打开Scope,记录 stream.terminated 事件,减少活动流计数并结束span。
sequenceDiagram
participant C as TCP客户端
participant P as Play流响应
participant T as 终止回调
participant Q as 导出队列
participant R as Collector
C->>P: 请求SSE
P-->>C: 至少一段data
C->>P: 关闭socket
P->>T: materialized termination
T->>T: 记录事件与结束span
T->>Q: ended span
Q->>R: OTLP protobuf
R-->>Q: HTTP200
Note over C,R: 接收遥测不等于客户端读完整响应
实验真实建立TCP连接,读取到 data: tick 后关闭socket,重复两次。应用的streamTerminals变为2,activeStreams恢复为0;Collector实际收到两条带终止事件的manual.stream。驱动使用每条请求的traceId查找对应span,不依赖一个全局计数来猜测归属。
完成回调里的error是否为空,不能独自区分正常结束与取消。这个实验能把终止与取消关联,是因为客户端明确执行了断开动作,而源本来会持续产生数据。它没有证明客户端消费了完整文件,也没有验证所有代理、TLS中断和网络分区下的关闭延迟。
真实OTLP接收证明到哪一层
实验启动官方Collector0.113.0,启用OTLP HTTP receiver和detailed debug exporter。agent与Collector之间放置一个只在loopback监听的小型HTTP转发器,记录请求路径、Content-Type、body字节数、SHA-256及Collector响应状态,不修改protobuf内容。
最终运行收到17个 application/x-protobuf 批次,转发后的Collector返回均为200。Collector的debug输出实际解析出71条span,其中包含自动入口、手工阶段、WS调用和流终止。span数量也包含探测请求,不能用71倒推业务调用次数。
HTTP接收200证明这一批数据被当前Collector接收处理。debug exporter输出证明这些span已经被解析并交给该输出端;实验没有配置持久化后端,不能声称数据已经耐久保存、能够跨进程恢复或永久可查询。
Collector0.113.0的 receiver/otlpreceiver/otlphttp.go 中,handleTraces 先选择Content-Type对应的解码器,读取body,再解码trace请求。解码失败返回400,调用 tracesReceiver.Export 失败进入错误映射,只有响应编码成功才写回200。这个分支解释了为何接收确认不能替代持久化确认;固定版本源码文件及SHA-256也保留在证据里。
有无遥测和导出失败使用同一stage包、同样的三个业务请求。agent模式返回recording=true;无agent模式为false。导出失败模式把OTLP地址指向未监听的本地端口,业务请求仍全部返回200和ok,服务日志实际出现 Failed to export spans。这条结果证明遥测失败没有改变这个样例的业务返回,不代表遥测故障对CPU、内存和延迟毫无影响。
有界队列与关闭顺序
agent的BatchSpanProcessor配置为最大队列16、最大批次8、调度间隔100 ms、export timeout1000 ms;OTLP网络timeout500 ms。故障对照刻意使用很小的边界,使超时和丢弃问题能在有限请求内讨论。生产容量不能直接照抄这些数值。
另一个JUnit使用SDK1.44.1建立独立BatchSpanProcessor,队列16、批次1。受控exporter接住第一条span后阻塞完成结果,再生产100条span。业务线程全部返回,释放exporter后forceFlush成功,实际导出17条,丢弃84条。这个结果属于受控SDK队列实验,不是根据网络日志猜出的agent丢弃数。
结束span、进入队列、开始导出、收到确认是不同事件。队列满时,已经结束的span可能丢弃;网络失败后,也不能保证最终会送达。业务侧因此不能把“span已结束”写成“远端一定可见”。
应用停止钩子先停止自己的业务执行器并等待退出,流端点也已收到取消;agent负责它自己的SDK关闭。三个应用进程都在SIGTERM后退出,应用日志记录drained=true、executor=true、activeStreams=0,Collector在读取完成后单独停止。导出失败日志被保留,未把它改写成关闭时所有span都已送达。
这个顺序只验证当前有界、已完成工作下的退出。SIGKILL、磁盘故障、Collector崩溃重启后的重发、关闭期间仍不断进入的新请求均未运行。
重跑与证据分层
可下载工程与完整遥测证据,用SHA256SUMS校验。共享工程 examples/play-electives/e06-otel 重新通过 2 个 JUnit 测试及 stage,3 个自有 class 与实际 jar 字节一致;真实运行的 60 条断言、73 个 span、16 批 OTLP 接收记录在 examples/play-electives/evidence/e06/integration。其中 23 个根 span 的空父节点逐一对照 Collector 原始日志,三条显式父子链单独验收。
构建运行2个真实JUnit,然后生成stage。应用控制器、Scala桥接类与stage jar按class字节核验。初次完整网络矩阵通过59条断言,另一个Collector分析脚本核对三条请求的SERVER、自动Action、手动controller和自动WS scope链。
出版复查发现日志解析器使用的 \s* 会跨过空Parent ID后的换行,把下一行ID读进父字段。公开工程改为只匹配空格和制表符,新增两个Python回归用例,并保留修正前的解析数据。原始日志的两次运行各修正22条根span;三条显式父节点链不受影响。接入复跑增加所有span的ID格式与空根父节点检查,共60条网络断言,新的traceId与批次数记录在integration目录中。
公开运行命令使用自有JDK和已下载的固定agent、Collector文件:
1 | |
工程README提供固定下载地址、校验值、构建命令和Java例子编译方式。每次运行使用新的证据目录。原始日志位于 examples/play-electives/evidence/e06/isolated,包括JUnit XML、实际版本、muzzle源码、Collector接收记录、代理批次、下游traceparent、失败日志与关闭结果。
| 验证层 | 当前已执行 | 不能据此推导 |
|---|---|---|
| Context单元测试 | 指定Executor上的父子ID | 所有库都自动传播 |
| SDK队列单元测试 | 101产生、17导出、84丢弃 | agent在另一负载也丢84条 |
| 真实网络 | WS请求头与Collector父子链 | 业务数据库已经提交 |
| 流终止 | 两次TCP取消、两条终止span | 客户端读完整响应 |
| Collector接收 | protobuf解析及debug输出 | 持久化存储与灾难恢复 |
两个改动练习
禁用某一种自动插桩,只保留手动业务阶段,重跑相同HTTP请求并比较scope、span数量与下游traceparent。目标是明确哪一个组件创建了哪个span;不要把“少了一条自动span”直接判断为业务调用丢失。
把OTLP转发器改为接收后延迟应答,并保持队列大小固定。分别记录业务返回耗时、实际收到的批次、导出超时和关闭耗时。恢复接收器后再次查询哪些trace可见,保留丢失范围,不把最终一次200响应解释为之前所有数据都补发成功。
参考:OpenTelemetry Java API、Java agent配置、固定Pekko插桩构建配置、Collector0.113.0 HTTP接收分支。
上一节:E05 Pekko Actor。下一节:E07 虚拟线程与阻塞IO。
