Python OpenTelemetry 生产环境分布式追踪实战:跨服务接口从 3 秒到 300ms,一次链路卡顿的完整排查(2026)
开头:周五晚上十点的告警
上周五晚上十点,钉钉群里弹了条告警,我看了一眼血压就上来了:下单接口 p99 延迟从平时的 300ms 直接飙到 3 秒,而且只在新偶发时段出现。我第一反应是数据库慢,结果点开 MySQL 一看,慢查询里干干净净。CPU 也不高,内存也正常。
最气人的是——你在生产上用 top、用 free、用 iostat 看了一圈,全是”正常”。这就是典型的分布式系统的病:病根不在任何一台机器上,而是藏在一次请求穿越多个服务的过程里。
单机排查工具(top/strace/perf)看的是”一台机器在干嘛”,但要回答“一次完整请求在系统里到底花了多少时间、卡在哪一环”,你必须得看链路。这次我用了 OpenTelemetry,前后 40 分钟,把 800ms 的真凶揪出来了。
OpenTelemetry 是什么,为什么不用 X
一句话:OpenTelemetry(简称 OTel)是一个开源的、厂商中立的可观测性框架,帮你把”请求在代码里穿越的所有痕迹”收集起来,导出到 Jaeger、Zipkin、Prometheus、Datadog 这类后端。
你可能想问:项目里有现成的日志(Logger)啊,为啥还要追踪?这就是最容易踩的认知误区。日志回答的是“我在某个时刻做了什么”,但它是离散的——你没法把网关的一条日志、订单的一条日志、支付的一条日志按同一次请求串起来。而追踪(tracing)的核心就是上下文传播(context propagation):给一次请求发一个 trace_id,让它穿越所有服务,把全部 span 按时间线拼成一张完整的瀑布图。
为什么不自己写日志中间件?我见过好几个团队手撸过”给每个请求加 request_id”的轮子,最后全烂在手上——要么没把 id 传给下个服务,要么异步线程里上下文丢了。OTel 把这事标准化了,而且有自动埋点,不用你手写。
Step 1:安装与初始化
Python 这侧最省事,用官方 SDK 加自动埋点包:
pip install opentelemetry-distro opentelemetry-exporter-otlp-proto-grpc
# FastAPI / requests / psycopg 这类常用库的埋点,按需装:
pip install opentelemetry-instrumentation-fastapi opentelemetry-instrumentation-requests opentelemetry-instrumentation-psycopg2
初始化也就几行,重点是配置导出端点和 service_name。service_name 是区分服务的关键,别懒,都叫什么 “backend” 将来排查能把你气死:
from opentelemetry import trace
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
provider = TracerProvider()
provider.add_span_processor(BatchSpanProcessor(
OTLPSpanExporter(endpoint="http://otel-collector:4317")))
trace.set_tracer_provider(provider)
踩过的坑:endpoint 填的是 Collector 的地址,4317 是 gRPC 端口、4318 是 HTTP。填错端口它不报错,就是静默丢数据——我当时排查半天以为是埋点没生效,结果是端口写成了 HTTP 的,白折腾。
Step 2:自动埋点,几乎零侵入
我最喜欢 OTel 的一点就是自动埋点。上面的 FastAPI 包注册好后,你的每个路由就是一个 span,连 HTTP 请求、数据库查询都自动带上。手动加一点就能把”业务含义”标出来:
from opentelemetry import trace
tracer = trace.get_tracer("order-service")
@tracer.start_as_current_span("check_stock")
def check_stock(order_id):
# 你的业务逻辑
return True
看到没,一个装饰器就把某个函数变成独立 span,在瀑布图里能单独看到它的耗时。这对我这种懒人太友好了——不用改业务代码多少。
Step 3:上下文传播,跨服务串起来
这一步是整个追踪能打通的关键。如果两个服务之间不传播 context,那每个服务的 trace 都是孤岛,你在 Jaeger 里看到的是一堆互不相关的碎片。
HTTP 场景,OTel 的 requests 埋点会自动注入 W3C 标准的 traceparent 头,下游服务自动解析。但如果你用消息队列(Kafka/RabbitMQ),或者用了自定义 HTTP client,就得手动传:
from opentelemetry import context, trace
from opentelemetry.propagate import inject
# 发送消息前注入上下文
ctx = context.get_current()
carrier = {}
inject(carrier, ctx) # 把 traceparent 等放进 carrier
# 然后把 carrier 塞进你的 MQ header 发出去
# 消费侧,接收后提取
from opentelemetry.propagate import extract
ctx = extract(carrier)
# 用 ctx 包裹后续业务逻辑
这个坑我要刻骨铭心地记下:我们那个”800ms”的真凶,就跟跨服务上下文丢失有关,下面案例里细说。
Step 4:把日志和链路串起来(correlation)
光有链路还不够,你会想通过 trace_id 去翻对应的日志。做法是在日志里自动加上 trace_id 和 span_id。配个 filter 就能做到:
import logging, contextvars
from opentelemetry import trace
ctx_trace_id = contextvars.ContextVar("trace_id", default="")
ctx_span_id = contextvars.ContextVar("span_id", default="")
class TraceFilter(logging.Filter):
def filter(self, record):
span = trace.get_current_span()
sc = span.get_span_context()
record.trace_id = sc.trace_id if sc and sc.is_valid else "N/A"
record.span_id = sc.span_id if sc and sc.is_valid else "N/A"
return True
这样你在 ELK / Loki 里搜某个 trace_id,就能把整条链路的日志全捞出来。这正好跟我那篇写过的 Python 结构化日志实战呼应——日志给出”为什么”,链路给出”在哪里多花的时间”,两个一配合,排查效率翻倍。
Step 5:部署 OTel Collector(Linux 侧)
Python 进程不直接连 Jaeger,而是把数据发给 Collector,再由 Collector 统一转储。好处是解耦,而且 Collector 能帮你做采样、缓冲、过滤。生产上我推荐容器化部署:
# docker-compose.yml
services:
otel-collector:
image: otel/opentelemetry-collector-contrib:latest
command: ["--config=/etc/otelcol/config.yaml"]
volumes:
- ./otel-config.yaml:/etc/otelcol/config.yaml
ports:
- "4317:4317" # gRPC
- "4318:4318" # HTTP
配置里关键两块——接收器和导出器。下面这段把 gRPC/HTTP 数据转给 Jaeger:
receivers:
otlp:
protocols:
grpc:
exporters:
jaeger:
endpoint: jaeger:14250
tls: { insecure: true }
processors:
batch:
service:
pipelines:
traces:
receivers: [otlp]
processors: [batch]
exporters: [jaeger]
Linux 侧我顺带踩了个坑:容器里 endpoint: jaeger:14250 用的是 docker 内网域名,得保证 jaeger 服务也在同一 network 里,否则 Collector 日志一直报 connection refused。排查手段还是老一套,ss -tlnp 看端口、docker logs 看报错。
真实案例:把 800ms 的真凶揪出来
回到开头那次告警。我把 FastAPI 埋点部署好后,在 Jaeger 里打开那条 3 秒的 trace,瀑布图一看,问题全出来了。
跨服务链路耗时分布(修复前):
你看这张图,从左到右五个服务里,order 服务一个 span 就吃了 820ms,其他全都是几十毫秒。按理说这不是一目了然吗?但真相远不止于此。
我点开 order 那个 820ms 的 span 往下钻,发现它内部又被拆成一个巨长的同步等待——原来 order 服务调用支付服务时,用的是同步 HTTP 调用,而且中间隔着两层无关紧要的业务逻辑,导致一次调用链被拉得很长。更致命的是,上游网关那侧因为上下文没传干净,部分请求把 trace 断掉了,我在 Jaeger 里看得到”漂移”的瀑布。
根因就是三件事叠在一起:同步阻塞调用 + 业务逻辑塞在了 HTTP 调用路径上 + 上下文传播在异步环节丢失。
修复方向很直接:把同步调用改成异步/并行、把非必要的业务逻辑挪出请求主链路、补齐 MQ 和线程池的上下文传播。改完之后 order 的 p99 直接降到 95ms,整条链路从 3 秒回到 300ms 出头。
我常说,这种”你在单机上看不出问题,一上链路就现原形”的故障,是最考验工程体系的东西。真到那一天,你会庆幸自己提前接了它。
采样与成本控制
全量上报数据量大到能把你后端打挂。官方默认就是按比例采样(比如 10%)。生产上可以做得更聪明:头部采样(head-based sampling)在入口处决定整条链路是否上报,或者尾部采样(tail-based sampling)等链路走完再看是否值得记。下面这段是常用的 p99 延迟采样:
processors:
tail_sampling:
policies:
- name: keep-slow-traces
type: latency
latency:
threshold_ms: 500
- name: keep-errors
type: status_code
status_code:
status_codes: [ERROR]
这样一分钟上千条正常请求,只会留下少数几条慢的和有错误的,成本能砍到一个很舒服的量级。
FAQ
Q: OTel 数据不上报,不报错,怎么回事?
先查 endpoint 端口是不是写错(4317 gRPC / 4318 HTTP),再确认 Collector 是否在同一 network、端口是否可达。可以临时用 curl -v telnet://otel-collector:4317 测联通,或者看 Collector 容器日志有没有 connection refused。
Q: 为什么 Jaeger 里每个服务是孤岛,串不成一条链?
上下文没传播出去。HTTP 场景要确保用到被埋点的 requests/httpx;自定义 client 或消息队列要手动 inject/extract carrier(W3C traceparent)。还要检查下游服务是不是也正确初始化了 OTel。
Q: 异步代码(asyncio/ThreadPool)里上下文丢了怎么办?
asyncio 里 OTel 用 contextvars 自动传播,一般没事;但跨线程(ThreadPoolExecutor)需要手动传递 context,用 context.set_value() 或者在任务里重新注入。这也是我们那次 800ms 故障的一环。
Q: OTel 会拖慢性能吗?
轻微。埋点开销主要是生成 span 和序列化,配合 BatchSpanProcessor(批处理,而非同步逐一上报)基本可忽略。真正要控的是上报数据量,按需采样即可。
Q: 能和日志、指标一起用吗?
可以,这就是 OTel 说的”Three Pillars”。同一个 trace_id 能串联日志和指标,配合 ELK/Loki 搜索,就能从”哪慢”定位到”为什么慢”。
总结
这次 40 分钟的排查,让我彻底信了一句话:单机工具看”机器”,分布式追踪看”链路”。两者缺一不可,但后者往往才是跨服务卡顿的真凶所在地。
排查流程速记:
- ① 接口慢先看数据库慢查询、MySQL 慢日志(排除 DB)
- ② 用 OTel 打开对应 trace,看整条链路瀑布图
- ③ 定位耗时最高的 span,往里钻到底层调用
- ④ 重点检查同步阻塞、业务逻辑塞在主链路、上下文传播
- ⑤ 修复后复测 p99,落回正常水位
推荐搭配阅读:Python 性能剖析三件套:py-spy、Scalene、memray 实战对比、Python FastAPI 性能调优实战、生产环境死锁排查完全指南 —— 组成一个完整的”生产排查”内容集群。
