11.03 日志、指标与 Trace：沿 IM 请求链留下有限证据
返回第十一卷 · 测量前置：11.01 · 分布前置：11.02
11.03 日志、指标与 Trace：沿 IM 请求链留下有限证据
DeepTutor 初稿经技术与教学审阅后的静态课程。日志行、指标值、Span 时间和结果均为虚构纸上记录；本次没有运行 Go、IM 服务、监控/追踪系统、基准或站点构建。
为什么已经有一个 200，还要三种证据
09.04 给出一个困难情景：u-a 提交 m-a，服务端在本进程内存中已经受理，随后响应在返回 A 的路上丢失。服务端日志可能写过 status=200，A 却只看到超时。11.01 教我们先定义“内存受理”与“客户端收到回答”的不同确认点；11.02 教我们不能只看平均或少量成功样本的 P99。现在要给未来教学服务设计三种互补的观察：日志记录一次事件，指标汇总许多事件，Trace连接某一次请求经过的阶段。
当前仓库仍只有本地 imhistory CLI 和静态未来接口设计，没有运行中的 HTTP/WS、指标收集器或 Trace 后端。本章不会宣称持久保存、B 设备收到或已读有真实观测。u-a/u-b/c-a/m-a 均为虚构身份，数字沿用前章纸上模型。
| 第一遍 | 第二遍 | 练习交付物 |
|---|---|---|
| 事件、Counter/Gauge/Histogram、Span | 关联、采样、高基数与盲区 | 一条脱敏日志、三项指标、一棵请求 Span 树 |
一、日志、指标、Trace 分别回答什么
假想 m-a 的 POST 在服务端经过 handler、应用服务、内存适配器。问“这一次在内存提交前还是后断开”，可以查有阶段记录的日志或 Trace；问“最近五分钟这种超时发生多少、受理比例怎样变化”，应按 11.01 的分母汇总指标；问“这条请求的总耗时里哪段等待”，需要含起止时间的阶段记录与 Trace。它们覆盖范围不同，不能让一条日志代替完整统计，也不能让一个 P99 直接指出单次请求根因。
| 信号 | 一份记录的典型单位 | 擅长回答 | 单独不能证明 |
|---|---|---|---|
| 日志 log | 一次阶段事件 | 当时做了什么、哪个错误类别 | 全部请求的可靠比例、客户端实际收到了什么 |
| 指标 metric | 时间序列里的计数或分布 | 多少、增长速度、当前排队、时延轮廓 | 某条 m-a 的完整调用路径 |
| 追踪 trace | 同一操作关联的一组 span | 哪些阶段发生、相互次序与各段耗时 | 未被采样的所有请求、用户已读 |
Google SRE 将对外可见的黑盒观察与服务内部提供的白盒观察区分开。A 设备是否真的得到完整 200，是更靠近黑盒的一项；服务内的 memory_commit 日志和处理耗时是白盒证据。两边若相互矛盾，先确认观察主体和时间范围，不能用服务端一条“准备写 200”的记录把 A 的超时改写成成功收到。
二、结构化日志：记录阶段，而非复述正文
一条有用的日志应能回答“何时、哪条操作、在哪个阶段、是什么结果”。Go 标准库 log/slog 为以后个人实现提供结构化字段入口；本章只设计字段，不运行 logger。用完全虚构、脱敏的纸上记录表达服务端已内存提交：
op_id=teach-001 route=POST /v1/conversations/{id}/messages
stage=memory_commit result=accepted_in_memory status_planned=200
duration_ms=<个人实际测量后填写>status_planned=200 比“客户端收到了 200”更准确：此刻只是内存提交完成并准备响应。若写出失败，可再记录 stage=response_write result=interrupted；同一个操作的两条事件共同说明“服务端已提交、外部回答未知”。一条请求中日志的操作标识应能稳定关联阶段；但客户端自报的 X-Request-ID 可能伪造、过长或重复，边界需要生成/校验并限制长度，不能直接把不受控字符串写入日志作为可靠身份。
日志默认不记录真实访问令牌、原始 JSON、消息正文、用户资料或完整任意 URL。即使教学身份是 u-a/c-a/m-a，未来服务也应按最少信息原则只记录路由模板、阶段、稳定错误码、必要的大小或数量，并对可关联身份的值设访问控制与保留期。slog 让字段格式统一，不会自动替应用完成脱敏或权限审查。HTTP 400、409 和客户端取消应分别记录原因，不能只写一行 error=true 失去解释能力。
日志也可能丢失、采集延迟或重复发送。因此“没查到日志”不是事件绝对没发生；“查到 commit 日志”也需核对它是在状态完成后写的，而不是提前打印的“即将提交”。记录位置应与 09.04 的内存提交点对应，审阅时可沿代码路径指出证据能覆盖的边界。
三、Counter、Gauge、Histogram 的最小模型
Counter 累加已发生事件，例如 im_send_attempts_total 按被限定的结果类别加一。对单个运行进程，它通常单调增加直到进程重启或计数重置；看“每秒多少次”要计算某段时间内的增量 ÷ 时长，不能把当前累计值 100 直接写成 100 次/秒。多进程汇总还要处理实例范围和重启后的重置。指标名称和标签只用课程自定示意，不表示已有真实 Prometheus 服务。
Gauge 表示当下可增可减的状态，例如 im_inflight_requests 或内存队列长度。它回答“某时刻有几项”，不是“这一小时总共进来几项”。容量为 2 的 channel 当前 len=2 可表示排队已满，但不能由一次快照知道等了多久，或有多少生产者在外面阻塞。
Histogram 按桶记录一组数值。沿用 11.02 的客户端口径：从 A 点击提交到 A 收到内存受理回应，只有完成该确认点的请求才形成时延样本；服务端若另测“入口到内存提交”，必须另起指标，不能混入同一桶。本章统一用秒作为指标单位。借用 11.02 的十个虚构完成时延，总和 326 ms=0.326 s、count=10；若桶上界取 0.020 s、0.100 s、+Inf，传统累计桶计数为 9、9、10。这不是在计算设备送达；桶只能估计分位数，不能把 +Inf 中那一个原值从桶表精确还原为 0.200 s。
| 类型 | 示例名字与单位 | 更新时刻 | 勿误读为 |
|---|---|---|---|
| Counter | im_send_attempts_total，次 | 一次请求尝试进入选定边界 | 业务唯一消息数 |
| Gauge | im_inflight_requests，项 | 请求开始/结束或队列变化 | 累计请求量 |
| Histogram | im_accept_response_duration_seconds，秒 | A 收到受理回应时记录客户端耗时 | 服务端处理 P99 或 B 设备送达 P99 |
指标设计要回到 11.01 的分母。若统计服务端内存受理比例，分子是同一合格尝试队列中完成内存提交的事件，分母是合格尝试；无效参数、重复 ID 和客户端超时怎么分类须事先写明。Counter 按 result 聚合也必须让全部类别能对账，不能为让比例好看而只给成功路径加计数。上表的客户端时延直方图只覆盖已收到回应的样本，还必须并排报告超时和结果未知的尝试数。
四、标签基数：一次请求的身份别放进每条时间序列
指标通常可按少数标签分组，例如 route=send_message、result=accepted_in_memory、stage=handler。标签值的组合会变成不同的时间序列。假设纸上只有 3 种固定路由模板、4 种固定结果类别，单靠这两个维度最多形成 3×4=12 个组合；若再用 100000 个用户 ID 作标签，理论组合上界升到 1200000。真实出现的组合可能更少，但高基数会提高采集、存储、查询成本，也可能泄露身份线索。
| 候选标签 | 基数与用途 | 本章选择 |
|---|---|---|
| 固定路由模板 | 少数值，可比较不同接口 | 可用 /v1/conversations/{id}/messages 这类模板 |
| 固定结果类别 | 如 accepted/duplicate/invalid | 可用，值集合有版本管理 |
原始 URL，包含 c-a 等 ID | 每会话可能不同 | 不作普通指标标签 |
user_id、message_id、令牌、正文 | 高基数或敏感 | 不作指标标签，也不输出原始正文 |
把用户 ID 做哈希通常也不会把高基数变低：不同用户的哈希仍可能几乎都不同，只是改变了显示样式。若确需定位一条虚构 m-a，可在受权限控制的日志或 Trace里使用受限关联标识，并设定采样、留存和脱敏规则；聚合指标保持低基数。请求路径里的 c-a 应归一到路由模板后再做标签，不能把原始路径原样灌入 Counter。
标签也改变 11.02 的样本可比性。若 accepted_in_memory 与 duplicate 混用一个“成功”分布，分母和终点就失真；若给每个连接 ID 一个桶，可能既高基数又无法稳定聚合。先定义用户动作与阶段，再给固定标签词汇，不能由底层指标平台自动替业务决定。
五、Trace 与 Span：把一次请求的阶段连起来
Trace 是围绕一次操作关联的一组 Span；Span 表示其中一段工作，可包含名称、父 Span、开始/结束时刻、状态与少量属性。追踪的价值是把“HTTP handler→应用服务→内存追加→响应”放在一张有先后与嵌套关系的图中；它不是把每一行日志都改名为 Span。
沿 11.01 的单一理想时钟纸上时间线，画一棵可能的树：
client.send m-a t=0..40 ms （客户端侧纸上 Span）
└─ HTTP POST handler t=12..30 ms （服务端请求 Span）
├─ app.Send t=13..25 ms
│ └─ memorystore.Append t=20..25 ms
└─ prepare/write response t=25..30 ms
客户端收到响应 t=40 ms这里 app.Send 的 12 ms 包含子段 memorystore.Append 的 5 ms，不能把父子 Span 时长直接相加成 17 ms；还要留意 t=12..13、t=13..20 的其他处理。服务端 Write 返回于 t=30，也不能由这棵服务端树证明 A 在 t=40 已经完整收到响应——后者需要客户端自己的观察。现实跨机器时钟可能不一致，本图只为说明父子关系和阶段，实际端到端时长需在各自进程用合适时钟与传播关联事件核对。
Trace 有自己的 trace_id，每个 Span 有 span_id；父子关系用于把阶段组合起来。HTTP 请求跨进程时，追踪上下文需要通过约定的载体注入、提取和传播，不是只把 Go 的 context.Context 当普通参数往下传，就会自动在另一台机器生成正确 Trace。r.Context() 的取消与 Trace 上下文可以共存，但分别解决停止工作与关联观察的问题。
一条业务消息 m-a 因响应丢失重试，可能产生两个 HTTP 请求、两个操作 ID/Trace，却只有一个原本的业务消息 ID；反过来，一个 Trace 也可能包含多个内部 Span。三种 ID 不可互相替换。若要跨两次重试关联，需要受控的业务身份记录和访问权限，不能因为 trace_id 看起来唯一就当作消息去重键。
六、同一条请求用三种证据互相校验
假想 A 发起 POST，服务端内存提交完成，服务端尝试写 200，而 A 因连接中断只看到超时。三种信号可共同缩小不确定范围：
| 信号 | 本题可设计的纸上证据 | 此时仍不知道 |
|---|---|---|
| 日志 | op_id=teach-001 stage=memory_commit result=accepted_in_memory，随后 response_write=interrupted | A 是否曾看到任何部分响应 |
| Counter | 受理结果计数的 accepted_in_memory 类别 +1；另一个响应写出错误计数 +1 | 哪个单独用户意图已确认完成 |
| Trace | 若该请求被采样，显示 app.Send→Append 已结束、写回应阶段中断 | 未采样的其他请求怎样、B 是否收到 |
| 客户端观察 | A 超时、没有可用的 HTTP 状态码 | 服务端是否已经受理，需另查 |
不应在日志里写“客户端已获 200”，也不能因为 Counter 增了 1 就把 A 的超时改成成功回答。若接口后来提供按同一消息 ID 查询受理状态，A 才有机会把未知结果转成已确认状态；该查询及幂等保证留给 S5。当前 S2 设计里只有内存已受理的可能事实，进程退出后还可能丢失，不能从三类观测中推导持久性。
换一个请求体过大的变式，日志可在 body_limit 阶段记 REQUEST_TOO_LARGE，Counter 的 413 类别加一，若有 Trace 可显示处理在授权/内存追加前结束；状态不应产生 memory_commit 事件。负例同样需要可审计的阶段记录，但不能为定位错误而把原始坏 JSON 或真实凭据全部写入日志。
七、采样与缺失：没有一条记录并非没有发生
为了限制成本，Trace 常只保留一部分请求；采样意味着某条慢或失败请求可能没有完整 Span 树。不能用被抽中的十条 Trace 直接当 100 次请求的分母，或由“没搜到 Trace”断定服务端没受理。错误分支可以有不同采样策略，但无论怎样都要记录采样条件，否则前后比例会失真。日志也可能因收集器故障、进程退出或权限策略而缺失；指标虽可设计为每次事件加计数，实际采集和进程重启仍需处理丢失与 Counter 重置。
11.01 的持久确认、设备收到和用户已读在当前课程没有真实数据源。既不能报“0% 已送达”，也不能报“100% 未读”；应该写“未实现/未观测”，再列需要在哪些未来阶段采集什么事件。白盒的内存提交与黑盒的 A 客户端结果应并列，不能只留一侧。必要的关联 ID、保留期、访问权限和脱敏也是观测设计的一部分，不是上了指标系统就自动解决。
一条长 Trace 看似能指出“哪一段占时最多”，但它本身也可能是异常样本；平均/分位分布仍需 11.02 的同口径样本集合。反过来 P99 升高只告诉你结果分布变了，不直接告诉你是锁、CPU、网络还是 B 的设备；11.04 才将这些信号用于假设驱动诊断。
八、交付最小观测设计与分层练习
练习交付三件静态产物：一条没有正文/令牌的 memory_commit 日志字段表；三项指标卡（Counter 尝试、Gauge 当前在途、Histogram 内存受理时延）及各自单位/标签/更新点；一棵 POST 的 Span 树，并标明客户端与服务端各自能看见什么。最后给“响应丢失”和“请求体过大”各写一条已知/未知/下一证据。将来学习者在自己的隔离系统实际运行后，再另存真实数据；本章没有执行 Go 或监控。
分层练习：先回答，再核对反馈
1. 日志适合回答“最近五分钟占比”吗？
单条日志不适合；要定义同口径分母与聚合计数。
2. 指标能直接画出某条 m-a 的完整请求栈吗？
通常不能。需要关联日志或被采样 Trace 的阶段信息。
3. Trace 的一个 Span 表示什么？
一次操作中的一段工作，带起止与父子关联等信息。
4. `status_planned=200` 证明 A 收到了 200 吗？
不能。它仅说明服务端计划写该状态，外部结果另需观察。
5. Counter 当前累计值 100 等于 100 次/秒吗？
不等于。速率要看选定时间窗内的增量除以时长。
6. Gauge 适合记录当前在途请求吗？
适合。它随开始/结束增减，代表某时刻存量。
7. Histogram 的 count=10、sum=0.326 s 表示均值多少？
0.326/10=0.0326 s=32.6 ms。
8. 累计桶 9、9、10 能相加当总数吗？
不能。它们相互包含，总数由 +Inf 的 10 表达。
9. `route` 标签应填 c-a 的原始 URL 吗？
不应。用固定路由模板，避免每个会话生成一个新时间序列。
10. 3 条路由×4 个结果最多多少组合？
仅这两个维度的上界为 12，尚未计其他维度。
11. 再加 100000 个用户 ID 标签，上界怎样变？
可达 1200000 个组合，且涉及身份信息与成本。
12. 把 user_id 哈希就一定消除高基数吗？
不会。大量不同用户的哈希仍是大量不同标签值。
13. `trace_id` 与业务 `message_id` 是同一身份吗？
不是。Trace 关联一次执行路径，消息 ID 关联业务对象。
14. 一次重试会必然沿用第一次 trace_id 吗？
不必然。它可产生新请求/Trace，仍指向同一业务消息意图。
15. `app.Send` 12 ms 含子 Span `Append` 5 ms，能相加成 17 ms 吗？
不能。子段已包含在父段中，相加会重复计时。
16. Go `context.Context` 传给函数就自动跨网络传播 Trace 吗？
不会。跨进程需按协议注入、提取追踪上下文。
17. 某请求没有 Trace，能证明它没发生吗？
不能。它可能未被采样或采集失败。
18. 只用抽样 Trace 的条数作全部请求分母合适吗？
不合适。抽样集合与 11.01 的全部合格尝试集合不同。
19. 内存提交日志能证明数据库持久化吗？
不能。本章尚无持久阶段的真实数据源。
20. A 客户端超时与服务端 commit 日志矛盾吗？
不矛盾。服务端可已受理而响应在返回途中丢失。
21. 能把消息正文/访问令牌写进日志便于排障吗？
不应如此。记录脱敏阶段、类别和受控关联信息。
22. P99 升高就一定知道瓶颈是哪一个 Span 吗？
不能。要结合同口径分布、具体阶段 Trace 和后续诊断证据。
来源与下一步
- Google SRE：Monitoring Distributed Systems：黑盒/白盒、结果与内部观测的入门框架。
- OpenTelemetry：Trace 概念与可观测性基础：Span、父子关系与上下文传播。
- Prometheus：指标类型与采集实践：Counter/Gauge/Histogram 和标签成本。
- Go
log/slog：后续 Go 结构化日志入口。
按学习路线，S2 下一步可进入10.09 最小 CI 与制品；具备后续系统/存储前置后，再进入11.04 诊断方法。离开本章前，请能分别写出“日志查什么、指标算什么、Trace 追什么、没有数据时不能说什么”。