- 引言 —— 有仪表盘,却不知道为什么慢
- 先定顺序
- 第一阶段 —— 光靠自动埋点能走多远
- 第二阶段 —— resource 属性事后没法补救
- 第三阶段 —— 上下文传播断裂的四个地方
- 第四阶段 —— 手动 span 只加在 self time 大的地方
- 第五阶段 —— 为什么要在应用和后端之间放一个 collector
- 埋点把应用搞坏的那些方式
- 结语 —— 埋点的价值来自 trace 的完整性,而不是 span 的数量
引言 —— 有仪表盘,却不知道为什么慢
订单 API 的 p99 是 1.4 秒。Grafana 上已经有 CPU、内存、请求数、错误率的面板,而且全是绿的。数据库的仪表盘也正常。可用户说慢,我们却不知道是哪段代码用掉了这 1.4 秒。
在这种状态下需要的不是再加一个面板,而是埋点。埋点是让代码自己说清楚「发生了什么、什么时候、花了多久」的工作,而 OpenTelemetry 就是把这种「说法」的格式和传输协议标准化的项目。
本文会把一个服务从头到尾埋点一遍。示例用的是 Python 的 FastAPI 服务,但这个顺序和语言无关。验证基准是截至 2026 年 7 月的 OpenTelemetry Collector v0.157.0、Semantic Conventions v1.43.0、Python SDK 1.3x 系列。语义约定里仍有一些字段名还在变动,所以属性名最好始终去对应版本的 Semantic Conventions 注册表 核实一遍。
先定顺序
埋点失败的团队几乎都以同一种方式失败:先在代码里插手动 span,两周后 span 有了 300 个,trace 却依然在服务边界处断裂。
真正能跑通的顺序是这样的。
| 阶段 | 要做的事 | 花费时间 | 跳过这一步会怎样 |
|---|---|---|---|
| 1 | 打开自动埋点,确认 trace 能到达后端 | 半天 | 之后所有排查都会变成猜测 |
| 2 | 定下 resource 属性(service.name 等) | 半天 | 事后再改会切断和历史数据的联系 |
| 3 | 验证跨服务边界的传播是否存活 | 1 天 | span 加得再多,trace 也还是碎的 |
| 4 | 只在 self time 大的区间加手动 span | 持续 | 自动埋点的盲区会永远留在那里 |
| 5 | 在前面加一层 collector,把加工和采样移交出去 | 1 天 | 每次改策略都要重新发布所有服务 |
关键在于第 3 步排在第 4 步之前。在传播还断着的情况下加手动 span,只是把已经碎掉的 trace 切得更碎。
第一阶段 —— 光靠自动埋点能走多远
在 Python 里,opentelemetry-instrument 这个启动器会在进程启动时把已安装的埋点包挂成钩子,不需要改代码。
pip install \
'opentelemetry-distro[otlp]' \
opentelemetry-instrumentation-fastapi \
opentelemetry-instrumentation-sqlalchemy \
opentelemetry-instrumentation-requests \
opentelemetry-instrumentation-redis \
opentelemetry-instrumentation-logging
# 自动探测已安装的埋点包并接上
opentelemetry-bootstrap --action=install
运行时只靠环境变量来控制,这正是自动埋点的核心优势。埋点配置不在代码里、而在部署清单里,所以改端点或采样率不需要走代码评审。
export OTEL_SERVICE_NAME=checkout-api
export OTEL_RESOURCE_ATTRIBUTES=service.version=2.7.1,deployment.environment.name=prod,service.namespace=commerce
export OTEL_EXPORTER_OTLP_ENDPOINT=http://otel-collector.observability.svc:4317
export OTEL_EXPORTER_OTLP_PROTOCOL=grpc
export OTEL_TRACES_SAMPLER=parentbased_always_on
export OTEL_PYTHON_LOG_CORRELATION=true
opentelemetry-instrument uvicorn app.main:app --host 0.0.0.0 --port 8000
建议从 parentbased_always_on 开始。一开始就打开按比例采样,一旦某条 trace 看不见,你根本分不清是埋点的问题还是采样的问题。等确认数据在正常流动之后,再去 collector 那里挂采样。
在这种状态下能拿到的,恰好是一样东西:网络边界。
SERVER checkout-api POST /v1/orders 1421ms
├─ CLIENT GET http://auth.internal/verify 31ms
├─ CLIENT SELECT carts WHERE id = ? 6ms
├─ CLIENT redis GET promo:rules:t-8871 2ms
├─ CLIENT POST http://payment.internal/charge 74ms
└─ (剩下的 1308ms 不属于任何一个 span)
最后一行就是全部信息。自动埋点用一个 1308ms 的空白告诉你哪里「不是」问题所在。这段空白叫 self time,第四阶段里也只在这里加手动 span。
自动埋点绝对看不到的东西
- 进程内部的 CPU 工作 —— 序列化、压缩、模板渲染、加密、图片处理
- 等锁和等连接池 —— 等待时间不会被算进拿到连接之后的那个查询 span 里
- GIL 竞争和事件循环延迟
- 没有对应埋点包的第三方 SDK 调用
- 业务逻辑里的分支 —— 评估了哪些规则、评估了多少条
第二阶段 —— resource 属性事后没法补救
resource 是一组描述「这份遥测数据是谁产生的」的属性。和 span 属性不同,resource 属性会附着在这个进程发出的每一个信号上。而且一旦定下来就很难改。一旦你改了 service.name,仪表盘、告警、服务拓扑图、和历史数据的联系会同时全部断掉。
# 最小集合 —— 没有这三个,就没法知道数据是从哪来的
OTEL_SERVICE_NAME=checkout-api
OTEL_RESOURCE_ATTRIBUTES=service.version=2.7.1,deployment.environment.name=prod
# 实务中额外有用的属性
OTEL_RESOURCE_ATTRIBUTES=service.version=2.7.1,\
deployment.environment.name=prod,\
service.namespace=commerce,\
service.instance.id=checkout-api-7d9f4b-x2k9m
在 Kubernetes 里不要把实例标识符写死,而是用 Downward API 注入。
# deployment.yaml
env:
- name: OTEL_SERVICE_NAME
value: checkout-api
- name: POD_NAME
valueFrom:
fieldRef:
fieldPath: metadata.name
- name: POD_NAMESPACE
valueFrom:
fieldRef:
fieldPath: metadata.namespace
- name: OTEL_RESOURCE_ATTRIBUTES
value: >-
service.version=2.7.1,
deployment.environment.name=prod,
service.namespace=commerce,
service.instance.id=$(POD_NAME),
k8s.namespace.name=$(POD_NAMESPACE)
命名约定上经常出错的地方有两个。
第一,环境属性的名字是 deployment.environment.name。旧名字 deployment.environment 已经不再使用了。名字一旦不同,就会变成两个互不相干的属性,而仪表盘的变量只会读其中一个。
第二,service.name 应该按服务来划分,而不是按部署单元。如果同一份代码为了金丝雀发布起了两份实例,两者都应该是 checkout-api,区分靠 service.version 或另一个属性来做。一旦把金丝雀实例命名成 checkout-api-canary,服务拓扑图里就会冒出一个幽灵节点。
| 属性 | 取值示例 | 基数 | 能不能改 |
|---|---|---|---|
| service.name | checkout-api | 服务数量 | 事实上不能 |
| service.namespace | commerce | 团队数量 | 很难 |
| service.version | 2.7.1 | 发布次数 | 每次发布都会变 |
| deployment.environment.name | prod | 3~5 | 不能 |
| service.instance.id | Pod 名字 | Pod 数量 | 每次重启都会变 |
service.instance.id 基数很高,但因为它是 resource 属性,在 trace 和日志里都没问题。不过一旦把这个属性原样提升成指标标签,时间序列就会按 Pod 数量成倍膨胀。通常的做法是只在指标这条流水线上、在 collector 里把它去掉。
第三阶段 —— 上下文传播断裂的四个地方
传播是产生 trace 的唯一机制。调用方把当前的 trace ID 和 span ID 放进 W3C 的 traceparent 请求头,接收方读出它、当作父级。验证这一点只需要一条命令。
# 冒充网关直接注入请求头,再到后端用这个 trace ID 查一遍
curl -sS -o /dev/null -w '%{http_code}\n' \
http://checkout-api.internal/v1/orders \
-H 'traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01' \
-H 'content-type: application/json' \
-d '{"cart_id":"c-1"}'
# 如果没有 span 挂在这个 trace ID 下面,就是下面四种情况之一
断裂 1 —— 线程池和 executor
这是最常遇到的一类。上下文存放在线程本地变量(或者 asyncio 的 contextvar)里,所以一旦把任务交给别的线程,这个上下文不会跟过去。
# 会断 —— worker 线程里没有上下文,所以会开启一条新的 trace
from concurrent.futures import ThreadPoolExecutor
pool = ThreadPoolExecutor(max_workers=8)
def enrich_all(items):
return list(pool.map(fetch_details, items))
# 能存活 —— 先捕获当前上下文,在 worker 内部重新激活它
from concurrent.futures import ThreadPoolExecutor
from opentelemetry import context as otel_context
pool = ThreadPoolExecutor(max_workers=8)
def _with_context(ctx, fn, *args):
token = otel_context.attach(ctx)
try:
return fn(*args)
finally:
otel_context.detach(token)
def enrich_all(items):
ctx = otel_context.get_current()
futures = [pool.submit(_with_context, ctx, fetch_details, it) for it in items]
return [f.result() for f in futures]
在 Java 里是 Context.current().wrap(runnable),在 Go 里是把 context.Context 当作 goroutine 的参数传下去,在 Node.js 里是 AsyncLocalStorage,起的都是同一个作用。各语言叫法不同,原理却完全一样。上下文不会自动跟着执行单元走,必须显式地搬运它。
断裂 2 —— 消息队列
队列既是进程边界,也是时间边界。它不像 HTTP 那样会自动带着请求头流动,所以必须把上下文直接注入到消息里。
from opentelemetry import propagate, trace
from opentelemetry.trace import SpanKind
tracer = trace.get_tracer("checkout", "2.7.1")
def publish_order(producer, order):
with tracer.start_as_current_span(
"orders publish", kind=SpanKind.PRODUCER
) as span:
span.set_attribute("messaging.system", "kafka")
span.set_attribute("messaging.destination.name", "orders")
headers = {}
propagate.inject(headers) # 把 traceparent 放进 dict
producer.send(
"orders",
value=order.to_bytes(),
headers=[(k, v.encode()) for k, v in headers.items()],
)
在消费者那一端,把提取出来的上下文当作父级来用。但如果是批量一次处理多条消息,父级只能有一个,这时要用 link。
from opentelemetry import propagate, trace
from opentelemetry.trace import SpanKind, Link
def consume_batch(messages):
links = []
for m in messages:
headers = {k: v.decode() for k, v in (m.headers or [])}
ctx = propagate.extract(headers)
sc = trace.get_current_span(ctx).get_span_context()
if sc.is_valid:
links.append(Link(sc))
with tracer.start_as_current_span(
"orders process", kind=SpanKind.CONSUMER, links=links
) as span:
span.set_attribute("messaging.batch.message_count", len(messages))
for m in messages:
handle(m)
如果队列等待时间有好几分钟,哪怕只有一条消息,也可以考虑用 link。如果按父子关系连起来,一条 trace 的持续时间就会因为等待时间而拉长,后端处理起来会很吃力。
断裂 3 —— 后台任务和调度器
像 cron、Celery beat、FastAPI 的 BackgroundTasks 这类和请求无关运行的任务,没有父级可言。这里常见的错误是硬把请求的上下文接上去。请求早就返回了响应、结束了,如果这时候还给那条 trace 挂上一个耗时 30 秒的子节点,请求延迟的统计数据就被污染了。
# 后台任务以新的根 trace 开始,导致它发生的那个请求只留一个 link
def schedule_reindex(cart_id):
origin = trace.get_current_span().get_span_context()
def run():
links = [Link(origin)] if origin.is_valid else []
with tracer.start_as_current_span(
"cart.reindex", kind=SpanKind.INTERNAL, links=links
) as span:
span.set_attribute("cart.id", cart_id)
reindex(cart_id)
background.add_task(run)
断裂 4 —— 会剥掉请求头的中间层
代理、WAF、API 网关、CDN 如果用白名单方式过滤请求头,traceparent 就会悄无声息地消失。日志里什么都不会留下,症状就是「trace 从网关之后重新开始了」。
# 确认实际到达的请求头最快的办法
kubectl -n commerce exec deploy/checkout-api -- \
sh -c 'timeout 20 tcpdump -A -s0 -i any "tcp port 8000" 2>/dev/null | grep -i traceparent'
# 或者给应用加一个临时端点,把收到的请求头原样返回
curl -s http://checkout-api.internal/__debug/headers \
-H 'traceparent: 00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01' | jq .
如果用的是 Envoy 或 Istio,确认 traceparent、tracestate、baggage 是否在允许列表里。如果混了一些还在用 B3 请求头的老服务,就把传播器配成多个。
OTEL_PROPAGATORS=tracecontext,baggage,b3multi
第四阶段 —— 手动 span 只加在 self time 大的地方
回到那 1308ms 的空白。适合加手动 span 的候选一共五类。
- 循环和批处理的边界 —— 把重复次数记成属性
- 缓存查询 —— 把命中与否记成属性,缓存效率就能直接在 trace 里看到
- 没有对应埋点包的第三方 SDK 调用
- 等锁、等队列、等连接池
- 长时间占用 CPU 的区间 —— 序列化、压缩、生成报表
from opentelemetry import trace
from opentelemetry.trace import Status, StatusCode
tracer = trace.get_tracer("checkout", "2.7.1")
async def apply_promotions(cart, tenant_id):
with tracer.start_as_current_span("checkout.apply_promotions") as span:
span.set_attribute("cart.item_count", len(cart.items))
span.set_attribute("tenant.id", tenant_id)
span.set_attribute("promotion.engine", "rules-v3")
try:
with tracer.start_as_current_span("promotion.load_rules") as load:
cached = await rules.from_cache(tenant_id)
load.set_attribute("cache.hit", cached is not None)
ruleset = cached or await rules.compile(tenant_id)
load.set_attribute("promotion.rule_count", len(ruleset))
with tracer.start_as_current_span("promotion.evaluate") as ev:
result = ruleset.evaluate(cart)
ev.set_attribute("promotion.evaluated", result.evaluated)
ev.set_attribute("promotion.matched", len(result.matched))
return result
except Exception as exc:
span.record_exception(exc)
span.set_status(Status(StatusCode.ERROR, str(exc)))
raise
加上这段埋点之后,同一个请求的 trace 会变成这样。
SERVER checkout-api POST /v1/orders 1421ms
├─ CLIENT GET http://auth.internal/verify 31ms
├─ CLIENT SELECT carts WHERE id = ? 6ms
├─ INTERNAL checkout.apply_promotions 1298ms
│ ├─ INTERNAL promotion.load_rules cache.hit=false 1241ms <-- 就是这里
│ └─ INTERNAL promotion.evaluate evaluated=812 54ms
├─ CLIENT POST http://payment.internal/charge 74ms
└─ (self time 12ms)
span 命名只要守住一条规则就行:名字必须是低基数的。 是 GET /v1/orders/:id,而不是 GET /v1/orders/A-99183,具体的值一律放进属性里。因为后端是靠 span 名字来分组、生成延迟统计和服务拓扑图的,一旦名字里混进了 ID,整个聚合视图就会垮掉。
第五阶段 —— 为什么要在应用和后端之间放一个 collector
SDK 直接发往后端也能工作。即便如此,放一个 collector 还是有五个理由。
- 不用重新发布就能改策略。 采样率、属性过滤、要保留什么,这些都是运行期间会持续调整的值。如果它们放在应用的环境变量里,就意味着要把 20 个服务全部滚动升级一遍。
- 把应用和后端故障隔离开。 后端变慢的时候,如果 SDK 的发送队列被填满,应用的内存就会往上涨,严重时还会影响请求处理。有 collector 挡在前面,这份压力就由它来承受。
- 可以更换后端。 指标发到 Prometheus、trace 发到 ClickHouse、日志发到 OpenSearch —— 按信号类型选不同的目的地,或者两套后端并行运行、逐步迁移,这些事都只需要改 collector 的配置文件一处就能完成。
- 在应用外部清除敏感信息。 token 或邮箱混进属性里的事故迟早会发生一次。在 collector 里预先设好防线,事故响应就变成改配置,而不是重新发布。
- 能做尾部采样。 要根据 trace 的最终结果来判断,span 就必须先汇聚到一处,而这个地方不可能是应用本身。
下面是一份设置了批量大小、重试、内存上限的最小配置。
# otel-collector.yaml —— 部署在和应用同一个节点上、或作为 sidecar 的 agent 层
receivers:
otlp:
protocols:
grpc:
endpoint: 0.0.0.0:4317
http:
endpoint: 0.0.0.0:4318
processors:
# 必须放第一位。一旦触及内存上限就拒绝接收,防止 collector 自己被拖死
memory_limiter:
check_interval: 1s
limit_percentage: 80
spike_limit_percentage: 20
# 把 Kubernetes 元数据附加成 resource 属性
k8sattributes:
auth_type: serviceAccount
extract:
metadata:
- k8s.namespace.name
- k8s.deployment.name
- k8s.pod.name
- k8s.node.name
# 清除敏感属性 —— 不用改应用,在这里挡住
attributes/redact:
actions:
- key: http.request.header.authorization
action: delete
- key: user.email
action: delete
- key: db.query.text
action: hash
# 永远放最后。减少网络往返
batch:
timeout: 5s
send_batch_size: 8192
send_batch_max_size: 16384
exporters:
otlp/gateway:
endpoint: otel-gateway.observability.svc:4317
tls:
insecure: true
sending_queue:
enabled: true
num_consumers: 10
queue_size: 5000
retry_on_failure:
enabled: true
initial_interval: 5s
max_elapsed_time: 300s
service:
telemetry:
metrics:
level: detailed
pipelines:
traces:
receivers: [otlp]
processors: [memory_limiter, k8sattributes, attributes/redact, batch]
exporters: [otlp/gateway]
metrics:
receivers: [otlp]
processors: [memory_limiter, k8sattributes, batch]
exporters: [otlp/gateway]
logs:
receivers: [otlp]
processors: [memory_limiter, k8sattributes, attributes/redact, batch]
exporters: [otlp/gateway]
processor 的顺序是有意义的。如果 memory_limiter 不放在第一位,过载时 collector 会被 OOM 杀死;如果 batch 不放在最后,它后面的 processor 会把批次重新拆开,批处理的收益也就没了。Collector 的官方文档也建议用同样的顺序。
把 collector 拆成两层是常见做法。应用旁边的 agent 只负责采集和附加元数据,网关层负责做尾部采样和后端路由。如果用了尾部采样,网关前面就需要按 trace ID 做路由。一旦同一条 trace 的 span 散落到不同的实例上,每个实例都只能拿自己手上的片段去判断,trace 就会被随机切碎。
埋点把应用搞坏的那些方式
只展示 happy path 的指南没什么用,这里整理一份实际会遇到的故障清单。
| 症状 | 原因 | 排查方式 | 应对 |
|---|---|---|---|
| 发布后内存持续上涨 | 后端响应延迟导致 exporter 的队列一直满着 | collector 的队列大小指标和应用的 RSS 走势 | 明确设置队列大小上限和丢弃策略,切换到经由 collector 转发 |
| span 只到了一部分 | 进程退出时没有 flush 就被杀掉了 | batch processor 的超时设置和退出钩子 | 退出时调用 shutdown,把容器的 terminationGracePeriod 调大 |
| 单个 span 有几百 KB | 把整个请求体塞进了属性里 | 后端的 span 大小分布 | 给属性值的长度设一个上限 |
| 延迟明显增加 | 同步的 exporter,或者在热循环内部创建 span | 埋点前后做基准测试 | 使用 batch processor,把 span 放在循环的边界,而不是循环内部 |
| trace 在网关处重新开始 | 代理剥掉了请求头 | 请求头抓包 | 把 traceparent 加入允许列表 |
| 服务拓扑图里出现幽灵节点 | 金丝雀实例用了单独的 service.name 部署 | 检查 resource 属性 | service.name 按服务维度固定下来 |
属性大小可以在 SDK 这一层设上限。默认值是属性数量 128 个、值长度不限,明确指定会更安全。
OTEL_SPAN_ATTRIBUTE_COUNT_LIMIT=64
OTEL_ATTRIBUTE_VALUE_LENGTH_LIMIT=2048
OTEL_BSP_MAX_QUEUE_SIZE=4096
OTEL_BSP_MAX_EXPORT_BATCH_SIZE=512
OTEL_BSP_SCHEDULE_DELAY=2000
退出时的 flush 行为因语言而异。Python 的自动埋点在正常退出时会关闭 provider,但如果是被 SIGKILL 杀掉,队列里剩下的 span 就没了。短生命周期的批处理作业,显式 flush 会更保险。
from opentelemetry import trace
def main():
run_job()
# 批处理作业必须显式清空队列
trace.get_tracer_provider().force_flush(timeout_millis=10_000)
trace.get_tracer_provider().shutdown()
判断埋点是否完成的标准
要通过下面这份清单,才能进入下一阶段。
- 随便挑一个生产请求,打开它的 trace,涉及的服务数量和 SERVER span 数量一致
- 根 span 的持续时间和网关访问日志里的响应时间在误差范围内一致
- 最大的 self time 占总时长不到 20%
- 从 trace 里复制 trace ID 拿去搜日志,能搜到这个请求的日志
- 把 span 名字按基数排序,排名前 20 的是路由模板,而不是 ID
- 跨消息队列的工作被串成了一条 trace 或者用 link 连了起来
- 重启 collector 不会影响应用
最后一项只有真正做过才知道。把 collector 杀掉一次,看看应用的错误率和延迟会不会跟着抖动。如果抖动了,说明 exporter 是同步的,或者队列策略设错了。
结语 —— 埋点的价值来自 trace 的完整性,而不是 span 的数量
一条只有 12 个 span、但完整的 trace,比一条有 500 个 span、却支离破碎的 trace 有用得多。投入的顺序也由此而定:传播不断是第一位,resource 属性一致是第二位,手动 span 排在最后。
现在就能做的、成本最低的验证,是打开一条生产环境的 trace,数一数 SERVER span 有几个。如果一个请求经过了六个服务,SERVER span 却只有两个,那这周该做的不是加手动 span,而是把另外四处的传播救活。
值得继续深入的资料。
현재 단락 (1/307)
订单 API 的 p99 是 1.4 秒。Grafana 上已经有 CPU、内存、请求数、错误率的面板,而且全是绿的。数据库的仪表盘也正常。可用户说慢,我们却不知道是哪段代码用掉了这 1.4 秒。