记录一下那天晚上的排查过程。同步请求的日志能串起来,但异步回调那一段找不到 trace_id,出问题时只能按时间猜是哪次请求触发的,一个退款回调查了两个小时。
刚开始盯着「回调服务是独立部署,没有接同一个采集端」,折腾了半个多小时,排掉了。
这类报错背后常见的原因有几处,逐个排除就行。trace 上下文存在线程本地变量里,异步任务拿不到。也可能是任务入队时没有把 trace 上下文一起序列化。
还有一种情况,日志格式里 trace_id 是可选项,缺了也不报错。
先看异步段日志里 trace_id 的空值比例
python -c "import json;d=[json.loads(l) for l in open('app.log')];print(sum(1 for x in d if not x.get('trace_id')), len(d))"
入队时把上下文写进消息头
python -c "print({'trace_id':'...','span_id':'...'})"
消费端从消息头恢复上下文
python -c "print('context=from_message_headers')"
末了跑一次端到端请求确认单 trace
python e2e_trace.py --query refund --expect 1
改完先别撤,确认这几项。一次退款请求在采集端只出现一条 trace,同步段和异步段共 7 个 span,按 trace_id 能直接查出完整链路。
补一句。异步是 trace 断裂的高发区,上下文必须在消息里显式传递;采集端要统一,两个系统各采各的永远拼不起来。同一份配置在测试环境跑通,不代表线上没事,两边的默认值经常不一样。
