第 9 课约 15 分钟

可观测性 + Metrics + 日志 —— 系统上线后的"第三只眼"

掌握 Prometheus 三类指标埋点、trace_id 全链路日志、no-op 优雅降级、以及从指标异常反向定位根因。

可观测性PrometheusMetrics日志Python
进度保存在本机浏览器；验收通过后再点更稳妥

第 9 课：可观测性 + Metrics + 日志 —— 系统上线后的"第三只眼"

本节目标：掌握 Prometheus 三类指标埋点、trace_id 贯穿全链路日志、no-op 优雅降级模式、以及如何从指标异常反向定位根因。

前 8 课做了一个功能完备的 RAG Agent。上线后问题怎么发现？靠用户投诉？太晚了。

1. 可观测性三支柱

支柱回答的问题典型场景
Metrics"每秒多少请求？P95 延迟多少？"告警、容量规划、SLO
Logging"这个请求具体做了什么？"排查单个问题
Tracing"一次请求经过哪些步骤，每步耗时？"瓶颈定位、依赖分析

2. Metrics：Prometheus 三种指标类型

类型特点用法例子
Counter只增不减.inc()llm_calls_total：调了多少次
Histogram记录值的分布.observe(v)retrieval_latency_seconds：每次检索耗时
Gauge可升可降.set(v)approvals_pending：当前待审批数

指标全景

python
# LLM
llm_calls_total = Counter("llm_calls_total", "调用次数", ["model", "status"])
llm_latency_seconds = Histogram("llm_latency_seconds", "耗时", ["model"],
    buckets=(0.1, 0.5, 1, 2, 5, 10, 30))
llm_tokens_total = Counter("llm_tokens_total", "消耗 token", ["model", "type"])

# Retrieval
retrieval_latency_seconds = Histogram("retrieval_latency_seconds", "检索耗时", ["mode"],
    buckets=(0.02, 0.05, 0.1, 0.2, 0.5, 1, 2))
retrieval_hits = Histogram("retrieval_hits", "命中数", ["mode"],
    buckets=(0, 1, 3, 5, 10, 20))

# Agent
agent_steps = Histogram("agent_steps", "运行步数", buckets=(1,2,3,4,5,6,8,10))
agent_halts = Counter("agent_halts", "终止计数", ["reason"])

# Verifier
verifier_verdicts = Counter("verifier_verdicts", "判决计数", ["verdict"])

Labels 黄金法则

Code
# 低基数：model 3-5 种，status 就 ok/error → 6 条时间序列
llm_calls_total.labels(model="gpt-4o", status="ok").inc()

# 高基数：user_id 几万个 → Prometheus 存储爆炸

每个指标的 label 组合不超过 100。

Buckets 要贴合 SLO

Code
# SLO 是"检索 P95 < 200ms" → 200ms 附近加密桶
buckets=(0.02, 0.05, 0.1, 0.2, 0.5, 1, 2)
#                  ↑ 100ms  ↑ 200ms ← 目标附近

SLO 目标值两侧必须加密桶，否则 Prometheus 线性插值偏差大 → 告警不准。

3. 优雅降级：prometheus-client 没装也不崩

python
try:
    from prometheus_client import Counter, Histogram, Gauge
    _PROM_AVAILABLE = True
except ImportError:
    _PROM_AVAILABLE = False

    class _NoopMetric:
        def labels(self, *_a, **_kw): return self
        def inc(self, *_a, **_kw): pass
        def observe(self, *_a, **_kw): pass

    Counter = Histogram = Gauge = lambda *a, **kw: _NoopMetric()

核心设计：prometheus-client 是 optional 依赖。没装时所有指标变 no-op。业务代码零 if/else，开发和 CI 不需要装依赖，生产装上自动启用。

4. 埋点实战

检索服务

python
timer = retrieval_latency_seconds.labels(mode).time()
try:
    hits = hybrid_retrieval_service.retrieve(...)
    retrieval_hits.labels(mode).observe(len(hits))
finally:
    timer.__exit__(None, None, None)  # 即使抛异常也正确关闭

Verifier 判决

python
try:
    verifier_verdicts.labels(verdict.value).inc()
except Exception:
    pass  # metrics 失败静默忽略，不让观测代码阻断业务

Agent 步数

python
agent_steps.observe(len(run.scratchpad))
if run.halt_reason:
    agent_halts.labels(run.halt_reason).inc()

5. Logging：trace_id 全链路贯穿

ContextVar（协程安全，不用 thread-local）

python
_trace_id: ContextVar[str] = ContextVar("trace_id", default="-")

class TraceFormatter(logging.Formatter):
    def format(self, record):
        record.trace_id = _trace_id.get()   # 每条日志自动注入
        record.user_id = _user_id.get()
        return super().format(record)

输出效果：

text
INFO [trace=a1b2c3d4 user=bob] app.services.retrieval | [hybrid] v=5 k=3 fused=7
INFO [trace=a1b2c3d4 user=bob] app.graph.nodes | verify done in 1.23s | claims=3

一条 grep a1b2c3d4 看全链路。前端务必展示 X-Request-Id 让用户反馈时贴出。

TraceMiddleware：入口生成/复用 trace_id

python
class TraceMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request, call_next):
        tid = request.headers.get("X-Request-Id") or uuid.uuid4().hex[:16]
        token = _trace_id.set(tid)
        try:
            response = await call_next(request)
        finally:
            _trace_id.reset(token)   # ← 必须 reset！
        response.headers["X-Request-Id"] = tid
        return response

前端/上游传了 X-Request-Id 就复用 → 跨服务追踪。set/reset 必须成对在 try/finally 里。

6. 三行代码接入可观测性

python
from app.core.observability import TraceMiddleware, configure_logging

configure_logging(level=settings.log_level)   # 结构化日志
app.add_middleware(TraceMiddleware)            # trace_id 中间件
if settings.enable_metrics:
    app.include_router(metrics_router)         # /metrics 端点

7. 监控全景：哪个指标管什么

指标正常范围告警条件原因
llm_latency_seconds P95< 3s> 5sLLM 变慢/限流
llm_calls_total{status="error"}< 1%> 5%API key 过期
retrieval_latency_seconds P95< 200ms> 500ms索引膨胀
retrieval_hits 均值3-5< 1知识库空/query rewrite 失效
verifier_verdicts{verdict="revise"}< 15%> 30%生成质量下降
verifier_verdicts{verdict="conflict"}≈ 0> 0知识库矛盾
agent_halts{reason="error"}0> 0工具执行 bug
approvals_pending< 10> 50审批积压

8. 工程教训

  1. Metrics 失败静默→ try: counter.inc() except: pass。可观测性是旁路，绝不阻断业务
  2. trace_id 是排查生命线→ ContextVar 协程安全，TraceFormatter 自动注入。前端展示 X-Request-Id
  3. Histogram buckets 贴合 SLO→ 目标值附近加密桶，否则 P95/P99 不准 → 告警失真
  4. ContextVar > thread-local→ async 下 threading.local() 串数据，上线后才暴露
  5. Label 低基数→ user_id 等不要做 label。每个指标 label 组合不超过 100

9. 自测

问题 1：SLO 变成"P99 < 100ms"，buckets 怎么调？

问题 2：给 chat_messages 加 llm_calls_total 和 llm_latency_seconds，代码写在哪？注意什么？

问题 3：TraceMiddleware 不 reset ContextVar 会怎样？

问题 4：_NoopMetric 为什么不做参数校验（label 数量不对也不报错）？

问题 5（最重要）：上线后 retrieval_hits 均值 4.2→0.8，verifier insufficient 5%→60%，但 LLM 延迟正常、无报错。最可能根因是什么？怎么排查？

答案与解析

问题 1：调整 buckets

SLO 目标 100ms → 在 100ms 附近加密：(0.01, 0.02, 0.03, 0.05, 0.07, 0.1, 0.15, 0.2, 0.5, 1)。

70ms/100ms/150ms 三个桶精确捕捉"差一点超标"的请求。桶太稀疏 → P99 插值偏差 → 误报或漏报。

问题 2：LLM 埋点

在 chat_messages 方法内：try 前设 status="ok"，except 里改 status="error"，finally 里打点。这样成功失败都记录，且失败时 token 埋点不执行（resp 不存在）。

python
try:
    resp = await self._client.chat.completions.create(...)
except ...:
    status = "error"; raise
finally:
    llm_calls_total.labels(model=..., status=status).inc()
    llm_latency_seconds.labels(model=...).observe(time.time() - start)

问题 3：不 reset ContextVar

同一个 async task 处理下一个请求时 _trace_id.get() 返回上一个请求的 trace_id → 日志串数据。ContextVar set/reset 必须成对在 try/finally 里——和打开文件要关闭一样。

问题 4：_NoopMetric 不校验

职责不同——_NoopMetric 只保证"业务代码不崩"，不模拟真实行为。真实参数校验由 prometheus-client 本身负责（开发环境装了就能发现）。降级替换不需要复刻校验逻辑。

问题 5：指标异常排查

因果链：hits 暴跌 → context 几乎为空 → LLM 证据不足 → verifier 判 insufficient。LLM 正常 + 无报错 → 问题在检索层。

排查：先看 v_hits 和 k_hits 分别多少（定位向量还是关键词路），grep [hybrid] 日志，检查 vector_store.count() 和 FTS 表行数。

最可能：ChromaDB 被清空/损坏、Embedding API key 过期返回全零向量、ACL 变更过滤掉所有文档。

静默失败（检索返回空没有异常、只是结果为空）只有 metrics 能发现。

本节要点

  1. 三种指标各司其职：Counter 数次数、Histogram 看分布、Gauge 看瞬时状态。Labels 低基数，buckets 贴合 SLO
  2. trace_id 是排查生命线：ContextVar + TraceFormatter + TraceMiddleware → 一条 grep 看全链路
  3. 可观测性是旁路不是主路：no-op 降级 + except:pass。绝不让观测代码阻断业务
返回路线目录