Java、Redis 与异步消息的证据链
2026-10-21
同一条用户反馈“下单很慢”,可以引出完全不同的改动。有人扩大线程池,有人增加 Redis 内存,也有人把消息消费改成同步等待。它们都可能让某个局部数字变好,却没有回答最初的问题:用户等待的那段时间,系统到底做了什么?
可观测性首先是一种证据组织能力。指标告诉我们哪些现象值得注意,追踪把一次工作分解成有因果关系的区间,日志补充当时的决定和结果。三个后台同时上线,不会自动得到这种能力;必须先定义工作边界、身份、时间和结果,再让采集与查询保留这些定义。
这本书适合已经会写基本 Java 服务的读者。主线是一套可以执行的小系统:客户端通过 HTTP 网关创建订单,订单服务访问 Redis、发布 RocketMQ 消息,消费者完成异步处理。三个逻辑服务使用真实 OpenTelemetry Java SDK,通过 OTLP 把遥测发送给 Collector。Tempo 保存和查询 trace,Prometheus 抓取指标并计算告警;结构化日志同时输出到应用日志与 OTLP 日志管线。这里没有用一张内存列表替代追踪后端。
为了降低环境复杂度,网关、订单服务和消费者运行在同一个 JVM 内,但使用三个独立的遥测资源与真实 HTTP、Redis、RocketMQ 连接。它适合研究传播边界,不能据此宣称验证了跨主机网络或独立进程的全部行为。我们也没有部署 Grafana 或 Loki;本书直接查询后端 API,日志证据保存在运行产物里。先把证据取得,再决定用什么界面呈现。
阅读顺序可以分成三段。第 1—4 章建立证据模型、运行环境和 HTTP 传播;第 5—8 章处理 Redis、消息、日志与指标;第 9—13 章进入 Collector、后端查询、采样、成本与 SLO;第 14—16 章把这些能力组织成故障演练、采集故障处理和生产交付方案。附录包含命令、练习解答、官方来源及从项目自动生成的完整代码。
实验使用固定版本与镜像摘要。它们是本书可以复核的基线,不表示当前生产系统应该照抄这组版本。本地没有容器环境时,也可以查看仓库 Actions 保存的真实集成产物,再按正文检查 JSON、span 关系与日志,而不是只相信一个“测试通过”的徽章。
实验中特别保留了三个容易误判的情况。第一,在 Redis 客户端 span 内注入等待,只能证明这个区间变长,不能证明 Redis 服务端执行变慢。第二,订单接口返回 202,不表示消费者已完成业务。第三,采样关闭后看不到 trace,不表示请求没有发生。我们将通过不同证据区分这些情况。
每章都先给出一个需要解释的问题,再推导所需的信息和采集位置,最后连接到可执行命令或证据文件。代码片段用来说明局部机制;运行入口是
lab/run_ci.sh
与完整项目。没有特别标为实际结果的数字,均是计算示例或实验预期。最终验证记录会给出对应提交和运行入口,避免把旧报告当成新代码的证明。
可观测性不会替代业务正确性测试,也不会因为接入 SDK 就自动具备生产安全、隐私治理和高可用。本书希望帮助你形成一种更具体的习惯:先说明想证明哪件事,找到能反驳自己假设的证据,再修改系统。
收到慢请求反馈后,最危险的第一步往往是直接改参数。一次请求可能在网关等待连接、在应用排队、访问缓存,也可能已经返回给用户而后台消息仍未完成。如果没有把这些区间分开,“慢”就不是一个可用于决策的描述。
本书把用户提交的一次 HTTP 请求,与由它触发的一次消息处理分开。前者的结果可以是 202 已接受,也可以是 503 实验失败;后者的结果是消费者写入专用 Redis 处理标记。两者通过订单标识与追踪上下文联系,但具有不同的完成条件。用户等待时间是网关入口到响应返回的时间,异步完成时间还要覆盖消息传递和消费者处理。
这种区分决定了监控是否会说真话。假设接口始终在 30 毫秒返回 202,而消费者停滞十分钟,HTTP 延迟图仍然很好看。此时继续优化 HTTP 并不能恢复业务结果;我们还需要观察消费进度、处理结果和业务等待时间。反过来,消费者处理正常也不能证明入口没有大量拒绝。
实验把遥测分成三类。lab.requests
是可聚合的请求计数,适合比较一段时间内的错误比例;一个 span
描述某次工作从开始到结束的区间,适合寻找这次工作的组成;日志记录
order.queued、worker.processed
等事件,适合解释具体决定。三者的分母、保留和采样方式不同,不能直接把数量当作应当相等的数字。
“可能是 Redis 慢”过于宽泛。更可检查的说法是:“在这次网关请求对应的 trace 中,订单服务的 Redis 客户端区间占据了大部分同步耗时。”这个说法可以被 trace 反驳:如果长区间在 HTTP 客户端而 Redis span 很短,就应该继续查看连接、上游服务或未被仪表化的区间。
“消息上下文可能丢失”也需要具体化。在默认传播实验中,消费者的 trace ID 应当与入口响应中的 ID 相同,消费者父 span 应当是发布 span。关闭传播后,订单仍会被消费,但工作者建立新的 trace。两种情况都要运行,才能证明我们的检查确实区分了传播与业务成功,而不只是看到了一个绿色页面。
这里的 order_id 是业务关联字段,trace ID
是一次执行的技术身份。同一订单可能被读取很多次,也可能在重试中产生多个工作区间。把订单号直接当
trace ID,会把独立执行硬塞到同一棵树里,反而妨碍理解。
运行后,evidence/results.json
保存场景与响应,trace-*.json 保存 Tempo
原始返回,events.json
保存应用事件,metrics-requests.json 与
alerts.json 保存 Prometheus 查询。读者应能够从一条响应里的
trace ID,走到 span 树,再走到同一 span ID 的日志。
我们不要求每个问题都同时查看三种信号。指标用于判断范围,trace 用于定位一次执行,日志用于解释决定。最有效的排查通常是逐步缩小范围,而不是先把所有后台打开。
练习。 为“用户说订单成功了,但统计没有变化”写两个互相竞争的假设,分别说明需要哪个完成条件、哪份证据,以及出现什么结果时应当放弃该假设。不要把“多打一些日志”作为完整答案。
本章关于上下文和信号边界的基础定义可对照 OpenTelemetry 上下文传播说明。
一张架构图只展示了作者想表达的连接,不能证明这些连接真实发生。我们的实验先启动实际依赖,再执行 Java 程序,最后通过后端查询验证遥测。某个环节缺失时,验收应当失败,而不是由程序自己打印“已发送 trace”就结束。
Java 21 运行一个入口网关、订单 HTTP 服务和 RocketMQ
消费者。它们共用进程,是为了把环境成本集中在传播、采集和查询上;三个
Telemetry 实例分别设置
book-gateway、book-orders、book-worker。网关通过真实
Java HttpClient 访问 8081,订单服务通过 Jedis 访问 Redis,再通过经典
Remoting 客户端发布 RocketMQ 消息。
容器栈包含 Redis 7.2.5、RocketMQ 5.3.2、Collector Contrib
0.111.0、Tempo 2.6.1 与 Prometheus 2.55.1。Java SDK 固定为 OpenTelemetry
1.55.0,Jedis 固定为 5.2.0。book/image-lock.json
保存镜像清单摘要,Compose
在标签后同时写入摘要。标签方便人阅读,摘要约束实际拉取内容;升级时仍须重新执行验收。
这些组件不需要都向宿主机开放。实验仅把读者操作和验收用的端口绑定到
127.0.0.1。Prometheus 使用 9095,避免与常见的 9090
服务冲突。Collector 在容器网络里向 Tempo 的 OTLP gRPC 4317 导出,宿主
Java 则使用 Collector 的 HTTP
4318。相同数字在不同网络命名空间中,并不意味着同一个监听器。
在本书根目录准备 JDK 21、Maven 与 Docker Compose:
mvn -f lab/pom.xml --batch-mode --no-transfer-progress package
bash lab/run_ci.sh脚本先创建独立 Compose project,等待 Broker 能够创建主题,检查 Redis PING,再启动 Java 应用。Java 只有在 Redis 可连接、生产者与消费者已经初始化后才暴露健康入口。随后 Python 验收程序提交场景请求,查询实际 Tempo 与 Prometheus。退出时脚本只清理本实验 project 的容器和卷,并停止自己启动的 Java 子进程。
不要把脚本中的端口改成指向已有生产依赖。Redis 键使用
otelbook: 前缀,实验不会执行 FLUSHALL;RocketMQ
使用专用主题与消费组。这些约束降低误混数据的概率,但不替代你在运行前检查
Compose project 与监听端口。
容器状态为 running 只能说明入口进程尚未退出。Broker 可能还没有注册,Collector 可能因为配置错误而拒绝遥测,Tempo 也可能处于查询未就绪阶段。因此脚本用带超时的重复查询等待业务条件,而不是固定睡眠三秒后假设环境准备完毕。
验收还保留反例:消息业务成功但上下文断开、采样为零但指标继续出现。只有正例的测试容易把网络、库配置或查询误解掩盖掉。运行产物应当记录返回内容、版本、镜像和提交;当代码改变时,需要新的运行证据。
本地没有容器运行时的读者可以查看仓库 Actions 的
observability-evidence artifact。它证明对应提交在 CI
环境的行为,不代表你的电脑也已经完成部署。
练习。 Collector 的 4318 可连接、Prometheus 的
up 为 1,是否足以证明网关请求已进入
Tempo?写出至少两个仍可能失败的环节,并指出应查询哪个接口验证。
RocketMQ Docker 启动与 Broker 对外地址可对照 官方快速开始。
span 的价值不在数量,而在它回答了什么问题。给每个函数套上计时器,可能得到上千个区间,却仍然看不见等待资源、调用远端和业务提交之间的关系。仪表化首先需要选择有意义的边界。
入口的 server span 描述网关处理一次请求。它内部有一个 client span,描述网关向订单服务发起的 HTTP 调用;订单服务再建立自己的 server span。客户端与服务端区间有重叠是正常的,它们从不同观察点描述同一次远程操作,不能直接相加计算总耗时。
Redis 操作和 RocketMQ 发布分别是订单服务内部的 client、producer span。消费者使用 consumer span,后面还包含写入处理结果的 Redis client span。这样选择边界,是为了区分同步响应、发布确认和异步业务完成。发布成功不需要等待消费完成,消费者 span 因而可能在入口结束后继续运行。
创建 span 不会自动让它成为当前上下文。Java 代码使用显式 Scope:
Span span = telemetry.tracer.spanBuilder("redis SET order")
.setSpanKind(SpanKind.CLIENT).startSpan();
try (Scope ignored = span.makeCurrent()) {
redis.setex(key, 3600, value);
} finally {
span.end();
}makeCurrent() 影响当前执行范围里随后创建的子
span、日志上下文和传播头。关闭 Scope 恢复先前上下文;end()
结束计时。这两个动作职责不同,只做其中一个都会留下问题。漏掉 Scope
关闭可能让后续工作错误继承身份,漏掉 end 则可能使 span
长期留在未完成状态。
异常被记录到 span,并不自动意味着业务向用户返回失败;有些异常会被恢复。反过来,一个受控返回 503 的分支也未必抛异常。本实验显式设置 ERROR 状态,同时保留 HTTP 结果,避免把“没有异常堆栈”误解为成功。
仪表化本身也可能失败。Exporter
不应把网络导出放到业务关键路径同步等待;本实验使用
BatchSpanProcessor。它在后台批量导出,但队列和重试都有界,不能承诺采集故障期间的数据永远不会丢失。/lab/flush
是验收工具,用来缩短等待已结束数据导出的时间,不是生产接口设计。
redis SET order 是稳定操作名,具体订单号放在
order.id 属性。若将每个订单号都拼进 span
名称,后续按操作聚合会变得困难。类似地,HTTP 使用 /orders
路由模板,不把完整 URL 当成操作类别。
Trace 属性可以高选择性地包含业务关联标识,但这不意味着可以无边界记录请求正文。实验仅记录合成订单标识,不记录真实客户信息。一个有用的检查是:如果这条属性被复制到日志、告警或共享截图里,是否仍符合团队的数据规则?
运行后,可以在 Tempo 返回中检查
startTimeUnixNano、endTimeUnixNano、spanId
和
parentSpanId。验收程序把它们转换成便于比较的记录,但仍保留原始
JSON,避免只剩作者加工过的结论。
练习。 如果一段异步任务在创建时继承了父上下文,但父 span 已结束,它就一定是错误的父子关系吗?说明时间重叠与因果关系分别表达什么,并给出一个应考虑使用 link 的场景。
SDK、Tracer、Span 与 Scope 的具体用法见 OpenTelemetry Java 仪表化文档。
网关和订单服务各自生成一个 trace,画面上看起来也都有请求与耗时。问题在于,维护者无法证明这两个请求就是同一次调用。时间接近不是因果证据,尤其在高并发、重试和时钟偏差存在时。
W3C Trace Context 用 traceparent 传播 trace ID、父 span
ID 和标志位。业务 JSON
仍只表达创建订单的意图。将传播身份放在独立协议字段里,既方便跨语言接入,也避免每个业务消息都自行发明一套上下文格式。
本实验网关在入口使用 propagator 的
extract,以收到的上下文创建 SERVER
span;向订单服务调用时,先创建 CLIENT span,使其成为当前上下文,再向
HttpRequest.Builder 注入头。订单服务提取这个头后创建自己的 SERVER
span。因此服务端父 span 指向调用方的 client
span,而不是随便指向某个仍然存在的入口 span。
这个顺序很重要。如果先 inject、再创建 client span,订单服务可能直接成为网关入口的子节点,真正的远程调用区间反而与它成为兄弟关系。整个 trace ID 仍相同,单靠“ID 没丢”检查就发现不了。我们的验收保留 span ID 与父 ID,要求在必要边界检查具体父子关系。
单独运行服务后,可以提交一个合成订单:
curl -sS http://127.0.0.1:8080/orders \
-H 'Content-Type: application/json' \
-d '{"id":"http-example"}'响应的 trace_id 是后续查询入口。不要把书中某次运行的 ID
写进脚本,重新运行会产生新身份。使用这个 ID 查询 Tempo,应该找到网关
server、网关 client 与订单 server。HTTP 响应还带
X-Trace-Id,便于人在排查时取得关联标识;它不是权限凭证,也不能替代服务端审计。
网关计时包含发起和等待上游的时间,订单服务计时从自身收到请求开始。两者之间的差值可能包括连接、网络、调度与未覆盖区间,不能直接命名为“网络耗时”。需要更精细的证据时,才继续引入连接池和网络层仪表化。
外部调用方可以提供自己的 traceparent。它可能格式错误,也可能带着不适合内部采样策略的标志位。本书采用标准提取器处理格式,并用 parent-based sampler 演示继承;没有实现面向不可信租户的身份隔离和采样配额。生产入口需要明确何时接受外部上下文、何时新建内部 trace,并通过 link 保存必要关联。
不要把可识别用户的信息放进 baggage 只是为了方便传递。baggage 会继续向下游传播,传播范围可能超出最初预期。订单标识在实验里作为明确的业务字段传递,只有需要的遥测位置才把它记录为属性。
练习。 你看到网关和订单服务的 trace ID 相同,却发现订单 server 的父 ID 等于网关 server 的 span ID。给出一段可能造成该结果的错误注入顺序,并说明为什么普通业务测试仍可能全部成功。
协议格式见 W3C Trace Context,提取与注入机制见 OpenTelemetry 上下文传播。
假设同一条请求中,Redis span 从几毫秒变成几百毫秒。最容易说出口的结论是“Redis 变慢了”,但这个 span 通常从客户端调用前开始,到客户端获得结果后结束。连接池等待、应用线程调度、序列化、网络和服务端执行,都可能落在这个区间里。
订单服务创建 redis SET order client span,然后调用 Jedis
的真实 SETEX。实验通过 redis_delay_ms 在该 span 内、实际
Redis 命令之前等待。这个设计故意制造一种很像缓存依赖变慢的
trace,却让我们知道真正的等待发生在应用侧。
{"id":"redis-slow","redis_delay_ms":350}输入范围限制在 0—1500 毫秒,避免实验参数变成无限休眠工具。运行产物中
trace-redis-slow.json 保存原始
trace;results.json 还记录该 client span
的实际持续时间。验收只要求注入 350
毫秒时观察区间至少覆盖其中大部分,不会断言整个请求恰好耗时 350 毫秒。CI
调度、消息发布和导出都可能带来额外时间。
先执行 normal,再执行 redis-slow。比较时保持路由、业务数据规模和消息处理方式基本一致,只改变等待参数。若 Redis client 区间显著变长,而 RocketMQ 发布区间没有同样增长,故障范围就比“一切都慢”小得多。
但这仍然只是客户端视角。要进一步断言服务端执行变慢,需要结合 Redis 命令统计、慢日志或服务器资源。本书没有把这些证据放进自动验收,所以结论应停在“客户端包围的这段工作变慢,且实验注入位于该范围”。这不是保守措辞的游戏,而是避免下一步错误地给 Redis 扩容。
反方向也值得练习:如果网关慢、订单 server span 慢,但 Redis 与发布区间都短,说明存在未被这些子 span 解释的时间。可能是线程等待,也可能是没有仪表化的业务计算。不要为了使图形看起来完整,直接把空白区间归到最近的依赖头上。
示例使用 otelbook:order:<id>,TTL
为一小时,消费者结果另写
otelbook:processed:<id>。这些键便于读者独立核查状态,也保证实验不需要清空整个
Redis。GET 订单入口会产生自己的 HTTP trace 与 Redis GET
span,不能假定它继承创建请求的
trace;它们通过订单号关联的是同一业务对象,不是同一次执行。
本实验没有展示缓存命中率优化,也没有模拟 Redis 集群故障。JedisPooled 提供连接管理,我们手工创建的 span 只包围明确代码范围,不等于自动观测了内部每次连接重试。接入自动仪表化时,需要避免同一命令同时被手工和 agent 重复包围,造成重复计数或混淆。
练习。 列出 Redis client span
内可能发生的四类等待。选其中两类,分别说明能补充什么独立证据;再说明为什么把
redis_delay_ms 实验结果写成“Redis
服务端延迟测试”是不准确的。
客户端接口和生命周期可对照 Redis 官方 Jedis 文档。
同步 HTTP 调用很容易让人把上下文传播理解成“调用栈里的变量”。消息跨过队列后,生产者与消费者可能相隔很久,也可能运行在不同进程。消费者线程不会因为业务上处理了同一条消息,就自动拥有生产者的 Context。
订单号标识业务对象,消息 ID 标识一次消息投递相关的技术对象,trace ID 标识一次因果执行。它们不应互相替代。一个订单可能产生创建、支付、取消等事件,一个事件也可能被重投;如果只靠订单号聚合执行,就无法区分独立读取和重试。
实验在 producer span 成为当前上下文后,把 W3C 字段注入 RocketMQ message user properties。消费者从 MessageExt 取回这些字段,以提取结果创建 CONSUMER span。应用 JSON 保留订单号与受控消费等待参数,消息协议字段保留技术上下文,两者职责分开。
验收要求 consumer 的父 span ID 等于 producer 的 span ID,并且三个服务的 span 出现在同一个 trace 中。只检查 trace ID 相等还不够,因为一个错误的上下文选择也可能保留 ID,却把工作挂到错误的父节点。
向 /orders 提交:
{"id":"broken-context","propagate":false}订单依然写入 Redis,消息依然被 RocketMQ
消费,消费者依然写入结果。差异是消费者没有可提取的技术上下文,于是创建新的根
trace。验收通过 worker.processed 事件取得第二个 trace
ID,再分别查询两个 trace,证明业务成功与追踪连续性是两个独立属性。
这个负例在真实系统里很常见:某条旧消息格式没有属性透传,转发服务只复制正文,或者框架更换了属性名。排查时若只看“消息没有积压”,会完全错过可观测性断点。反之,看到断点也不能立即断言消息丢失。
本书采用单消息、单处理者的 parent-child 表达,适合展示最小因果链。批量消费、聚合多条消息、长期任务或多次重投时,一个工作区间可能有多个输入来源;span link 比强行挑一个父节点更能保留这些关系。选择表达方式应基于业务语义与所用框架约定,不要把单例代码当作所有消息系统的统一标准。
worker_delay_ms 会使 consumer span
持续变长,而入口仍可能很快返回 202。这个实验帮助我们区分 HTTP
接受延迟与异步完成延迟。若真实业务承诺“订单必须在一分钟内完成”,还要设计从业务事件时间到处理完成时间的
SLI,不能用入口 p95 代替它。
消费者示例在异常时返回 RECONSUME_LATER,没有实现完整业务幂等事务,也没有验证所有 Broker 故障窗口。这里关注的是每次处理是否有正确因果身份;业务重投语义仍应按消息系统和应用约束单独测试。
练习。 一个消费者把十条来自不同 trace 的消息聚合成一次写入,应该怎样表达这些来源?请画出一种 link 方案,再说明把十个 trace ID 拼成新的业务 trace ID 会丢失哪些语义。
消息属性与消费行为可从 RocketMQ 官方文档继续核查;上下文的作用范围见 OpenTelemetry 传播文档。
一次正常请求不能说明整段时间的服务质量,一次很慢的请求也不能说明所有用户都受影响。指标把大量执行压缩成可以比较的序列。压缩意味着必须选择保留哪些维度,以及愿意丢弃哪些细节。
lab.requests
在网关和订单服务结束请求时增加,标签只有稳定路由与 ok/error
结果;资源带服务名与版本。它不是一个“当前并发请求数”,不能在请求结束时减回去。Prometheus
导出的序列名是
lab_requests_total,累计值在进程重启时可能回到较小数字,速率计算需要识别这种重置。
计算入口错误比例时,先聚合错误速率,再除以全部速率:
sum(rate(lab_requests_total{service_name="book-gateway",outcome="error"}[1m]))
/
sum(rate(lab_requests_total{service_name="book-gateway"}[1m]))
不要先求每个实例的百分比再简单平均。一个实例处理一万次请求,另一个只处理一次,它们不能拥有相同权重。也不要混入健康检查来稀释业务错误率。本实验
/health 与 /lab/*
不进入业务计数;实验规则因此有明确分母。
请求耗时记录为秒,并使用显式桶边界。Prometheus 中
_bucket 是累积桶:le="0.5"
表示小于等于半秒的观察次数,不表示只处于相邻两个边界之间的次数。要观察一段时间的分布,通常先对桶计数求
rate,再按 le 聚合。
histogram_quantile(0.95,
sum by (le) (
rate(lab_http_duration_seconds_bucket{
service_name="book-gateway"}[1m])
)
)
这个 p95 来自桶内插值,不是把每条原始请求重新排序。桶过宽会影响解释精度;低流量时还要关注样本量和窗口。实验中的一次 350 毫秒注入可以帮助你检查桶分布是否变化,但不能把某次计算出来的 p95 当作可复用的性能基准。
单靠 service_name 与 route
无法从一条聚合序列找到唯一 trace。为此,直方图可以携带
exemplar,保留少量观察值与当时的 trace/span
上下文。本项目记录耗时时显式传入 span Context,因为 try-with-resources
关闭 Scope 后,线程上的“当前 span”已经恢复,不能指望 finally
中自然取得正确上下文。
Collector 的 Prometheus exporter 开启 OpenMetrics,Prometheus 启用
exemplar storage。验收查询 /api/v1/query_exemplars,确认
exemplar 里的 trace ID 能与本次应用事件关联。它不是为每一个观测值都保存
trace,也不是给指标增加 trace_id
标签;两者对序列数量的影响完全不同。
指标、exemplar、trace 的保存时间可能不同。点击一个 exemplar 后查不到 trace,既可能是采样、过期,也可能是导出失败。查询界面需要允许这种情况,并保留原始指标作为群体信号。
练习。 两个实例分别处理 1000 次和 10 次请求,错误率分别是 1% 和 50%。计算整个服务的错误比例,并解释为什么“平均错误率 25.5%”误导了判断。再说明将 trace ID 作为指标标签会带来什么后果。
查询与 exemplar 接口见 Prometheus HTTP API。
把 SDK endpoint 改成 Collector 后,很多团队会认为采集可靠性已经被统一解决。实际上,Collector 只是把接收、处理和导出组织到一个独立进程里;队列、内存、重试、磁盘和下游可用性仍然存在边界。
本书 Java SDK 使用 OTLP HTTP,分别向
/v1/traces、/v1/metrics、/v1/logs
导出。Collector 的一个 OTLP receiver 可以接收三个信号,但 service
pipelines 要分别声明它们的处理与去向。仅在配置里定义 exporter,而没有在
pipeline 里引用,并不会让数据自动流向它。
Trace 管线导出到 Tempo 的 OTLP gRPC 地址
tempo:4317;metrics 管线暴露 Prometheus exporter,由
Prometheus 主动抓取;logs 管线写 debug
exporter。它们没有共享同一种交付确认语义:SDK 的 HTTP
导出成功,不意味着稍后的 Prometheus
抓取已经完成,也不意味着日志已经进入一个可长期查询的数据库。
按这个顺序排查很实用:业务是否记录了信号,SDK 是否有可导出数据,Collector receiver 是否接收,processor 是否拒绝,exporter 是否成功,最后才是后台是否按预期查询。每一段都有可能让“我已经接入 OTel”与“我可以解释这次请求”之间出现断层。
实验把 memory_limiter 放在 batch 前面,限制进程接收压力,再将小批次攒成更合适的导出单元。batch 的 timeout 是延迟与效率之间的取舍;设得更小可以缩短可见等待,却增加请求开销。它不能被当作端到端可见时间的严格上限,因为下游、队列和重试也需要时间。
memory_limiter 在压力下可能拒绝数据,让上游有机会退避。它不是操作系统级的硬内存限制,也不保证整个容器永不 OOM。SDK 和 Collector 都可能拥有自己的缓冲,评估容量时需要把多个位置的排队同时考虑,而不是只计算一个配置项。
本书没有配置持久化发送队列。Collector 被停止或机器断电时,不应承诺未导出的所有数据可以恢复。生产若需要更强的交付保证,需要明确支持持久队列的组件、磁盘位置、容量、重放顺序及下游限流,并通过故障注入验证。
health_check 的 13133 可以帮助判断 Collector
进程是否能响应,但不是业务 trace 的查询接口。类似地,Prometheus 的 up=1
只说明抓取成功,不说明 Java
请求计数正在增长。最好在运行手册中把“进程可达”“管线有流量”“后端可查询”写成三项不同检查。
实验的故障阶段会停止本次 CI 专用 Collector,再提交业务请求,观察业务是否仍可完成;恢复后再提交新请求,检查新的完整 trace。对故障窗口里旧 trace 的查询结果只如实保存,不把后来恢复连接解释为历史数据绝不丢失。
练习。 SDK 导出返回成功,但 Prometheus 看不到新的请求指标。按本章的管线写出四个检查点,分别说明应查看哪个 endpoint、配置引用或运行信号。不要把重启所有组件作为第一步。
具体组件与 pipeline 规则见 Collector 官方配置文档。
彩色瀑布图很直观,但它是后端数据的一个呈现方式。为了让实验能在 CI 中独立核查,本书直接查询 Tempo 的 HTTP API,保留原始返回,再由检查器提取服务、操作名与父子关系。
提交订单后,响应里的 trace_id 是本次执行的查询键:
curl -sS -H 'Accept: application/json' \
http://127.0.0.1:3200/api/traces/替换为本次trace_id32 位十六进制文本是人常用的表示形式。不同协议中的二进制 ID 可能在 JSON 里以 base64 表示,因此验收先标准化 ID,再比较父子关系。只比较两个看起来不同的字符串,而不确认编码方式,会得到虚假的“上下文断开”。
Tempo 可能需要一段时间才查询到刚结束的 span。验收使用有上限的轮询等待,不把首次 404 立即解释为永久丢失;同时也不会无限等待,让后端故障被隐藏。HTTP 200 也可能只包含先到达的一部分 span;验收会继续等到场景所需的服务与区间都出现,而不是遇到首个 200 就断言整条链路完整。采样为零的阶段则在确认业务已经发生、导出等待完成后,明确检查该 trace 不存在。
normal 场景至少应能找到三个服务。网关 server 包围自己的 HTTP client,订单 server 从该 client 传播而来,Redis 与消息发布位于订单执行范围。消费者 parent 指向消息 producer,随后有自己的 Redis 处理结果区间。
这些约束比“span 数量等于七”稳定。如果将来增加数据库或连接池区间,span 数量变化并不一定是故障;但消费者错误挂到另一个请求上仍然是故障。本书验收同时保留 span 列表,使读者能够检查为什么某条断言成立,而不是只有一串布尔值。
服务名来自 Resource,不应该由 span 操作名猜测。一个 JVM 中可以有多个遥测资源,本实验用它区分三个逻辑服务;生产中还需要实例身份、部署环境和版本。版本是定位发布影响的重要维度,但如果把每次请求的随机数放进资源,后台就会把它们当成大量不同资源处理。
客户端与服务端 span 往往重叠,异步消费也可能与入口尾部重叠。将所有 span 时长求和,可能大于用户实际等待时间。要分析关键路径,需要先明确哪一个结果是完成条件,再沿因果与依赖关系查看阻塞区间。
本实验的 redis-slow 与 worker-slow 分别改变同步和异步区间。前者会延长入口等待;后者可能在入口返回后继续增长。如果只按最长 span 排序,可能把一个并未阻塞用户响应的异步区间当成入口变慢原因。这也是为什么用户症状必须先被准确描述。
练习。 一条 trace 中网关总耗时 500 毫秒,订单 server 450 毫秒,消费者 800 毫秒。你能否由此断言用户等了 1750 毫秒?写出两种可能的时间关系,并说明需要哪些开始与结束时间才能判断。
查询路径与响应格式以 Tempo API 文档为入口,实验固定版本的实际返回保存在证据包中。
一个请求没有出现在追踪后台,可能是请求没到,也可能是没有被记录、尚未导出、被采样、被后端拒绝或已经过期。若把“查不到 trace”直接等同于“请求没有发生”,可观测性系统反而会制造错误结论。
本书使用 parent-based trace ID ratio sampler,默认比例
1.0。验收完成常规场景后,停止自己启动的 Java 子进程,再以
SAMPLER_RATIO=0 启动同一程序,保留 Redis、RocketMQ
与遥测后端运行。新的根请求不记录
trace,消费者继承未采样标志,但业务仍然应当完成。
采样为零阶段保存响应、消费者事件、Tempo HTTP 状态和指标查询。它要求
worker.processed 确实出现,并标记 sampled=false;Tempo
查询返回
404,而请求指标仍可见。这个组合比单独展示一张空白追踪界面更能说明采样的作用。
没有采用 0.1 比例来证明“恰好保留十分之一”,因为短时间、少量请求中比例会波动。确定的 1 与 0 先验证策略连接,统计采样效果则需要更大样本与误差分析。
parent-based 策略尊重已有上下文的采样决定,避免同一 trace 中各段随意割裂。但这也意味着入口接受外部上下文时,需要考虑谁能够影响采样。对不可信调用方,生产网关可能要新建内部 trace 并通过 link 关联,或实施明确的采样配额。不能一边完全继承外部标志,一边假设内部成本始终由自己控制。
头部采样在工作开始前决定,无法根据后来出现的错误自动保留一个此前没有记录的完整 trace。尾部采样则需要在 Collector 等位置观察更多 span 后再选择,代价是更多内存、等待时间,以及同一 trace 汇聚到合适决策位置的路由要求。
本实验没有启用尾部采样,也没有验证多 Collector 的 trace 分片。因此本章将尾采样作为设计推导,不把本地配置中的 batch 误称为已经完成尾采样。
HTTP 计数器表达全部被仪表化请求的累计事件,通常不应该跟着 trace 采样一起按比例丢弃。日志也有独立保留与限速策略。于是你可能看见一个错误日志,日志有 trace ID,但追踪后台没有对应内容;排查工具应该给出合理解释,而不是把它标成不可能状态。
Exemplar 也依赖可关联的观察上下文,不能保证每个桶变化都有一个可查询 trace。设计跳转时,需要同时处理缺失、过期与访问权限。一个能优雅说明数据边界的界面,比永远显示“加载失败”更有用。
练习。 维护者希望“只保存出错请求的完整 trace”,却只在入口把 ratio 设为 1%。解释为什么这个设置无法保证目标,再列出尾部采样需要新增的两项容量或路由约束。
采样与上下文的官方概念可从 OpenTelemetry
Java 文档继续核对;实验实际 sampler 配置以
Telemetry.java 为准。
一个指标的名字只有一条,并不意味着后台只保存一条序列。标签的不同取值组合会产生不同序列。如果把每个订单号、trace ID 或完整 URL 都加入标签,流量越大,序列数量就可能越接近请求数量。
假设一个 HTTP 指标有 8 个稳定路由、3 类结果、10 个实例,理论组合是 240。若再添加每天一百万个不同订单号,维度乘积会跃迁到完全不同的量级;直方图还要为每组标签保存多个桶、sum 与 count。这是成本结构的推导,不是本书声称做过的一百万序列压测。
实验请求计数只保留 route 与
outcome,服务、版本和环境来自 Resource。验收查询全部
lab_requests_total,检查序列标签不包含 order_id 与
trace_id。订单标识仍能存在于 span 和日志中,exemplar
则以受限样本把指标观察关联到 trace,不需要把 trace ID
变成普通指标标签。
资源属性同样需要审查。启用
resource_to_telemetry_conversion 会让资源属性进入
Prometheus
标签,这对演示服务筛选很方便,却可能意外放大成本。不要把每次启动生成的长随机配置、客户信息或请求属性放进
Resource,只因为 exporter 会自动处理它们。
限制基数并不等于所有细节都不记录。维护者确实可能需要按某个订单调查问题,只是不一定应该通过全量指标索引完成。常见分工是:指标回答群体变化,trace 和受控日志回答某次执行,业务数据库回答对象的权威状态。
在真正删除字段前,应说明查询还怎样完成。若团队依赖 tenant 维度判断影响范围,可以先把租户分组或将少量关键租户单独观察,而不是直接删除所有隔离信息。若要记录错误原因,也应考虑稳定的错误类别,避免把含动态文本的异常消息作为标签值。
本书的 ok/error 很粗,适合最小实验;生产可能需要有限的
HTTP
状态类别、操作类型与错误码。新增每个维度时,都应估计取值上限、组合关系与保留窗口,并用实际序列查询验证估计。
请求正文、认证头、URL 查询参数和消息正文可能含敏感信息。一次方便调试的全量记录,可能被复制到 Collector、日志后台、告警和共享截图。到达后端再脱敏,无法撤回此前已经经过的所有副本。
因此优先在产生信号的边界实施最小记录规则,再在 Collector 加第二层防护。实验使用合成订单号,并不记录完整请求正文或密钥。CI 证据包只有专用实验数据,不能把它的公开方式直接套在真实客户系统上。
练习。 设计一个“接口成功率”指标,给出不超过三个标签,并估计每个标签的取值上限。然后写出一次具体订单故障应怎样从该指标跳到 trace 或日志,说明哪些信息属于普通标签、exemplar 和事件字段。
命名与标签设计可参考 Prometheus 指标实践;度量数据模型见 OpenTelemetry Metrics。
一条告警的价值不在于它能变红,而在于它提醒谁、哪种用户结果正在恶化、下一步应做什么。没有定义分母和时间窗口的“错误太多”,通常会在低流量、重启或发布时产生难以解释的噪声。
本实验的入口 SLI 把业务请求分成可接受与失败两类。202 表示请求已经接受并完成示例中的发布流程;它不表示异步订单处理成功。我们可以为入口定义可用性目标,但若真正的用户承诺涉及处理完成时间,还必须增加异步 SLI。
以 99% 请求可用性为计算示例,允许的错误比例是 1%。若短窗口实际错误比例为 5%,消耗率就是允许水平的 5 倍,称为 burn rate 5。这个比值解释了为什么同样的错误率,在不同目标下意味着不同紧迫程度。
本书并不据此宣称一个几分钟实验能够证明月度 SLO。实验窗口只验证规则的计算、最小流量条件、pending 与 firing 状态,生产窗口和阈值需要依据用户目标、流量形态与响应能力另行确定。
Prometheus 规则文件使用一分钟 rate 窗口,错误比例超过 5%,同时窗口内请求增量不少于 5,持续两秒后进入 firing。最小请求量条件避免一次低流量错误立刻触发百分比告警;两秒是为了缩短教学验收,不是推荐的值班阈值。
验收先提交正常请求,再逐步注入五次应用失败,最后查询
/api/v1/alerts。原始返回保存在
alerts.json,可以检查 alertname、state、activeAt
与当时的计算值。应用失败分支返回 503 并设置 span
ERROR,关联日志保留请求上下文;这样告警与具体执行之间有可核查的路径。
规则只说明条件满足。没有配置 Alertmanager、值班路由、静默、去重或通知发送,因此不能把 firing 截图写成“告警已经通知到人”。在真实交付中,通知链与运行手册必须另外验收。
单看触发测试会忽略另一半生命周期。若规则直接对累计错误计数大于零告警,那么一旦出现过错误,系统再健康也不会恢复。使用 rate 或 increase 才能让观察窗口随时间滑动;重启导致的计数重置也需要正确处理。
短窗口对突发敏感,长窗口对持续退化更稳定。多窗口 burn-rate 规则尝试同时限制短期噪声与长期风险,但增加了团队解释和维护成本。引入它之前,应当能说明每个窗口希望捕捉的用户损害,以及维护者多久能够行动。
实验只自动检查 firing,没有为了等待一分钟窗口完全过期而把恢复状态算作已验证。读者可以增加恢复阶段:停止注入错误,持续提交正常流量,等待规则回到非 firing,并保存查询返回。只有实际执行后,才能把这项写进验证记录。
练习。 将目标从 99% 改为 99.9%,相同 5% 错误比例对应多少倍预算消耗?再解释为什么一条 202 入口 SLO 无法保证异步任务一分钟内完成。
SLO 告警设计可参考 Google SRE Workbook:Alerting on SLOs,查询行为以 Prometheus HTTP API为准。
工具齐全以后,排查仍然可能沿着错误方向前进。本章不新增后台,而是用相同系统、相同接口的四种输入,练习如何提出假设、收集反证并缩小结论范围。
先运行 normal,保存入口 trace ID、消费者事件和完整 span 列表。再运行 redis-slow,唯一关键变化是客户端区间内等待 350 毫秒。比较结果时,先看入口总区间,再查看订单 server、Redis client 和发布区间。若长区间落在 Redis client 范围,只能把排查范围缩小到该调用周围;你仍需知道注入实际发生在命令前,才能准确说出原因。
随后运行 worker-slow,将消费者等待设为 450 毫秒。此时需要先确认入口的完成条件:它返回已接受,不等待消费结果。消费者变慢主要影响异步完成时间,不一定让入口同幅度变慢。若告警只盯入口延迟,这个业务风险可能被遗漏。
两种输入使用不同的故障注入位置,这比在所有请求结束后统一 sleep 更有教学意义。后者会让曲线变慢,却无法检验我们是否识别了具体依赖和完成边界。
broken-context 的业务状态与正常请求相似,但不注入消息属性。先看订单是否处理,再看 worker 日志的 trace ID,最后查询两个独立 trace。若先在入口 trace 里寻找不存在的 worker span,容易把问题误判成“消息没有消费”。
这类场景提醒我们,业务观测与遥测管线要互相核对。业务标记证明某次处理确实发生,独立 trace 证明消费者也被仪表化;两者不共享上下文,说明断点位于传播而非业务投递。
受控失败返回 503,不发送新消息。对该场景,应该看到错误计数增长与对应 ERROR span,而不是等待一个不可能出现的消费事件。告警根据群体错误率触发,trace 则解释某一次失败。查询顺序可以是“告警确定服务和窗口 → 错误指标定位范围 → 事件日志取得具体 trace → trace 检查失败位置”。
不要把某次错误 trace 的存在当作所有错误都被保留。采样比例、导出失败和保留策略都会改变可查询集合,因此统计分母仍应来自合适的指标,而不是 trace 搜索命中数量。
本项目第一轮真实 CI
运行曾出现一个很具体的问题:mqadmin updateTopic
打印连接异常,但退出码为零。原脚本把退出码当作主题可用,过早启动应用,首个发布得到
MQClientException。容器 running 与 CLI
返回零,两项表面检查同时通过,业务仍失败。
修正后的脚本检查主题创建成功文本,并查询 NameServer 实际路由,确认出现 brokerAddrs 后再继续。这一经历不是虚构生产事故,而是本书实验开发中的可复核失败窗口。它说明 readiness 应当验证后续工作依赖的语义条件,不能只验证“命令被调用过”。对应失败和修正运行链接记录在验证附录。
练习。 为“入口变慢、消息完成也变慢”写一份五步排查顺序,至少包含一项可能推翻 Redis 假设的证据。再把主题就绪检查推广到数据库或搜索后台:说明什么样的 API 结果才代表你的业务下一步可以安全开始。
可观测性系统帮助维护业务,也可能成为额外负担。若每次业务请求都同步等待远程日志写入,采集后端故障就会沿着新依赖拖垮业务。完全丢弃错误则又会让维护者在最需要证据时失明。正确设计需要明确两条链路的隔离与边界。
本项目 SDK 使用批量处理器,业务线程主要负责记录,而网络导出在后台进行。这降低了直接耦合,但不能推导出“导出永不影响业务”或“所有信号都会补传”。缓冲、CPU、序列化、内存和后台线程仍是共享资源;压力过大时需要可解释的丢弃、退避或拒绝策略。
Collector 的 memory_limiter 和 batch 也有各自边界。多个位置的缓冲会增加故障窗口内可暂存数据的总量,同时增加恢复时的突发流量。只把队列数字不断调大,可能把短暂拥堵变成恢复后的长时间积压。
因此团队需要分别定义业务可用性、遥测接受率、导出延迟和数据缺失容忍度。审计类事件如果要求可靠保存,应采用与其交付合同匹配的系统,不应仅依赖一个普通 debug 日志管线。
CI 在常规链路验收之后,停止自己创建的 Collector 容器,保持 Redis、RocketMQ、Tempo、Prometheus 和 Java 运行。此时提交新的订单,并检查 HTTP 仍返回 202、消费者确实写入处理标记。证据记录应用响应耗时,但不把一次通过当作所有压力下的隔离证明。
随后重新启动 Collector,等待健康入口,再提交 after-outage 请求,要求它的三个服务重新出现在同一个 Tempo trace 中。这里验证的是恢复后的新数据通路。对于停机窗口中的旧 trace,测试只记录恢复后的查询状态,不强制它必须存在,也不把一个 200 状态解释成所有 span 已完整补回。
这个区分很重要:后台 retry 可能救回部分数据,也可能在上限后放弃。一个旧 trace 只剩部分 span 时,后端仍然可能返回 200。若交付要求无损,需要专门检查完整性与持久化,而不能只检查 endpoint 可达。
Collector 恢复后,应用积压的数据与新流量可能同时导出。应关注接收、拒绝、队列使用、导出失败和后台自身资源,而不是只看健康灯。生产中还需要避免重试把下游持续压在超载状态,明确队列满、磁盘满和后端限流时的行为。
本书的容器是专用 CI 资源,停机脚本不会操作用户已有服务。把同样方法用于共享环境时,必须先确认隔离、恢复入口和影响范围;不应为了演练擅自停止正在为他人服务的 Collector。
练习。 Collector 停机期间业务成功,恢复后旧 trace 查询返回 200。列出至少三项仍未被证明的事情。然后设计一个只针对专用实验环境的完整性检查,说明如何识别缺少的 span,而不是仅检查 trace 是否存在。
处理器与导出队列行为应核对所用版本的 Collector 配置与组件文档。
实验跑通是一个清楚的起点,不是生产方案已经完成的证明。真正交付给团队时,需要把仪表化合同、查询入口、成本边界和故障响应一起保存,使维护者不必依赖最初作者的记忆。
本书真实执行了 HTTP、Redis、RocketMQ 和 OTLP 连接,并从 Tempo、Prometheus 与 Collector 日志取得返回。它验证了特定场景的父子关系、上下文断点、客户端注入等待、异步等待、受控错误、告警状态与采样。读者可以复核代码、镜像摘要和查询 JSON,再决定哪些机制适合迁移到自己的系统。
但三个逻辑服务共用 JVM,不能验证独立进程间的时钟差异、主机失效和网络隔离。Redis 与 Broker 都是单实例,也没有展示生产持久化、身份认证和高可用。没有部署 Grafana、Loki 或 Alertmanager,所以图形探索、日志索引和通知链都需要另外实现和验收。
把这些边界写清楚,可以帮助团队安排真正需要补的工作,避免为了“架构完整”先堆叠一批尚无问题要回答的组件。
服务名、操作名、路由标签和事件名会进入查询与运行手册,修改它们相当于修改一个接口。上线新版本前,应检查旧查询是否仍然可用,标签是否突然增多,采样和脱敏规则是否保持预期。需要更名时,可以制定迁移窗口,而不是在一次重构里无声地让告警失效。
自动仪表化可以补充客户端、框架和运行时信息,但应先检查与现有手工 span 的重复。一个请求出现两层同名区间,并不意味着观测变得更准确。团队应明确哪些 span 是框架边界,哪些是业务决定,哪些指标按什么分母累计。
来源版本也属于合同。官方文档的 latest 页面可能变化,本书记录访问日期、页面指纹、依赖版本和容器摘要。升级时重新运行真实验收,比仅更新版本号并保留旧截图更可靠。
一份好的手册不只是罗列 dashboard。它从“用户等待”“错误比例增加”“异步结果滞后”“trace 断开”等症状出发,给出第一条查询、预期结果、下一步分支和停止条件。明确什么时候应扩大影响判断,什么时候证据不足以继续归因。
每条告警最好连接到相关查询和近期变更,而不是附上几百行原始日志。需要通知到人时,还要测试路由、去重、静默和恢复,而不是以 Prometheus firing 代替完整闭环。本书的短窗口规则是演示,生产阈值应由真实服务目标与响应能力决定。
最后,把完整发布对应到一个提交、一次构建和一份证据包。网页和 EPUB 由同一份正文生成,代码附录与实验源码同源;结构检查能够发现内容漂移,但不会替代事实审阅。真正可维护的结果,是下一位读者能够独立运行、解释失败,并知道哪些结论还没有证据。
结业练习。 为你自己的一个 Java 服务写一页交付说明:定义用户完成条件,画出至少一个异步边界,列出三条查询与一个反例,估计指标维度上限,并说明 Collector 不可用时允许怎样退化。完成一次专用环境实跑后,再把“计划验证”改成带提交和证据的“已经验证”。
需要 JDK 21、Maven、Docker Engine 与 Compose 插件。macOS 的 Java
可能安装在 Homebrew 或单独 JDK 目录,应先实际运行
java -version 与 mvn -version,确认 Maven
使用的 Java 与预期一致。不能因为 /usr/bin/java
文件存在,就假定运行时可用。
java -version
mvn -version
docker version
docker compose version
mvn -f lab/pom.xml --batch-mode --no-transfer-progress package
bash lab/run_ci.sh脚本是一次完整验收,退出时会关闭它创建的栈。若想手工查询,先独立执行
docker compose -f lab/compose.yaml up -d,按照 run_ci.sh
的就绪步骤创建并查询主题,再运行 jar。手工运行后,由操作者确认工作目录与
project,再清理同一实验栈。不要把示例中的 down -v
换成针对已有共享服务的清理命令。
| 接口 | 含义 | 不代表什么 |
|---|---|---|
| POST /orders | 写入订单、发布消息,正常返回 202 | 消费者已经完成 |
| GET /orders/{id} | 通过真实 Redis 查询订单是否存在 | 与创建请求共享同一 trace |
| GET /health | Java 应用已完成启动 | 遥测后端已有本次 trace |
| GET /lab/events | 最近合成事件,供验收比对 | 持久日志或审计数据库 |
| GET /lab/flush | 缩短 SDK 导出等待 | 下游一定完整保存所有信号 |
POST 正文字段为 id、redis_delay_ms、worker_delay_ms、propagate、fail。id 限制为 1—40 位小写字母、数字、连字符;延迟限制为 0—1500 毫秒。所有参数仅用于独立实验,不应直接暴露为真实服务的故障接口。
Tempo 使用
http://127.0.0.1:3200/api/traces/<id>。Prometheus
使用
http://127.0.0.1:9095/api/v1/query、/api/v1/alerts
与 /api/v1/query_exemplars。Collector 健康入口为
13133,Prometheus exporter 为 8889,宿主 Java 向 4318 导出
OTLP。RocketMQ NameServer 为 9876,Broker 经典客户端为 10911。
PromQL 作为 URL 参数时应编码,避免 {}、引号或加号被
shell 与 HTTP 客户端改变。检查器使用标准 URL 编码;手工查询可以使用 curl
的 --get --data-urlencode 'query=...'。
先看 commit.txt、java-version.txt、images.txt,确定执行基线。再看
results.json,取得各场景 trace ID
与检查结论。trace-normal.json 等文件保留 Tempo
原始数据;events.json、application.log、collector.log
用于日志关联;metrics-requests.json、metrics-p95.json、exemplars.json 与
alerts.json 是实际后端返回。
sampling-zero.json 保存未采样时的消费者事件、指标和 404;collector-outage.json 与 collector-recovered.json 区分业务可用性、恢复后的新 trace 和旧 trace 的查询结果。任何一个文件缺失,都不能用另一个阶段的成功代替它。
完整管线发布时,下载区会附带证据 ZIP、validation.json 与 EPUBCheck 日志。机器可读验证记录中的 EPUB SHA-256 对应本次构建,避免校验日志与下载文件错配。
第 1 章可以提出“入口只表示已接受,异步消费尚未完成”与“消费已完成,但统计读模型尚未更新”两个竞争假设。先检查实际业务完成标记,再检查消息处理事件或下游读模型。若完成标记存在而界面未更新,就不应继续把原因固定为消息没有消费。
第 2 章中,Collector 接口可连与 up=1 仍不能证明 Java SDK 发出了 trace,也不能证明 traces pipeline 引用了正确 exporter。需要提交实际请求取得 ID,再查询 Tempo。若只抓取到了 Collector 自身或空的业务序列,Prometheus 可用也无法替代业务数据验证。
第 3 章中,父 span 结束之后子工作仍可继续,时间重叠不是父子关系的唯一条件。长期消息任务或多输入聚合可以考虑 link。关键是描述因果来源,并让模型与所用消息框架的语义保持一致。
第 4 章的错误顺序是先注入当前入口上下文,再创建 HTTP client span。此时远端继承的是入口 span ID。业务 JSON 与 HTTP 调用本身可以完全正确,所以普通功能测试不会发现该仪表化缺陷。
第 5 章的等待可能来自连接池、应用调度、网络往返和 Redis 执行。服务端命令统计或慢日志有助于区分服务执行时间,连接池等待指标或线程证据有助于定位本地争用。命令前的 Thread.sleep 被包在 client span 内,所以它不是 Redis 服务端延迟。
第 6 章的多来源工作可以在新 span 上添加十个来源上下文的 link,而不是把十个 ID 拼成一个非法或无语义的新身份。新的 span 仍有自己的 trace/span ID,link 保存来源关系。批量结果和重试次数也应作为另外的信息记录。
第 7 章的日志 span ID 不在后端,可能是 span 尚未结束或尚未导出,可能是未采样或已过期,也可能是在错误 Scope 中读取身份。需要把 sampled 标志、查询窗口、导出状态和日志发生位置一起检查。
第 8 章总错误数是 10 加 5,即 15;总请求数 1010,所以错误比例约 1.485%,并非 25.5%。高流量实例应该获得与其请求量相符的权重。trace ID 若作为普通标签,会把序列数量推向请求数量级;exemplar 则只保存受限的关联样本。
第 9 章可以依次检查 SDK metric reader、OTLP receiver、metrics pipeline 引用、Prometheus exporter、抓取目标与查询标签。使用错误的 service_name 或仅查看过窄窗口,也可能让存在的数据看起来像丢失。
第 10 章不能把 500、450 和 800 相加。订单 server 很可能位于网关等待范围内,消费者也可能跨过 HTTP 返回继续工作。需要开始、结束时间与依赖关系,才能确定用户关键路径。
第 11 章头部 1% 采样在知道结果前作出决定,不能保证后来出错的请求完整保留。尾采样需要保存待决数据,并使同一 trace 的相关 span 到达能够共同决策的位置;容量与路由都要验证。
第 12 章可以选择 route、outcome、service 三类有限维度,按已部署服务与路由数量估计上限。具体订单调查由 trace/log 的受控字段完成,指标到 trace 的跳转可以使用 exemplar。估计后还要查询实际序列,检查资源自动转换是否带入新维度。
第 13 章目标为 99.9% 时,允许错误比例是 0.1%,5% 错误对应 burn rate 50。入口接受成功没有覆盖排队与消费完成,因此不能保证异步一分钟目标。异步 SLI 应有自己的起点、终点、失败和超时定义。
第 14 章可先明确用户等待的是响应还是处理完成,再比较入口与服务 span,随后检查 Redis、消息发布与消费者范围。如果 Redis 区间很短而未覆盖时间很长,就应放弃单纯扩大 Redis 的假设。主题就绪的语义检查可以推广到“实际查询到索引”“实际通过数据库探针读写”等条件。
第 15 章中,旧 trace 返回 200 并未证明 span 全部存在、没有重复或所有故障请求均可查询。可以预先记录期望操作与身份,再逐一检查父子关系、结束状态和完整集合;仍需注意采样策略对可期待集合的影响。
可以选择补充告警恢复、给异步完成定义 SLI、接入日志查询后台或拆成独立 JVM。一次只增加一个主要变量,先写清预期和反例,再修改代码与验收。真实执行后记录提交、环境与原始查询,不要直接沿用本书旧报告为新功能背书。
| 组件 | 固定版本 | 用途 |
|---|---|---|
| Java | 21 | HTTP 服务、客户端与应用运行 |
| OpenTelemetry Java SDK | 1.55.0 | 实际 traces、metrics、logs 与 OTLP HTTP 导出 |
| Jedis | 5.2.0 | Redis 命令 |
| RocketMQ 客户端 / Broker | 5.3.2 | 经典 Remoting 消息链路 |
| Redis | 7.2.5-alpine | 专用订单键与处理标记 |
| Collector Contrib | 0.111.0 | OTLP 接收与三信号管线 |
| Tempo | 2.6.1 | 真实 trace 存储与 HTTP 查询 |
| Prometheus | 2.55.1 | 指标、exemplar 与规则状态 |
镜像标签与 registry manifest 摘要保存在仓库
book/image-lock.json,Compose
使用摘要约束实际镜像。这是已获取并用于本书实验的版本组合,不是对当前最新版本、安全状态或生产兼容性的推荐。源码依赖由
Maven 固定版本,下载与编译也属于 CI 的真实检查。
以下资料于 2026-10-21 获取。页面可能继续更新,仓库 sources.json 保存获取状态、长度与 SHA-256;书中的配置和验证范围以固定代码与实际运行返回为准。正文是原创教学解释,没有把外部文档逐页转载成书。
70c8aea0080b8bac8f493c2820e41f944d5da36678cc69c90e1024fef1ddbf58。6f93c34180bb37708bac35a7368e64dcc76210359072f0525513fff9728c5f6b。17f2f71cb64b97948672e2ba70ba49c6ea18278c18494c6bb1b7163af5137003。8026b95400ea1418e3be8e5471fcd563b38437b29a14e54f535db268aa141abe。cd3dee4480931bbf8feb034f480a2955bca6429b73ac81ea8f02f673a2758c43。df4d3d794a0b84120096ec68d8eec8d343e6bd79fabe1acf59d69bab32484cb3。b30721e77facc94ed235e0e6c8df3938fd0cba25604065903ee0ba333b5388db。91509d39ac6c48c8cc540b1c75d0f5928b961dba2a763704174bb10d77659ce6。7e621dd391b4d282ee0480c2eea2f520963ed77fba94fe802817bb6b1b8f1043。d793eae37b76c193d6d89479fe73cfa42eca407ba42cc2471aca12c10c08931b。9e7228d2a91c5aa4bef6e7f610366a2000274ee51699053e10c8ac3f0b8965be。340f148f65a7a92596c65f0a44828cbc1bcf165291cccf2c33a2b57673dd30b3。87edfb89793d20f2dee29f0b4e048479f13078d0ba73d7e9d68174a5c92d08bd。5d87d113d13ef2abcb30d82df727acb1279ec804d26ea0d295041b6deb17a4cc。2b3b44e6d9be5be7ee981bfb01df24035008da697aa6eea24b2c9bdd5ed6ec86。50a5347b8f30bea3aad9d0b4bd0ad0190028e9084fc69cd1996b8ff963d5dec7。最早通过的真实链路基线为 Actions
39570406550,对应提交
e831a81bd33d728a173a8ff1924d9ef853cd6526。该次正常场景取得七个
span,客户端注入等待观察值约 351 毫秒,消费者等待约 451
毫秒,累计入口请求 16 次,告警为 firing,采样零阶段 Tempo 返回
404。这些是该次 CI 的实际结果,不是跨环境性能基准。
增强实测 Actions 39573012520 已通过 exemplar 与 Collector 停机恢复验收;当前发布对应的提交、运行地址、EPUB 哈希、场景结果和原始证据包以下载区验证记录为准。发布管线要求集成证据提交与出版提交一致,避免拿旧实验为新实现背书。
第一轮未通过的真实运行 39569432908保留了 mqadmin 退出码误判的问题。它没有被当成成功证据,修正与新的验收分别保留在提交历史中。
已执行的检查围绕合成订单、专用 Redis 键、单节点 RocketMQ 和一个 JVM 中的三个逻辑服务。没有声称测试生产高可用、真实客户数据、独立主机网络、尾部采样、Loki 查询或通知发送。告警恢复与更长统计窗口作为后续练习,不能从短实验自动推导出月度 SLO。
原创正文、封面和图示采用 CC BY 4.0,署名 Aias00;原创代码采用 MIT。OpenTelemetry、Redis、Apache RocketMQ、Grafana Tempo、Prometheus 及其文档保留各自原许可与权利。本书为独立教学资料,不代表这些项目审核、背书或官方出版。仓库 LICENSE 与 LICENSE-CODE 给出具体授权范围。
以下文件在构建时从随书实验与测试目录读取,与下载区实验包同源。它们是本书教学实现;实际验证范围以实验章节和验证记录为准。
name: observability-book
services:
redis:
image: library/redis:7.2.5-alpine@sha256:6aaf3f5e6bc8a592fbfe2cccf19eb36d27c39d12dab4f4b01556b7449e7b1f44
ports: ["127.0.0.1:6379:6379"]
namesrv:
image: apache/rocketmq:5.3.2@sha256:4a80ff5cd4b0a3d3ef6dc338ce2028a85bd995648cb3aa5c3e753746d2dbc587
command: ["sh", "mqnamesrv"]
environment:
JAVA_OPT_EXT: "-Xms128m -Xmx128m -Xmn64m"
ports: ["127.0.0.1:9876:9876"]
broker:
image: apache/rocketmq:5.3.2@sha256:4a80ff5cd4b0a3d3ef6dc338ce2028a85bd995648cb3aa5c3e753746d2dbc587
command: ["sh", "mqbroker", "-n", "namesrv:9876", "-c", "/home/rocketmq/rocketmq-5.3.2/conf/broker.conf"]
environment:
JAVA_OPT_EXT: "-Xms256m -Xmx256m -Xmn128m"
volumes: ["./config/broker.conf:/home/rocketmq/rocketmq-5.3.2/conf/broker.conf:ro"]
ports: ["127.0.0.1:10911:10911", "127.0.0.1:10909:10909"]
depends_on: [namesrv]
tempo:
image: grafana/tempo:2.6.1@sha256:ef4384fce6e8ad22b95b243d8fc165628cda655376fd50e7850536ad89d71d50
command: ["-config.file=/etc/tempo.yaml"]
volumes: ["./config/tempo.yaml:/etc/tempo.yaml:ro"]
ports: ["127.0.0.1:3200:3200"]
collector:
image: otel/opentelemetry-collector-contrib:0.111.0@sha256:a2a52e43c1a80aa94120ad78c2db68780eb90e6d11c8db5b3ce2f6a0cc6b5029
command: ["--config=/etc/collector.yaml"]
volumes: ["./config/collector.yaml:/etc/collector.yaml:ro"]
ports: ["127.0.0.1:4318:4318", "127.0.0.1:8889:8889", "127.0.0.1:13133:13133"]
depends_on: [tempo]
prometheus:
image: prom/prometheus:v2.55.1@sha256:2659f4c2ebb718e7695cb9b25ffa7d6be64db013daba13e05c875451cf51b0d3
command: ["--config.file=/etc/prometheus/prometheus.yaml", "--storage.tsdb.path=/prometheus", "--enable-feature=exemplar-storage"]
volumes: ["./config/prometheus.yaml:/etc/prometheus/prometheus.yaml:ro", "./config/alerts.yaml:/etc/prometheus/alerts.yaml:ro"]
ports: ["127.0.0.1:9095:9090"]
depends_on: [collector]groups:
- name: book-slo
rules:
- alert: BookFastBurn
expr: (sum(rate(lab_requests_total{service_name="book-gateway",outcome="error"}[1m])) / sum(rate(lab_requests_total{service_name="book-gateway"}[1m])) > 0.05) and (sum(increase(lab_requests_total{service_name="book-gateway"}[1m])) >= 5)
for: 2s
labels:
severity: exercise
annotations:
summary: "实验请求错误率超过5%,为99%可用性目标的5倍预算消耗率"brokerClusterName=BookCluster
brokerName=book-broker
brokerId=0
brokerIP1=127.0.0.1
autoCreateTopicEnable=true
flushDiskType=SYNC_FLUSH
brokerRole=ASYNC_MASTER
receivers:
otlp:
protocols:
http:
endpoint: 0.0.0.0:4318
processors:
memory_limiter:
check_interval: 1s
limit_mib: 200
spike_limit_mib: 50
batch:
timeout: 1s
send_batch_size: 128
exporters:
otlp/tempo:
endpoint: tempo:4317
tls:
insecure: true
prometheus:
enable_open_metrics: true
endpoint: 0.0.0.0:8889
resource_to_telemetry_conversion:
enabled: true
debug:
verbosity: detailed
extensions:
health_check:
endpoint: 0.0.0.0:13133
service:
extensions: [health_check]
pipelines:
traces:
receivers: [otlp]
processors: [memory_limiter, batch]
exporters: [otlp/tempo]
metrics:
receivers: [otlp]
processors: [memory_limiter, batch]
exporters: [prometheus]
logs:
receivers: [otlp]
processors: [memory_limiter, batch]
exporters: [debug]global:
scrape_interval: 1s
evaluation_interval: 1s
rule_files: ["/etc/prometheus/alerts.yaml"]
scrape_configs:
- job_name: book-collector
static_configs:
- targets: ["collector:8889"]server:
http_listen_port: 3200
distributor:
receivers:
otlp:
protocols:
grpc:
endpoint: 0.0.0.0:4317
http:
endpoint: 0.0.0.0:4318
ingester:
trace_idle_period: 2s
max_block_duration: 1m
compactor:
compaction:
block_retention: 1h
storage:
trace:
backend: local
wal:
path: /tmp/tempo/wal
local:
path: /tmp/tempo/blocks<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 https://maven.apache.org/xsd/maven-4.0.0.xsd">
<modelVersion>4.0.0</modelVersion><groupId>book.observability</groupId><artifactId>observability-lab</artifactId><version>1.0.0</version>
<properties><maven.compiler.release>21</maven.compiler.release><project.build.sourceEncoding>UTF-8</project.build.sourceEncoding><otel.version>1.55.0</otel.version></properties>
<dependencies>
<dependency><groupId>io.opentelemetry</groupId><artifactId>opentelemetry-sdk</artifactId><version>${otel.version}</version></dependency>
<dependency><groupId>io.opentelemetry</groupId><artifactId>opentelemetry-exporter-otlp</artifactId><version>${otel.version}</version></dependency>
<dependency><groupId>redis.clients</groupId><artifactId>jedis</artifactId><version>5.2.0</version></dependency>
<dependency><groupId>org.apache.rocketmq</groupId><artifactId>rocketmq-client</artifactId><version>5.3.2</version></dependency>
<dependency><groupId>com.fasterxml.jackson.core</groupId><artifactId>jackson-databind</artifactId><version>2.17.2</version></dependency>
<dependency><groupId>org.slf4j</groupId><artifactId>slf4j-simple</artifactId><version>2.0.16</version></dependency>
</dependencies>
<build><finalName>observability-lab</finalName><plugins>
<plugin><groupId>org.apache.maven.plugins</groupId><artifactId>maven-compiler-plugin</artifactId><version>3.13.0</version></plugin>
<plugin><groupId>org.apache.maven.plugins</groupId><artifactId>maven-shade-plugin</artifactId><version>3.6.0</version><executions><execution><phase>package</phase><goals><goal>shade</goal></goals><configuration><createDependencyReducedPom>false</createDependencyReducedPom><filters><filter><artifact>*:*</artifact><excludes><exclude>META-INF/*.SF</exclude><exclude>META-INF/*.DSA</exclude><exclude>META-INF/*.RSA</exclude></excludes></filter></filters><transformers><transformer implementation="org.apache.maven.plugins.shade.resource.ServicesResourceTransformer"/><transformer implementation="org.apache.maven.plugins.shade.resource.ManifestResourceTransformer"><mainClass>book.SystemLab</mainClass></transformer></transformers></configuration></execution></executions></plugin>
</plugins></build>
</project>#!/usr/bin/env bash
set -euo pipefail
cd "$(dirname "$0")/.."
mkdir -p evidence
compose=(docker compose -f lab/compose.yaml)
app_pid=
cleanup() {
if [[ -n "$app_pid" ]]; then kill "$app_pid" 2>/dev/null || true; wait "$app_pid" 2>/dev/null || true; fi
"${compose[@]}" logs --no-color > evidence/containers.log 2>&1 || true
"${compose[@]}" ps -a > evidence/containers-status.txt || true
"${compose[@]}" down -v --remove-orphans || true
}
trap cleanup EXIT
git rev-parse HEAD > evidence/commit.txt
java -version 2> evidence/java-version.txt
"${compose[@]}" config --images > evidence/images.txt
"${compose[@]}" up -d
topic_ready=0
for ((attempt=0;attempt<90;attempt++)); do
"${compose[@]}" exec -T broker sh -c 'sh /home/rocketmq/rocketmq-5.3.2/bin/mqadmin updateTopic -n namesrv:9876 -b 127.0.0.1:10911 -t otel-book-orders' > evidence/topic.txt 2>&1 || true
if grep -qi 'create topic.*success' evidence/topic.txt; then
"${compose[@]}" exec -T broker sh -c 'sh /home/rocketmq/rocketmq-5.3.2/bin/mqadmin topicRoute -n namesrv:9876 -t otel-book-orders' > evidence/topic-route.json 2>&1 || true
if grep -q 'brokerAddrs' evidence/topic-route.json; then topic_ready=1; break; fi
fi
sleep 2
done
[[ "$topic_ready" == 1 ]] || { cat evidence/topic.txt; exit 1; }
"${compose[@]}" exec -T redis redis-cli PING > evidence/redis-ping.txt
java -jar lab/target/observability-lab.jar > evidence/application.log 2>&1 &
app_pid=$!
python3 tests/verify_system.py --phase full
"${compose[@]}" logs --no-color collector > evidence/collector.log
python3 - <<'PY'
import json
from pathlib import Path
results=json.loads(Path('evidence/results.json').read_text())
trace=results['checks']['normal']['response']['trace_id']
logs=Path('evidence/collector.log').read_text().lower()
assert trace.lower() in logs, 'Collector did not receive trace-correlated OTLP logs'
print('PASS actual OTLP logs contain the same trace id as Tempo spans')
PY
"${compose[@]}" stop collector
python3 tests/verify_system.py --phase collector-outage
"${compose[@]}" start collector
python3 tests/verify_system.py --phase recovered
kill "$app_pid"
wait "$app_pid" || true
app_pid=
SAMPLER_RATIO=0 java -jar lab/target/observability-lab.jar > evidence/application-sampling-zero.log 2>&1 &
app_pid=$!
python3 tests/verify_system.py --phase sampled-out
"${compose[@]}" exec -T redis redis-cli --scan --pattern 'otelbook:*' > evidence/redis-keys.txtpackage book;
import com.fasterxml.jackson.databind.JsonNode;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.sun.net.httpserver.HttpExchange;
import com.sun.net.httpserver.HttpServer;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.logs.Severity;
import io.opentelemetry.api.trace.Span;
import io.opentelemetry.api.trace.SpanKind;
import io.opentelemetry.api.trace.StatusCode;
import io.opentelemetry.context.Context;
import io.opentelemetry.context.Scope;
import io.opentelemetry.context.propagation.TextMapGetter;
import org.apache.rocketmq.client.consumer.DefaultMQPushConsumer;
import org.apache.rocketmq.client.consumer.listener.MessageListenerConcurrently;
import org.apache.rocketmq.client.consumer.listener.ConsumeConcurrentlyStatus;
import org.apache.rocketmq.common.consumer.ConsumeFromWhere;
import org.apache.rocketmq.client.producer.DefaultMQProducer;
import org.apache.rocketmq.common.message.Message;
import org.apache.rocketmq.common.message.MessageExt;
import redis.clients.jedis.JedisPooled;
import java.net.InetSocketAddress;
import java.net.URI;
import java.net.http.HttpClient;
import java.net.http.HttpRequest;
import java.net.http.HttpResponse;
import java.nio.charset.StandardCharsets;
import java.time.Instant;
import java.time.Duration;
import java.util.Map;
import java.util.List;
import java.util.LinkedHashMap;
import java.util.concurrent.ConcurrentLinkedDeque;
import java.util.concurrent.Executors;
/** A deliberately small real HTTP -> Redis -> RocketMQ -> Redis system. */
public final class SystemLab {
static final ObjectMapper JSON = new ObjectMapper();
static final Telemetry GATEWAY = new Telemetry("book-gateway");
static final Telemetry ORDERS = new Telemetry("book-orders");
static final Telemetry WORKER = new Telemetry("book-worker");
static final JedisPooled REDIS = new JedisPooled(System.getenv().getOrDefault("REDIS_HOST", "127.0.0.1"), 6379);
static final DefaultMQProducer PRODUCER = new DefaultMQProducer("otel-book-producer");
static final DefaultMQPushConsumer CONSUMER = new DefaultMQPushConsumer("otel-book-worker");
static final HttpClient HTTP = HttpClient.newBuilder().connectTimeout(Duration.ofSeconds(3)).build();
static final ConcurrentLinkedDeque<Map<String,Object>> EVENTS = new ConcurrentLinkedDeque<>();
static final String TOPIC = "otel-book-orders";
static final TextMapGetter<HttpExchange> HTTP_GETTER = new TextMapGetter<>() {
public Iterable<String> keys(HttpExchange exchange) { return exchange.getRequestHeaders().keySet(); }
public String get(HttpExchange exchange, String key) { return exchange.getRequestHeaders().getFirst(key); }
};
static final TextMapGetter<MessageExt> MQ_GETTER = new TextMapGetter<>() {
public Iterable<String> keys(MessageExt message) { return message.getProperties().keySet(); }
public String get(MessageExt message, String key) { return message.getProperty(key); }
};
static byte[] bytes(Object value) throws Exception { return JSON.writeValueAsBytes(value); }
static void respond(HttpExchange exchange, int status, Object body) throws Exception {
byte[] raw = bytes(body);
exchange.getResponseHeaders().set("Content-Type", "application/json; charset=utf-8");
exchange.getResponseHeaders().set("X-Trace-Id", Span.current().getSpanContext().getTraceId());
exchange.sendResponseHeaders(status, raw.length);
exchange.getResponseBody().write(raw);
}
static void event(Telemetry telemetry, String name, String id) {
Map<String,Object> row = new LinkedHashMap<>();
row.put("timestamp", Instant.now().toString());row.put("service",telemetry.service);row.put("event",name);
row.put("order_id",id);row.put("trace_id",Span.current().getSpanContext().getTraceId());
row.put("span_id",Span.current().getSpanContext().getSpanId());row.put("sampled",Span.current().getSpanContext().isSampled());
EVENTS.add(row);while(EVENTS.size()>300)EVENTS.pollFirst();
try { System.out.println(JSON.writeValueAsString(row)); } catch(Exception error) { throw new RuntimeException(error); }
telemetry.logger.logRecordBuilder().setContext(Context.current()).setSeverity(Severity.INFO)
.setBody(name).setAttribute("order.id",id).emit();
}
static int delay(JsonNode body, String name) {
int value=body.path(name).asInt(0);
if(value<0||value>1500)throw new IllegalArgumentException("Delay outside 0..1500 ms");
return value;
}
static void consume(MessageExt message) throws Exception {
Context parent = WORKER.sdk.getPropagators().getTextMapPropagator().extract(Context.root(),message,MQ_GETTER);
Span span = WORKER.tracer.spanBuilder("rocketmq process " + TOPIC).setSpanKind(SpanKind.CONSUMER)
.setParent(parent).setAttribute("messaging.system","rocketmq").setAttribute("messaging.destination.name",TOPIC).startSpan();
long start=System.nanoTime();
try(Scope scope=span.makeCurrent()) {
JsonNode body=JSON.readTree(message.getBody());String id=body.path("id").asText();
span.setAttribute("order.id",id);Thread.sleep(body.path("worker_delay_ms").asInt());
Span redis=WORKER.tracer.spanBuilder("redis SET processed").setSpanKind(SpanKind.CLIENT).startSpan();
try(Scope ignored=redis.makeCurrent()) {REDIS.setex("otelbook:processed:"+id,3600,JSON.writeValueAsString(Map.of("id",id,"trace_id",span.getSpanContext().getTraceId())));}
finally {redis.end();}
event(WORKER,"worker.processed",id);
WORKER.requests.add(1,Attributes.builder().put("route","message").put("outcome","ok").build());
} catch(Exception error) {span.recordException(error);span.setStatus(StatusCode.ERROR);throw error;}
finally {WORKER.duration.record((System.nanoTime()-start)/1e9,Attributes.of(io.opentelemetry.api.common.AttributeKey.stringKey("route"),"message"),Context.root().with(span));span.end();}
}
static void order(HttpExchange exchange) {
Context parent=ORDERS.sdk.getPropagators().getTextMapPropagator().extract(Context.root(),exchange,HTTP_GETTER);
Span span=ORDERS.tracer.spanBuilder("orders " + exchange.getRequestMethod() + " /orders").setParent(parent)
.setSpanKind(SpanKind.SERVER).setAttribute("http.route","/orders").startSpan();
long start=System.nanoTime();String outcome="ok";
try(Scope scope=span.makeCurrent()) {
if(exchange.getRequestMethod().equals("GET")) {
String id=exchange.getRequestURI().getPath().replaceFirst("^/orders/","");
Span redis=ORDERS.tracer.spanBuilder("redis GET order").setSpanKind(SpanKind.CLIENT).startSpan();
String value;try(Scope ignored=redis.makeCurrent()){value=REDIS.get("otelbook:order:"+id);}finally{redis.end();}
respond(exchange,value==null?404:200,Map.of("order_id",id,"found",value!=null));return;
}
JsonNode body=JSON.readTree(exchange.getRequestBody());String id=body.path("id").asText();
if(!id.matches("[a-z0-9-]{1,40}"))throw new IllegalArgumentException("Use a short lowercase id");
int redisDelay=delay(body,"redis_delay_ms"),workerDelay=delay(body,"worker_delay_ms");span.setAttribute("order.id",id);
if(body.path("fail").asBoolean(false)) {outcome="error";span.setStatus(StatusCode.ERROR,"injected application failure");event(ORDERS,"order.failed",id);respond(exchange,503,Map.of("error","injected-application-error","trace_id",span.getSpanContext().getTraceId()));return;}
Span redis=ORDERS.tracer.spanBuilder("redis SET order").setSpanKind(SpanKind.CLIENT)
.setAttribute("db.system","redis").setAttribute("fault.injected_delay_ms",redisDelay).startSpan();
try(Scope ignored=redis.makeCurrent()){Thread.sleep(redisDelay);REDIS.setex("otelbook:order:"+id,3600,body.toString());}finally{redis.end();}
Span producer=ORDERS.tracer.spanBuilder("rocketmq publish " + TOPIC).setSpanKind(SpanKind.PRODUCER)
.setAttribute("messaging.system","rocketmq").setAttribute("messaging.destination.name",TOPIC).startSpan();
try(Scope ignored=producer.makeCurrent()) {
Message message=new Message(TOPIC,"created",id,bytes(Map.of("id",id,"worker_delay_ms",workerDelay)));
if(body.path("propagate").asBoolean(true)) ORDERS.sdk.getPropagators().getTextMapPropagator()
.inject(Context.current(),message,(carrier,key,value)->carrier.putUserProperty(key,value));
PRODUCER.send(message);
} finally {producer.end();}
event(ORDERS,"order.queued",id);respond(exchange,202,Map.of("order_id",id,"state","queued","trace_id",span.getSpanContext().getTraceId()));
} catch(Exception error) {error.printStackTrace();outcome="error";span.recordException(error);span.setStatus(StatusCode.ERROR);try{respond(exchange,500,Map.of("error",error.getClass().getSimpleName()));}catch(Exception ignored){}}
finally {ORDERS.requests.add(1,Attributes.builder().put("route","/orders").put("outcome",outcome).build());ORDERS.duration.record((System.nanoTime()-start)/1e9,Attributes.of(io.opentelemetry.api.common.AttributeKey.stringKey("route"),"/orders"),Context.root().with(span));span.end();exchange.close();}
}
static void gateway(HttpExchange exchange) {
try {
if(exchange.getRequestURI().getPath().equals("/health")){respond(exchange,200,Map.of("status","ready"));exchange.close();return;}
if(exchange.getRequestURI().getPath().equals("/lab/events")){respond(exchange,200,List.copyOf(EVENTS));exchange.close();return;}
if(exchange.getRequestURI().getPath().equals("/lab/flush")){GATEWAY.flush();ORDERS.flush();WORKER.flush();respond(exchange,200,Map.of("flushed",true));exchange.close();return;}
} catch(Exception error){exchange.close();return;}
Context parent=GATEWAY.sdk.getPropagators().getTextMapPropagator().extract(Context.root(),exchange,HTTP_GETTER);
Span span=GATEWAY.tracer.spanBuilder("gateway " + exchange.getRequestMethod() + " /orders").setSpanKind(SpanKind.SERVER)
.setParent(parent).setAttribute("http.route","/orders").startSpan();long start=System.nanoTime();String outcome="ok";
try(Scope scope=span.makeCurrent()) {
Span client=GATEWAY.tracer.spanBuilder("gateway -> orders").setSpanKind(SpanKind.CLIENT).startSpan();
HttpResponse<String> response;
try(Scope ignored=client.makeCurrent()) {
byte[] body=exchange.getRequestBody().readAllBytes();
HttpRequest.Builder request=HttpRequest.newBuilder(URI.create("http://127.0.0.1:8081"+exchange.getRequestURI()))
.timeout(Duration.ofSeconds(5)).header("Content-Type","application/json")
.method(exchange.getRequestMethod(),HttpRequest.BodyPublishers.ofByteArray(body));
GATEWAY.sdk.getPropagators().getTextMapPropagator().inject(Context.current(),request,(carrier,key,value)->carrier.header(key,value));
response=HTTP.send(request.build(),HttpResponse.BodyHandlers.ofString());
if(response.statusCode()>=500)client.setStatus(StatusCode.ERROR);
} finally {client.end();}
if(response.statusCode()>=500){span.setStatus(StatusCode.ERROR);outcome="error";}
JsonNode json=JSON.readTree(response.body());event(GATEWAY,"gateway.request",json.path("order_id").asText("unknown"));respond(exchange,response.statusCode(),json);
} catch(Exception error){span.recordException(error);span.setStatus(StatusCode.ERROR);outcome="error";try{respond(exchange,502,Map.of("error",error.getClass().getSimpleName()));}catch(Exception ignored){}}
finally {GATEWAY.requests.add(1,Attributes.builder().put("route","/orders").put("outcome",outcome).build());GATEWAY.duration.record((System.nanoTime()-start)/1e9,Attributes.of(io.opentelemetry.api.common.AttributeKey.stringKey("route"),"/orders"),Context.root().with(span));span.end();exchange.close();}
}
public static void main(String[] args) throws Exception {
String namesrv=System.getenv().getOrDefault("NAMESRV_ADDR","127.0.0.1:9876");REDIS.ping();
PRODUCER.setNamesrvAddr(namesrv);PRODUCER.setSendMsgTimeout(10000);PRODUCER.start();
CONSUMER.setNamesrvAddr(namesrv);CONSUMER.setConsumeFromWhere(ConsumeFromWhere.CONSUME_FROM_FIRST_OFFSET);
CONSUMER.setConsumeThreadMin(1);CONSUMER.setConsumeThreadMax(1);CONSUMER.subscribe(TOPIC,"*");
CONSUMER.registerMessageListener((MessageListenerConcurrently)(messages,context)->{
try {for(MessageExt message:messages)consume(message);return ConsumeConcurrentlyStatus.CONSUME_SUCCESS;}
catch(Exception error){error.printStackTrace();return ConsumeConcurrentlyStatus.RECONSUME_LATER;}
});CONSUMER.start();
HttpServer orders=HttpServer.create(new InetSocketAddress("127.0.0.1",8081),0);orders.createContext("/orders",SystemLab::order);orders.setExecutor(Executors.newVirtualThreadPerTaskExecutor());orders.start();
HttpServer gateway=HttpServer.create(new InetSocketAddress("127.0.0.1",8080),0);gateway.createContext("/",SystemLab::gateway);gateway.setExecutor(Executors.newVirtualThreadPerTaskExecutor());gateway.start();
Runtime.getRuntime().addShutdownHook(new Thread(()->{gateway.stop(0);orders.stop(0);CONSUMER.shutdown();PRODUCER.shutdown();GATEWAY.close();ORDERS.close();WORKER.close();REDIS.close();}));
System.out.println("READY http://127.0.0.1:8080");
}
}package book;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.logs.Logger;
import io.opentelemetry.api.metrics.DoubleHistogram;
import io.opentelemetry.api.metrics.LongCounter;
import io.opentelemetry.api.trace.Tracer;
import io.opentelemetry.context.propagation.ContextPropagators;
import io.opentelemetry.api.trace.propagation.W3CTraceContextPropagator;
import io.opentelemetry.exporter.otlp.http.trace.OtlpHttpSpanExporter;
import io.opentelemetry.exporter.otlp.http.metrics.OtlpHttpMetricExporter;
import io.opentelemetry.exporter.otlp.http.logs.OtlpHttpLogRecordExporter;
import io.opentelemetry.sdk.OpenTelemetrySdk;
import io.opentelemetry.sdk.resources.Resource;
import io.opentelemetry.sdk.trace.SdkTracerProvider;
import io.opentelemetry.sdk.trace.export.BatchSpanProcessor;
import io.opentelemetry.sdk.trace.samplers.Sampler;
import io.opentelemetry.sdk.metrics.SdkMeterProvider;
import io.opentelemetry.sdk.metrics.InstrumentSelector;
import io.opentelemetry.sdk.metrics.View;
import io.opentelemetry.sdk.metrics.Aggregation;
import io.opentelemetry.sdk.metrics.export.PeriodicMetricReader;
import io.opentelemetry.sdk.logs.SdkLoggerProvider;
import io.opentelemetry.sdk.logs.export.BatchLogRecordProcessor;
import java.time.Duration;
import java.util.List;
import java.util.concurrent.TimeUnit;
/** Three real OTLP signals; no in-memory tracing substitute. */
public final class Telemetry implements AutoCloseable {
public final String service;
public final OpenTelemetrySdk sdk;
public final Tracer tracer;
public final Logger logger;
public final LongCounter requests;
public final DoubleHistogram duration;
public Telemetry(String service) {
this.service = service;
String endpoint = System.getenv().getOrDefault("COLLECTOR_URL", "http://127.0.0.1:4318");
Resource resource = Resource.create(Attributes.builder().put("service.name", service)
.put("service.version", "1.0.0").put("deployment.environment.name", "book-lab").build());
double ratio = Double.parseDouble(System.getenv().getOrDefault("SAMPLER_RATIO", "1.0"));
SdkTracerProvider traces = SdkTracerProvider.builder().setResource(resource)
.setSampler(Sampler.parentBased(Sampler.traceIdRatioBased(ratio)))
.addSpanProcessor(BatchSpanProcessor.builder(OtlpHttpSpanExporter.builder()
.setEndpoint(endpoint + "/v1/traces").build()).setScheduleDelay(Duration.ofMillis(250)).build()).build();
SdkMeterProvider metrics = SdkMeterProvider.builder().setResource(resource)
.registerView(InstrumentSelector.builder().setName("lab.http.duration").build(), View.builder()
.setAggregation(Aggregation.explicitBucketHistogram(List.of(.005,.01,.025,.05,.1,.25,.5,1.0,2.0,5.0))).build())
.registerMetricReader(PeriodicMetricReader.builder(OtlpHttpMetricExporter.builder()
.setEndpoint(endpoint + "/v1/metrics").build()).setInterval(Duration.ofSeconds(1)).build()).build();
SdkLoggerProvider logs = SdkLoggerProvider.builder().setResource(resource)
.addLogRecordProcessor(BatchLogRecordProcessor.builder(OtlpHttpLogRecordExporter.builder()
.setEndpoint(endpoint + "/v1/logs").build()).setScheduleDelay(Duration.ofMillis(250)).build()).build();
sdk = OpenTelemetrySdk.builder().setTracerProvider(traces).setMeterProvider(metrics).setLoggerProvider(logs)
.setPropagators(ContextPropagators.create(W3CTraceContextPropagator.getInstance())).build();
tracer = sdk.getTracer("book.observability", "1.0.0");
logger = sdk.getLogsBridge().get("book.observability");
requests = sdk.getMeter("book.observability").counterBuilder("lab.requests").setUnit("{request}").build();
duration = sdk.getMeter("book.observability").histogramBuilder("lab.http.duration").setUnit("s").build();
for (String outcome : List.of("ok", "error")) requests.add(0, Attributes.builder().put("route","/orders").put("outcome",outcome).build());
}
public void flush() {
sdk.getSdkTracerProvider().forceFlush().join(10, TimeUnit.SECONDS);
sdk.getSdkMeterProvider().forceFlush().join(10, TimeUnit.SECONDS);
sdk.getSdkLoggerProvider().forceFlush().join(10, TimeUnit.SECONDS);
}
public void close() { sdk.close(); }
}#!/usr/bin/env python3
"""Query actual backends and preserve raw evidence. No in-memory trace oracle."""
import argparse,base64,json,time,urllib.request,urllib.error,urllib.parse
from pathlib import Path
OUT=Path('evidence');OUT.mkdir(exist_ok=True)
def request(url,body=None):
data=json.dumps(body).encode() if body is not None else None
try:
with urllib.request.urlopen(urllib.request.Request(url,data=data,headers={'Content-Type':'application/json','Accept':'application/json'}),timeout=15) as response:
raw=response.read();return response.status,json.loads(raw) if raw else None
except urllib.error.HTTPError as error:
raw=error.read()
try:value=json.loads(raw)
except Exception:value=raw.decode(errors='replace')
return error.code,value
def wait(label,fn,timeout=75):
start=time.monotonic();last=None
while time.monotonic()-start<timeout:
try:
last=fn()
if last:return last
except Exception as error:last=str(error)
time.sleep(1)
raise AssertionError(f'{label}: timeout; last={last}')
def save(name,data):(OUT/name).write_text(json.dumps(data,ensure_ascii=False,indent=2)+'\n')
def events():return request('http://127.0.0.1:8080/lab/events')[1]
def processed(order):return next((e for e in events() if e['event']=='worker.processed' and e['order_id']==order),None)
def query(expression):
status,result=request('http://127.0.0.1:9095/api/v1/query?'+urllib.parse.urlencode({'query':expression}))
assert status==200,(status,result)
return result
def identifier(value):
if not value:return ''
if len(value) in (16,32) and all(c in '0123456789abcdefABCDEF' for c in value):return value.lower()
return base64.b64decode(value).hex()
def spans(trace):
result=[]
def walk(value,service=''):
if isinstance(value,dict):
if 'resource' in value:
attrs=value['resource'].get('attributes',[])
service=next((a['value'].get('stringValue','') for a in attrs if a['key']=='service.name'),service)
if 'spanId' in value and 'name' in value:
result.append(dict(name=value['name'],service=service,span_id=identifier(value['spanId']),parent=identifier(value.get('parentSpanId','')),start=int(value.get('startTimeUnixNano',0)),end=int(value.get('endTimeUnixNano',0))))
for child in value.values():walk(child,service)
elif isinstance(value,list):
for child in value:walk(child,service)
walk(trace);return result
def trace(trace_id,name,services=None,minimum=7):
required=services or {'book-gateway','book-orders','book-worker'}
observations=[]
def fetch():
status,value=request('http://127.0.0.1:3200/api/traces/'+trace_id)
found=spans(value) if status==200 else []
observations.append({'status':status,'spans':len(found),'services':sorted({s['service'] for s in found})})
return value if status==200 and len(found)>=minimum and required<={s['service'] for s in found} else None
result=wait('Tempo complete trace '+name,fetch);save('trace-arrival-'+name+'.json',observations);save('trace-'+name+'.json',result);return spans(result)
def post(order,**extra):
status,body=request('http://127.0.0.1:8080/orders',dict(id=order,**extra))
return status,body
def main():
ap=argparse.ArgumentParser();ap.add_argument('--phase',choices=['full','sampled-out','collector-outage','recovered'],default='full');args=ap.parse_args()
wait('application ready',lambda:request('http://127.0.0.1:8080/health')[0]==200)
if args.phase=='collector-outage':
start=time.monotonic();status,body=post('collector-outage');elapsed=time.monotonic()-start
assert status==202 and elapsed<8,(status,body,elapsed)
event=wait('business with collector stopped',lambda:processed('collector-outage'))
save('collector-outage.json',{'response':body,'worker_event':event,'http_elapsed_seconds':elapsed})
print('PASS application and real MQ consumer continue while Collector is stopped');return
if args.phase=='recovered':
wait('Collector health after restart',lambda:request('http://127.0.0.1:13133/')[0]==200)
status,body=post('after-outage');assert status==202,body
event=wait('after-outage consumer',lambda:processed('after-outage'))
found=trace(body['trace_id'],'after-outage');assert {'book-gateway','book-orders','book-worker'}<={s['service'] for s in found}
outage=json.loads((OUT/'collector-outage.json').read_text())
old_code,old_body=request('http://127.0.0.1:3200/api/traces/'+outage['response']['trace_id'])
save('collector-recovered.json',{'fresh_response':body,'fresh_worker':event,'fresh_trace_services':sorted({s['service'] for s in found}),'outage_trace_status_after_recovery':old_code})
print('PASS fresh real traces resume after Collector restart; old-trace result recorded without promising lossless recovery');return
if args.phase=='sampled-out':
status,body=post('sampled-out');assert status==202,body
event=wait('unsampled consumer',lambda:processed('sampled-out'))
assert event['sampled'] is False,event
request('http://127.0.0.1:8080/lab/flush');time.sleep(5)
code,value=request('http://127.0.0.1:3200/api/traces/'+body['trace_id'])
assert code==404,(code,value)
result={'sampled_out_order':body,'worker_event':event,'tempo_http_status':code,'metrics':query('sum(lab_requests_total{service_name="book-gateway"})')}
assert result['metrics']['data']['result'],result
save('sampling-zero.json',result);print('PASS sampling=0: real consumer and metrics continue; Tempo returns 404; logs mark sampled=false');return
wait('initial metric series',lambda:query('sum(lab_requests_total{service_name="book-gateway"})')['data']['result'])
time.sleep(3)
results={}
for name,options in [('normal',{}),('redis-slow',{'redis_delay_ms':350}),('worker-slow',{'worker_delay_ms':450}),('broken-context',{'propagate':False})]:
status,body=post(name,**options);assert status==202,(status,body)
event=wait('worker '+name,lambda:processed(name))
results[name]={'response':body,'worker_event':event}
found=trace(body['trace_id'],name,{'book-gateway','book-orders'} if name=='broken-context' else None,5 if name=='broken-context' else 7)
assert {'book-gateway','book-orders'}<={s['service'] for s in found},found
if name!='broken-context':
assert event['trace_id']==body['trace_id'],(name,event,body)
assert 'book-worker' in {s['service'] for s in found},found
producer=next(s for s in found if s['name'].startswith('rocketmq publish'))
consumer=next(s for s in found if s['name'].startswith('rocketmq process'))
assert consumer['parent']==producer['span_id'],(producer,consumer)
assert any(s['span_id']==event['span_id'] for s in found),event
else:
assert event['trace_id']!=body['trace_id'],(event,body)
assert 'book-worker' not in {s['service'] for s in found}
detached=trace(event['trace_id'],'detached-worker',{'book-worker'},2)
assert 'book-worker' in {s['service'] for s in detached}
if name=='redis-slow':
client=next(s for s in found if s['name']=='redis SET order')
assert (client['end']-client['start'])/1e6>=300,client
results[name]['injected_span_ms']=(client['end']-client['start'])/1e6
if name=='worker-slow':
consumer=next(s for s in found if s['name'].startswith('rocketmq process'))
assert (consumer['end']-consumer['start'])/1e6>=400,consumer
results[name]['consumer_span_ms']=(consumer['end']-consumer['start'])/1e6
results[name]['spans']=found
for number in range(7):
status,body=post('slo-ok-'+str(number));assert status==202,body
time.sleep(.3)
for number in range(5):
status,body=post('slo-error-'+str(number),fail=True);assert status==503,body
time.sleep(1)
request('http://127.0.0.1:8080/lab/flush')
metrics=wait('metric counter',lambda:(lambda r:r if r['data']['result'] and float(r['data']['result'][0]['value'][1])>=16 else None)(query('sum(lab_requests_total{service_name="book-gateway"})')))
save('metrics-requests.json',metrics)
histogram=query('histogram_quantile(0.95, sum by (le) (rate(lab_http_duration_seconds_bucket{service_name="book-gateway"}[1m])))');save('metrics-p95.json',histogram)
assert histogram['data']['result'],histogram
def firing():
code,value=request('http://127.0.0.1:9095/api/v1/alerts')
return value if code==200 and any(a['labels'].get('alertname')=='BookFastBurn' and a['state']=='firing' for a in value['data']['alerts']) else None
alert=wait('Prometheus fast-burn firing',firing);save('alerts.json',alert)
metric_labels=query('lab_requests_total');save('metric-labels.json',metric_labels)
assert all('order_id' not in row['metric'] and 'trace_id' not in row['metric'] for row in metric_labels['data']['result'])
def exemplars():
expression='lab_http_duration_seconds_bucket{service_name="book-gateway"}'
code,value=request('http://127.0.0.1:9095/api/v1/query_exemplars?'+urllib.parse.urlencode({'query':expression,'start':time.time()-600,'end':time.time()}))
return value if code==200 and value.get('data') else None
samples=wait('real metric exemplars',exemplars);save('exemplars.json',samples)
exemplar_ids={sample['labels']['trace_id'] for series in samples['data'] for sample in series['exemplars'] if 'trace_id' in sample['labels']}
assert exemplar_ids, samples
known={e['trace_id'] for e in events()};assert exemplar_ids & known,(exemplar_ids,known)
save('events.json',events());save('results.json',{'checks':results,'passed':True,'metrics_requests':metrics,'alert':alert,'exemplar_trace_ids':sorted(exemplar_ids)})
print('PASS actual Java/Redis/RocketMQ/OTLP/Tempo/Prometheus: parentage, logs, delays, broken-context, histogram, low-cardinality labels and firing alert')
if __name__=='__main__':main()