文档目录

4.6 应用可观测性：指标、追踪、日志

上一节：4.5 系统级观测　|　下一节：4.7 数据与中间件观测配套代码：04-toolchain/06-app-observability

一句话结论

应用可观测性由三根柱子支撑：指标（发现问题）、追踪（定位环节）、日志（看清细节）。 三者各有致命陷阱：指标的分位数算法、追踪的采样策略、日志的同步刷盘——任何一个搞错，都会让你在关键时刻拿不到数据。

一、用「生命体征监护仪」理解三根柱子

监护手段	对应	特点
监护仪（心率、血压、血氧）	指标	连续、便宜、能告警；但只有数字，不知道原因
CT/造影（看具体位置）	追踪	能定位到具体环节；但有采样成本
病历（详细记录）	日志	信息最全；但成本高，不能全记

关键：三者互相验证。监护仪报警（指标异常）→ 做 CT（追踪定位）→ 查病历（日志细节）。

二、指标：三个必须避开的陷阱

陷阱一：用平均值或客户端算好的分位数

已在第 1 章 1.2 节讲过：百分位不可平均，必须用直方图。

-- ✅ 正确：先按 le 聚合，再算分位数
histogram_quantile(0.99, sum by (le) (rate(http_server_requests_seconds_bucket[5m])))

-- ❌ 错误：对实例的 P99 求平均
avg(http_server_requests_seconds{quantile="0.99"})

实践检查：如果你的 Prometheus 里出现了 quantile="0.99" 这样的标签，说明你（或某个库）在客户端算了分位数——这在多实例场景下是错的。

陷阱二：桶边界不合适

已在第 1 章 1.2 节讲过。这里补充一个快速检查方法：

# 如果 P99 长期等于某个固定值（比如正好 100ms），说明桶在那一带太稀疏
histogram_quantile(0.99, sum by (le) (rate(http_server_requests_seconds_bucket[5m])))

自检：把桶边界画出来，看 SLO 附近是否加密。

陷阱三：标签基数爆炸 ⭐

// ❌ 灾难：每个用户/订单/URL 一个时间序列
registry.counter("request", "userId", userId)
registry.counter("request", "uri", "/orders/12345")

// ✅ 正确：只用可枚举维度
registry.counter("request", "uri", "/orders/{id}", "status", "200", "method", "GET")

基数的量化影响：

1 个接口 × 5 种状态码 × 3 种方法 = 15 个序列    → 无所谓
10 万个订单 ID                 = 10 万个序列   → Prometheus 内存爆炸

基数排查：

# 看哪个指标的时间序列最多
topk(10, count by (__name__)({__name__=~".+"}))

一句话规则：标签值必须是「有限可枚举」的集合。 用户 ID、订单号、traceId、时间戳、具体 URL 绝对不能做标签。

三、追踪（Tracing）：定位环节的标准工具

3.1 Span 树：把一次请求拆开看

HTTP GET /orders/123                                    ← 根 Span（200ms）
├── auth.verify                                          ←  5ms
├── db.query orders                                       ← 80ms
│   └── SQL: select * from orders where id = ?            ← 78ms
├── redis.get order:123                                   ←  2ms
└── http GET user-service/users/42                        ← 95ms   ← 大头在这里
    └── (下游服务内部还有自己的 Span)

价值：一眼看出「95 ms 花在调下游」。这比看火焰图更直接（第 1 章 1.3 节的「差额分析法」）。

3.2 采样策略：必须提前想清楚

策略	原理	优点	缺点
Head sampling	在请求入口按比例决定是否采样	简单、开销均匀	可能漏掉慢请求（除非按延迟自适应）
Tail sampling	先收集全部 span，在 collector 端按条件决定保留	能精准保留「慢请求」和「错误请求」	需要 collector 缓冲全部 span，成本高

推荐做法：

① 基线采样率：1%~10%（head sampling）
② 关键路径：100% 采样（比如下单、支付）
③ 慢请求：tail sampling 保留（P99 以上的请求）
④ 错误请求：100% 保留

一个常见错误：只用 head sampling 1%，然后发现「追踪里没有慢请求的数据」——因为慢请求本来就是少数，1% 采样后几乎都丢了。慢请求恰恰是你最需要追踪的。

3.3 追踪与压测的关联

压测时给请求打一个标记（比如 header X-Load-Test: true），然后在追踪系统里按这个标记过滤：

// k6 脚本里
const res = http.get(url, { headers: { 'X-Load-Test': 'true' } });

这样可以把压测流量与真实流量分开分析——避免压测数据污染生产的追踪与指标。

四、日志：最容易被低估的性能杀手

4.1 同步日志的真实代价

// ❌ 最糟：每次请求都刷盘
log.info("处理订单 {}", order)     // 同步 appender → 每次 write + flush

代价来源：

代价	说明
系统调用	每次 `write` 都要陷入内核（`sy` CPU 上升）
磁盘 IO	`flush` 会等待数据落盘
字符串拼接	即使日志级别不输出，很多实现仍会先拼接字符串
GC 压力	拼接产生临时对象

实测影响：高频同步日志可能占 10%–30% 的延迟——这是最容易被忽视的性能问题之一。

4.2 三个改进方向

<!-- ① 用异步 appender -->
<AsyncLogger name="com.example" level="info" includeLocation="false"/>

<!-- ② 关掉行号（获取行号需要构造栈，非常贵） -->
<PatternLayout pattern="%d{HH:mm:ss} %-5level %msg%n"/>   <!-- 不要 %L / %line -->

<!-- ③ 用参数化日志，避免无谓拼接 -->

// ❌ 字符串在调用前就拼好了（即使级别不够也会拼接）
log.debug("order=${order.id}, items=${order.items.size}")

// ✅ 参数化：级别不够时不会拼接
log.debug("order={}, items={}", order.id, order.items.size)

// ✅ 更严格：先判断级别
if (log.isDebugEnabled) log.debug("expensive=${expensiveToString(order)}")

4.3 日志的三个成本层次

层次	成本	什么时候用
热路径 INFO 日志	高（每次请求都写）	只在必要时，且用异步 appender
关键事件日志（下单、支付）	中	保留，但控制字段数量
错误日志	低（频率低）	完整记录，含上下文

实战建议：用分配火焰图找日志开销——你会看到 StringBuilder、String.format、FileOutputStream.write 出现在热路径上（第 3 节）。

五、三根柱子怎么配合

① 指标报警：「/orders 的 P99 > 500ms」（发现问题）
        ↓
② 追踪定位：「95ms 花在调用 user-service」（定位环节）
        ↓
③ 日志细节：「user-service 返回了 504，重试了一次」（看清细节）
        ↓
④ 剖析验证：async-profiler wall 火焰图确认阻塞在 socket read（技术验证）
        ↓
⑤ 结论：下游超时 + 重试导致尾延迟放大

注意顺序：指标 → 追踪 → 日志 → 剖析。这个顺序是从「便宜」到「贵」、从「粗」到「细」。不要一上来就采火焰图——你不知道该找什么。

六、本节小结

应用可观测性三根柱子：指标（发现）、追踪（定位）、日志（细节），互相验证。
指标三个陷阱：客户端算分位数、桶边界不合适、标签基数爆炸。
追踪的关键是采样策略：head sampling 可能漏掉慢请求，慢请求与错误请求应 100% 保留。
同步日志是隐藏的性能杀手（可能占 10%–30%），改进方向是异步 appender、去掉行号、参数化日志。
排查顺序：指标 → 追踪 → 日志 → 剖析（从便宜到贵）。

七、自测

你的 Prometheus 内存持续增长，最后 OOM。最可能的原因是什么？怎么定位到具体是哪个指标？
你用 1% 的 head sampling 采集追踪，结果发现追踪系统里几乎没有慢请求。请解释原因，并给出两种改进方案。
一个服务的 sy CPU 从 5% 涨到 25%，同时 P99 从 50 ms 涨到 180 ms。你怀疑是日志问题。请说出你的验证步骤。

最可能的原因是指标标签基数爆炸——某个指标的标签值是无界的（用户 ID、订单号、URL 全路径、traceId 等），导致时间序列数量随时间无限增长。定位方法：用 topk(10, count by (__name__)({__name__=~".+"})) 找出序列数最多的指标名，然后看它的标签：count by (__name__, <可疑标签>) (...)，找到那个值特别多的标签。修复：去掉或聚合那个标签（改用路由模板、状态码分类等可枚举维度）。注意：已经产生的大量序列需要重启 Prometheus 或删除相关数据才能释放。
原因：慢请求是少数（比如只占 1%），在 1% 的 head sampling 下，1000 个慢请求里只有约 10 个被采样，而且采样是随机的——你几乎不可能恰好采到「有代表性的」慢请求，更看不到它们的完整调用链。两种改进方案：① Tail sampling——在 collector 端先收集全部 span，然后按「耗时 > 阈值」或「有错误」的条件决定保留（能精准留下慢请求，代价是 collector 需要缓冲）；② 差异化 head sampling——对关键路径提高采样率（比如 100%），或在应用端做「延迟自适应采样」（请求完成后如果发现很慢，就强制上报）。③ 另一种实用做法：把 slow query / 慢请求单独通过日志或自定义指标记录，不依赖 tracing。
验证步骤：① 时间对齐——确认 sy 上升的时间点与「新加了日志」的发布时间一致（如果不一致，可能不是日志）；② 采 CPU 火焰图——看是否出现 FileOutputStream.write / FileDispatcherImpl.write0 / StringBuilder / String.format 等栈；③ 用 JFR 的 jdk.FileWrite 事件——直接给出文件写入的次数与耗时排行榜，这是最确定性的证据；④ 做单变量实验——把日志级别降到 WARN 或临时关掉某条日志，看 sy 与 P99 是否回落；⑤ 检查日志配置：是否用了同步 appender、是否开启了 %L（行号，需要构造调用栈，非常贵）、是否在热路径上拼接大对象。修法：异步 appender + 去掉行号 + 参数化日志 + 降低热路径日志级别。

4.6 应用可观测性：指标、追踪、日志#

一句话结论#

一、用「生命体征监护仪」理解三根柱子#

二、指标：三个必须避开的陷阱#

陷阱一：用平均值或客户端算好的分位数#

陷阱二：桶边界不合适#

陷阱三：标签基数爆炸 ⭐#

三、追踪（Tracing）：定位环节的标准工具#

3.1 Span 树：把一次请求拆开看#

3.2 采样策略：必须提前想清楚#

3.3 追踪与压测的关联#

四、日志：最容易被低估的性能杀手#

4.1 同步日志的真实代价#

4.2 三个改进方向#

4.3 日志的三个成本层次#

五、三根柱子怎么配合#

六、本节小结#

七、自测#