《Python编程实战》17.1 OpenTelemetry 追踪

日志知道发生了什么、指标知道系统健不健康,追踪回答「一次请求慢在哪一段」。本节用 opentelemetry-api/sdk 1.45.1 真跑 TracerProvider、嵌套 span 的父子关系与耗时、手动埋点与装饰器、W3C traceparent 跨服务传播,并贴出 FastAPI 0.143.0 内建埋点导出的真实 SERVER span。

本节目标:用 opentelemetry-api/sdk 1.45.1 建立追踪,理解 span 的父子关系与耗时,掌握手动埋点、装饰器与 W3C 跨服务传播,并把追踪接进 FastAPI。
适用版本:Python 3.12+(实测 3.14.6);opentelemetry-api 1.45.1;opentelemetry-sdk 1.45.1;fastapi 0.143.0

17.1 OpenTelemetry 追踪

前面第 3 章讲了结构化日志和指标。日志回答「发生了什么」,指标回答「系统整体健不健康」,但两者都无法回答一个高频问题——「这一次请求,到底慢在哪一段?」。日志是一堆离散事件,指标是聚合数字,只有追踪能还原一次请求在服务内部的完整调用树。本节把追踪的第三块拼图补齐。

17.1.1 数据模型:Trace、Span 与 Context

追踪的全部概念可以压成一张表:

概念含义
Trace一次完整请求的调用链,由 trace_id 唯一标识
Span链路里的一段工作(一次查询、一次 RPC、一段计算)
Parent每个 span 指向上游 span,父子关系构成树
Context当前 span 的传播载体,决定新 span 挂在谁下面
Attributespan 上的键值对(db.system、http.route)
Eventspan 生命周期内的带时间戳事件(如「缓存未命中」)
StatusUNSET / OK / ERROR

关键约定是 W3C Trace Context:trace_id 是 128 位(32 位十六进制),span_id 是 64 位(16 位十六进制)。这个格式是跨语言、跨厂商统一的——Python 服务发出的 traceparent 头,Go 或 Java 服务能直接读懂并续接同一条链路。

17.1.2 最小可跑:Provider + Processor + Exporter

追踪的三件套是:TracerProvider(工厂与配置中心)、SpanProcessor(把结束的 span 送去导出)、Exporter(真正写出去)。最小可用组合是 SimpleSpanProcessor + ConsoleSpanExporter,把 span 打到标准输出:

from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import SimpleSpanProcessor, ConsoleSpanExporter

provider = TracerProvider()
provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter()))
trace.set_tracer_provider(provider)

tracer = trace.get_tracer("shop.orders")

with tracer.start_as_current_span("handle_request") as span:
    span.set_attribute("http.method", "GET")
    with tracer.start_as_current_span("db.query") as child:
        child.set_attribute("db.system", "postgresql")
        child.set_status(trace.Status(trace.StatusCode.OK))
{
    "name": "db.query",
    "context": {"trace_id": "0xd882ad9e7b99b1842a34d614a18f3450",
                "span_id": "0x03a982b08fbcdc03"},
    "parent_id": "0xda5cc520c31779af",
    "status": {"status_code": "OK"},
    "attributes": {"db.system": "postgresql",
                   "db.statement": "SELECT * FROM orders WHERE id=%s"}
}
{
    "name": "handle_request",
    "context": {"trace_id": "0xd882ad9e7b99b1842a34d614a18f3450",
                "span_id": "0xda5cc520c31779af"},
    "parent_id": null,
    "status": {"status_code": "UNSET"},
    "attributes": {"http.method": "GET", "http.route": "/orders/{order_id}"}
}

(为便于阅读,省略了 links、events、start_time/end_time、resource 等空或冗余字段,context 内的键值做了换行。)两点值得注意:db.query 的 parent_id 正好等于 handle_request 的 span_id,父子关系就是这么建立的;两个 span 的 trace_id 完全相同。实测中 resource.service.name 还是 unknown_service:python,因为没配 Resource——生产上必须显式设置,否则采集端无法区分服务。

17.1.3 嵌套 span:父子关系与耗时

start_as_current_span 把新 span 设为「当前 span」,退出时自动结束并恢复上一个。嵌套几层,就得到几层的调用树。给每段加上 sleep,看耗时如何层层包含:

import time
from opentelemetry.sdk.trace.export.in_memory_span_exporter import InMemorySpanExporter

exporter = InMemorySpanExporter()
provider = TracerProvider()
provider.add_span_processor(SimpleSpanProcessor(exporter))
trace.set_tracer_provider(provider)
tracer = trace.get_tracer("shop.orders")

@tracer.start_as_current_span("query_cache")
def query_cache():
    time.sleep(0.01)

@tracer.start_as_current_span("fetch_order")
def fetch_order():
    query_cache()
    time.sleep(0.02)

with tracer.start_as_current_span("handle"):
    fetch_order()

for s in exporter.get_finished_spans():
    print(f"{s.name:14s} parent={s.parent_id} "
          f"duration={(s.end_time - s.start_time) / 1e6:.1f}ms")
query_cache    parent=0x85309615faac6d02 duration=12.5ms
fetch_order    parent=0x9f0cb1b26f26a413 duration=34.3ms
handle         parent=None             duration=34.3ms

耗时是层层包含的:fetch_order 约 34ms,其中 12.5ms 花在它调用的 query_cache 上;handle 又几乎等于 fetch_order。这正是追踪的核心价值——总耗时不用猜,树状展开就知道时间花在哪个子段。InMemorySpanExporter 把 span 存在内存里,是测试断言埋点是否正确的常用手段。

17.1.4 手动埋点的三个动词:attribute、event、status

埋点无非三件事,对应三个 API:

动作API用途
标注维度span.set_attribute(key, value)记录可检索的键值(订单号、金额、路由)
记录时刻span.add_event(name, attributes)标注 span 内的重要瞬间(缓存未命中、重试)
标记结果span.set_status(Status(...))OK / ERROR
with tracer.start_as_current_span("create_order") as span:
    span.set_attribute("order.amount", 99.9)
    span.add_event("inventory_reserved", {"sku": "A-1", "qty": 2})
    span.set_status(trace.Status(trace.StatusCode.OK))
name=create_order status=OK events=['inventory_reserved'] attrs={'order.amount': 99.9}

事件的 attributes 里还能塞 sku、qty 这类业务字段,在追踪面板上点开这个 span 就能看到「下单前预留了哪个 SKU 几件」。但属性不是越多越好:高基数维度(用户 ID、原始 SQL)会显著抬高存储成本,只放排障真正需要的。

17.1.5 装饰器:给函数套上 span,异常自动记

每次都写 with tracer.start_as_current_span(...) 很啰嗦。tracer.start_as_current_span 本身就是装饰器,直接套在函数上即可:

@tracer.start_as_current_span("charge_card")
def charge_card(amount: float) -> str:
    time.sleep(0.05)
    return f"charged {amount}"

@tracer.start_as_current_span("create_order")
def create_order() -> str:
    return charge_card(99.9)

装饰器默认开启 record_exception=True 与 set_status_on_exception=True,所以函数抛异常时无需手写 try/except,span 会自动记下异常事件并把状态置为 ERROR:

try:
    with tracer.start_as_current_span("risky") as span:
        raise ValueError("boom")
except ValueError:
    pass
status: ERROR | events: [('exception', 'ValueError')]

装饰器适合「一整个函数就是一个 span」的场景;如果函数内部还要再细分(比如一次函数里既查缓存又查库),就用 with 块手动划分更灵活。两者可以混用——装饰器的 span 是 with 块 span 的父节点。

17.1.6 跨服务传播:注入与提取 traceparent

单服务内的链路叫「追踪」,跨服务还能连起来才叫「分布式追踪」。机制是 W3C 的 traceparent HTTP 头。上游在发请求前注入 context,下游收到请求后提取它,于是两边共享同一个 trace_id:

from opentelemetry.trace.propagation.tracecontext import TraceContextTextMapPropagator

propagator = TraceContextTextMapPropagator()

with tracer.start_as_current_span("gateway.call"):
    carrier = {}
    propagator.inject(carrier)          # 注入到「请求头」
    print("注入的头:", carrier)
    incoming = carrier                  # 模拟下游收到同样的头

ctx = propagator.extract(incoming)      # 下游提取
with tracer.start_as_current_span("downstream.handle", context=ctx) as span:
    print("downstream trace_id:", format(span.get_span_context().trace_id, "032x"))
    with tracer.start_as_current_span("downstream.db"):
        pass
注入的头: {'traceparent': '00-707def2b3c09f798e1ff19a1384a1e36-0c31e3447d193fed-03'}
downstream trace_id: 707def2b3c09f798e1ff19a1384a1e36
gateway.call      trace=0x707def2b.. parent=None
downstream.handle trace=0x707def2b.. parent=0x0c31e3447d193fed
downstream.db     trace=0x707def2b.. parent=0x6df614f5bc6fcf57

traceparent 的格式是 00-<trace_id>-<span_id>-<flags>:版本号、32 位 trace_id、16 位父 span_id、采样标志。下游 downstream.handle 的 parent_id 正是上游 gateway.call 的 span_id——跨进程的父子关系被接上了。实际项目里不用手写,HTTP 客户端/服务端库会自动注入和提取;但理解这层机制,才能在「链路断了」时判断是哪个环节没透传 header。

17.1.7 FastAPI 集成:内建埋点 + 手动补业务 span

FastAPI 0.143.0 起内置了 OpenTelemetry 埋点:只要全局 TracerProvider 已设置,一个什么都不传的 FastAPI() 就会自动为每个请求生成 SERVER span 和依赖/序列化等内部 span。实测如下:

from fastapi import FastAPI
from fastapi.testclient import TestClient

app = FastAPI()                       # 无需任何中间件

@app.get("/orders/{order_id}")
def get_order(order_id: int):
    return {"order_id": order_id}

TestClient(app).get("/orders/7")
print("自动生成的 span:", [s.name for s in exporter.get_finished_spans()])
自动生成的 span: ['fastapi.dependencies', 'fastapi.endpoint', 'fastapi.serialization', 'GET /orders/{order_id}']

其中根 span 是标准语义的 SERVER span,实测导出的结构:

{
    "name": "GET /orders/{order_id}",
    "kind": "SpanKind.SERVER",
    "parent_id": null,
    "attributes": {
        "server.address": "testserver",
        "server.port": 80,
        "url.path": "/orders/7",
        "url.scheme": "http",
        "http.request.method": "GET",
        "network.protocol.version": "1.1",
        "http.route": "/orders/{order_id}",
        "http.response.status_code": 200
    }
}

(省略了 context、时间戳与 resource 字段。)注意 http.route 是路由模板 /orders/{order_id} 而不是真实路径——这与第 3.3 节「标签基数」的教训一致,采集端按模板聚合才不会序列爆炸。内建埋点覆盖了 HTTP 层,但业务语义要靠手动补:在路由函数里再开一个 span 包住数据库查询,它就会自动挂在 SERVER span 之下。

如果想让业务完全自控,可以关掉内建埋点、改用自己写的 ASGI 中间件(本机实测的 telemetry={"tracing": False} 确实能让 span 数归零):

from opentelemetry.trace import SpanKind
from opentelemetry.trace.propagation.tracecontext import TraceContextTextMapPropagator

propagator = TraceContextTextMapPropagator()

@app.middleware("http")
async def trace_middleware(request, call_next):
    parent = propagator.extract(dict(request.headers))     # 提取上游 traceparent
    route = request.scope.get("route")
    name = getattr(route, "path", request.url.path)
    with tracer.start_as_current_span(name, context=parent, kind=SpanKind.SERVER) as span:
        span.set_attribute("http.request.method", request.method)
        response = await call_next(request)
        span.set_attribute("http.response.status_code", response.status_code)
        return response

说明:opentelemetry-instrumentation-fastapi 与 OTLP exporter 本机未安装,上面用的是 FastAPI/Starlette 内建埋点与 SDK 自带 exporter,均为实测。Starlette 该中间件在其源码中标注为 experimental,API 可能在小版本变动,升级前请核对版本说明。

17.1.8 导出与采样:BatchSpanProcessor 与采样器

生产上不能每个 span 都同步打印——SimpleSpanProcessor 会阻塞请求路径。换成 BatchSpanProcessor,它攒够一批(默认约 5 秒或若干条)再统一导出:

from opentelemetry.sdk.trace.export import BatchSpanProcessor

bsp = BatchSpanProcessor(exporter)
provider.add_span_processor(bsp)

with tracer.start_as_current_span("quick_op"):
    pass

print("导出前可见 span:", len(exporter.get_finished_spans()))
provider.force_flush()                          # 强制立即导出
print("force_flush 后可见 span:", len(exporter.get_finished_spans()))
导出前可见 span: 0
force_flush 后可见 span: 1

span 结束后并不会立刻出现,必须等批次触发或手动 force_flush()——进程退出前务必 flush,否则最后一批 span 会丢。高流量下全量采样成本过高,用采样器按比例丢弃:

from opentelemetry.sdk.trace.sampling import TraceIdRatioBased, ParentBased

provider = TracerProvider(sampler=ParentBased(TraceIdRatioBased(0.5)))
200 个 span 中被采样: 108 ≈ 54%

TraceIdRatioBased(0.5) 按 trace_id 的哈希决定是否采样(同一 trace 内决策一致),外层 ParentBased 保证「父被采样则子也采样」,避免链路只留下半截。实测 200 个 span 采到 108 个,符合 50% 的期望。

17.1.9 落地取舍

决策点建议
埋点粒度HTTP 入口 + 数据库/缓存/外部 RPC,业务函数按需
属性选择放低基数、可聚合的维度;高基数 ID 交给日志
导出方式生产用 BatchSpanProcessor,退出前 flush
采样高流量用比例采样 + ParentBased;关键链路可强制采样
服务标识必须设置 Resource 的 service.name

OTLP Collector 的部署与 OTEL_EXPORTER_OTLP_ENDPOINT 等环境变量配置属于运维侧,本机无 Collector,未实测。想更系统地了解微服务下的可观测性落地,可延伸阅读 Python 微服务架构 。

小结

  • 追踪的数据模型是 Trace → Span 树,trace_id 贯穿整条链路,parent_id 定义父子关系。
  • 三件套:TracerProvider(配置)+ SpanProcessor(导出时机)+ Exporter(写出目标);ConsoleSpanExporter 便于本地调试。
  • start_as_current_span 支持 with 块与装饰器两种写法,装饰器自动记录异常并置 ERROR;耗时在嵌套结构里层层包含,一眼定位慢段。
  • 跨服务靠 W3C traceparent 头注入/提取 context,下游 span 的 parent_id 接上上游的 span_id。
  • FastAPI 0.143.0 内置 OpenTelemetry 埋点,设置全局 Provider 即自动生成 SERVER span(http.route 用路由模板);业务语义仍需手动补 span。
  • 生产用 BatchSpanProcessor + 采样器,退出前 force_flush(),并务必设置 Resource 的 service.name。

有了链路,我们知道「慢在哪一段」;但要知道「为什么报错」,还得回到日志。下一节把结构化日志接进聚合链路,并让日志通过 trace_id 直接跳到对应的追踪。

阅读导航:上一节:压测、容量评估与限流降级 · 下一节:日志聚合与告警 。

继续阅读

探索更多技术文章

浏览归档,发现更多关于系统设计、工具链和工程实践的内容。

全部文章 返回首页

「python」更多文章

  1. 《Python高级编程》目录
  2. 《Python高级编程》11.3 PEP 流程与版本迁移策略
  3. 《Python高级编程》11.2 嵌入式与自由线程运行时