接口偶发超时如何做全链路排查?从时间预算到尾延迟
偶发超时难查,是因为平均指标正常、日志分散,而且调用方记录的 3 秒可能包含排队、DNS、建连、连接池等待和服务端执行。第一步是建立统一时间线,而不是逐台机器翻日志。
先定义超时发生在哪一层
区分客户端 deadline、网关超时、连接超时、读超时、数据库 statement timeout 和业务主动取消。记录错误类型、目标地址、traceId、实例、attempt、剩余预算。SocketTimeoutException 只表示等待读取超时,不证明服务端没执行。
用 Trace 分解 3 秒
一个完整 span 应覆盖:入口排队、业务方法、连接池获取、DNS/连接/TLS、下游响应、序列化。若调用方 span 3 秒而服务端 span 50ms,缺失时间可能位于建连、网络、负载均衡排队,或两端时钟偏差、采样和埋点空白。单个 span 的 duration 通常由本进程时钟计算,但跨进程瀑布图仍可能因时钟不同步错位。Trace 不是绝对真相,要与指标和日志交叉验证。
分层检查
应用层:线程池 active/queue/reject、连接池 pending、请求体大小、锁竞争。JVM:暂停时间、分配速率、CPU throttling。数据库:锁等待、慢 SQL、连接获取。网络:重传、丢包、DNS 延迟、NAT/负载均衡连接表。下游:同一时间窗口 P99 和熔断状态。
ss -s
nstat -az
jcmd <pid> JFR.start name=timeout settings=profile duration=60s filename=/tmp/timeout.jfr
这些命令要在对应 Linux/容器网络命名空间内执行;nstat 不一定包含在精简镜像中,可使用节点或经审批的诊断容器读取网络计数器。不要为了排障临时安装来源不明的工具,也不要把一次累计重传计数当作当前请求的直接因果证据,应比较时间窗口内增量。
容器 CPU throttling 是常见盲点:平均 CPU 不高,但 quota 周期内被限流,延迟呈周期性尖峰。检查 container_cpu_cfs_throttled_seconds_total。
一个真实形态的案例
接口每隔约 30 分钟出现 2–3 秒尖峰。Trace 显示业务代码未开始,下游无请求。连接池 pending 同期上涨,数据库连接存活时间集中到期,池在短时间内批量重建连接,DNS 偶发变慢。将连接最大生命周期加入随机抖动、预热最小空闲连接并修复 DNS 后,尖峰消失。
这说明“数据库接口超时”不等于慢 SQL。观察点必须覆盖获取连接之前。
采样如何避免漏掉长尾
固定 1% 头部采样可能漏掉稀有错误。可在 OpenTelemetry Collector 等后端链路采用尾部采样,按最终错误或延迟决定是否保留;代价是 Collector 必须在决策窗口内缓存完整 trace,需要容量、分片一致性、丢弃指标和降级策略。也可以结合头部概率采样、错误日志与 exemplars,避免把全部压力压给尾采样。日志以 traceId 关联,但不要把用户 token、SQL 参数等敏感内容无条件写入。
验证假设
一次只改变一个关键变量,在预发注入延迟、连接过期、DNS 故障或 CPU 限流,确认能复现相同指标形态。相关性不是因果:某次 Full GC 与超时同时出现,不代表一定由 GC 导致,应比较暂停起止时间是否覆盖请求空白区间。
生产检查清单
- 各层 timeout/deadline 是否有明确名称和错误码?
- Trace 是否覆盖线程池与连接池等待,而非只包业务方法?
- 是否保留全部错误和长尾 trace?
- 采样策略是否有 Collector 容量、丢弃率和故障降级监控?
- 是否检查 GC 暂停、CPU throttling、DNS 和网络重传?
- 连接生命周期是否加入抖动,避免同步重建?
- 是否能通过故障注入复现指标指纹?
偶发超时的本质是寻找“时间花在哪里”。把端到端延迟拆成可度量区间,根因才会从猜测变成证据。