拓十年匠心定制 · 商业建站与技术教学双线并行 咨询热线:400-886-1026 service@lmnt.cn
ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

eBPF实战:Nginx P99延迟飙升真凶与排查记录

eBPF实战:Nginx P99延迟飙升真凶与排查记录

1. 事故现场:P99 莫名飙高,常规排查全部落空

1.1 故障现象与监控数据

那天晚上八点刚过,运维群里就炸了。图片上传大面积转圈,接口响应时间翻着跟头往上涨。我拉出监控一看,Nginx 网关层的 P99 延迟从平日的 40ms 左右直接飙到 600ms+,P999 更是偶发突破 2 秒。但诡异的地方在于:QPS 并没有明显增长,后端服务的延迟指标全部正常,数据库、缓存、上游应用一个都没报警。

这个组合非常反直觉。如果 Nginx 延迟高而下游正常,那问题大概率出在 Nginx 自己身上——要么是它的进程在被什么东西拖住,要么是内核协议栈在处理网络事件时出现了异常。但一台刚跑了几个月的 16 核机器,CPU 使用率才 20%,load average 也不高,怎么看都不像是资源耗尽的样子。监控界面上那个平滑的延迟曲线就像在嘲讽我:你平时不是吹自己懂内核吗?拿出证据来。

我先确认了一个关键信息:高延迟集中在几十到两百字节的小响应上,大响应反而正常。这很有价值。小响应按说一个 TCP 段就发完了,传输时间几乎可以忽略,延迟只会出在"从事件就绪到进程实际处理"这一段路径上。也就是说,要么是 Nginx 的 worker 没有被及时唤醒,要么是它醒了之后进不了临界区,要么是 socket 上有锁在打架。这三个方向的排查思路完全不一样。

1.2 常规三板斧为什么全部失效

按照以往经验,我先把常规手段走了一遍。ss -s看连接状态,TIME_WAIT 确实比平时多了一些,但没有出现端口耗尽、accept 队列溢出之类的典型异常;top盯了十分钟,用户态 CPU 稳定,软中断(si)偶尔冲到 5%,谈不上异常;nginx error.log干干净净,没有 upstream 超时、没有 worker 崩溃重启的记录。

接着上strace。这里有个很深的教训:strace 本身会放大延迟,尤其是在高频网络进程上,ptrace 的 stop/continue 机制会严重影响事件处理的实时性。我挂上去之后,延迟不仅没降,反而变得更糟,输出里也看不到明显的长阻塞——worker 进程大部分时间都待在epoll_wait里,偶尔有一些accept、read、write调用,单个系统调用的耗时都在微秒级,完全正常。

这恰恰说明问题不在用户态。系统调用返回都很快,但请求的整体延迟却很高,意味着时间消耗在"进程被唤起到真正执行"以及"两个系统调用之间的内核路径"上。这就像是餐厅里服务员点单很快,但菜从厨房端出来的时间莫名变长——而厨房里到底发生了什么,坐在大厅里的你根本看不见。tcpdump抓包也只能确认三次握手正常、客户端 ACK 正常,协议层面没有任何重传和乱序。

所有传统工具都指向"一切正常",但用户体验就是很差。这种时候我反而清醒了:不是没有问题,是观察的层面不对。

1.3 压测复现不了,说明问题藏在真实流量的特征里

为了验证,我让测试同事从压测机打了一波流量,QPS 直接压到正常峰值的两倍,结果延迟曲线纹丝不动,P99 依然稳定在四十毫秒出头。这个结果非常有信息量——它说明问题不是因为"量大",而是因为某种特定的流量特征触发了内核里的某个临界条件。

回想一下真实流量和压测流量的区别:压测用的是长连接,建立好连接后反复发请求;而真实业务里,图片上传和接口调用有大量短连接,每个请求都意味着一次完整的 TCP 握手,再加上一次主动 close,accept 队列和 SYN 队列在晚高峰会经受密集的"建连—断开—再建连"冲击。连接事件的处理路径和普通请求事件的处理路径,在内核里完全是两码事,它们要碰的锁也不一样。

到这里,常规排查已经走到头了。要往下挖,只能进内核看现场。正好,这类问题就是 eBPF 的主场。

2. 为什么这次要上 eBPF:用户态工具的天花板

2.1 从"进程视角"切换到"内核视角"

传统工具最大的问题在于视角。top看的是 CPU 占用,strace看的是系统调用,tcpdump看的是网络报文——它们都在描述"发生了什么",却回答不了"时间到底耗在了哪一行内核代码上"。

eBPF 不一样。它允许你在内核的函数入口、返回点、tracepoint 上挂载一段受限的虚拟机指令,在事件发生的瞬间记录现场,然后把数据聚合后送回用户态。这意味着你可以直接问内核:这个进程刚才在等什么锁?这个锁被谁持有?这个 worker 被唤醒之后多久才真正跑到 CPU 上?这些问题的答案,是任何用户态工具都给不了你的。

我打个比方。strace 相当于你站在公司门口统计员工几点进楼,能看出谁迟到了,但不知道迟到是因为地铁晚点、电梯排队还是路上买咖啡。eBPF 则像在每个电梯口、每个工位旁都装了一个摄像头,你不仅能看出迟到,还能还原出完整的路径。对于内核协议栈这种"进楼之后还有几百道工序"的场景,eBPF 几乎是唯一能全程跟拍的方案。

2.2 工具选型:bpftrace 负责快,BCC 负责深

eBPF 生态里有两套常用的前端,我这次都用上了。bpftrace适合现场快速打点,语法类似 awk,一行命令挂上 kprobe 就能看某个函数的延迟分布,适合"先确认方向"的阶段;BCC 则提供了一堆写好的工具脚本,比如offcputime、runqslower、funccount,它们能输出完整的调用栈和聚合统计,适合"深挖根因"的阶段。

环境方面,机器是 Ubuntu 20.04 定制的 5.15 内核,BTF 默认开启,BCC 装完直接就能用,不需要额外编译内核模块。这里插一句:现在跑生产环境的内核最好选择 5.10 以上且开启 CONFIG_DEBUG_INFO_BTF,这样各种 eBPF 工具开箱即用,省去很多兼容性折腾。如果你还在用 4.x 老内核,BCC 也能跑,但 CO-RE 的特性用不了,脚本要跟着内核版本改。

权限方面,要么 root,要么给进程配CAP_BPF+CAP_PERFMON。我图省事,直接在容器外以 root 跑的,但说实话在多人共用的机器上,建议用 capability 的最小化授权,别把 root 撒得到处都是。

2.3 观测目标设计:先量化、再抓栈、再做关联

eBPF 能观测的东西太多了,不加设计就上脚本,容易被海量输出淹没。我在动手之前先定了三个明确的问题:

  1. 一个请求从网卡中断到 Nginx 处理,延迟的大头到底在哪一段?
  2. 如果是 worker 被卡住了,卡在内核的哪个函数上?
  3. 如果是唤醒延迟,唤醒源是谁,调度延迟有多长?

带着这三个问题,我给自己设了个时间盒:每个问题最多花两分钟找证据,找不到就换下一个假设。事实证明,这个"先量化、再抓栈、再做关联"的节奏非常重要,它避免了在错误的方向上深挖。

3. 5分钟定位全流程:从 tcp_sendmsg 到 accept 锁竞争

3.1 第一分钟:排除 socket 发送路径

第一个要排除的是发送路径。虽然直觉上小响应不该慢,但内核里发送路径上有个东西可能拖时间:TCP 的 Nagle 算法和 cork 选项,或者 congestion control 的状态机在某些 sysctl 配置下表现异常。我直接用 bpftrace 挂了一下tcp_sendmsg的入口和返回,统计耗时分布:

bpftrace -e ' kprobe:tcp_sendmsg { @start[tid] = nsecs; } kretprobe:tcp_sendmsg /@start[tid]/ { @send_us = quantize((nsecs - @start[tid]) / 1000); delete(@start[tid]); }'

输出的直方图显示,tcp_sendmsg的 P99 耗时只有 30 微秒左右,大部分调用都在 15 微秒以内。这意味着数据进入内核协议栈之后,送到驱动队列的过程很顺畅,发送路径不是瓶颈。我再顺手挂了一下网卡驱动的ndo_start_xmit函数的延迟,同样在几十微秒量级。

好,发送路径干净。延迟不在"数据怎么发出去",那八成就在"连接事件怎么被处理"。方向开始向 accept 路径和 epoll 唤醒机制靠拢。

3.2 第二分钟:offcputime 抓出内核阻塞栈

接下来的两分钟是整次排查的转折点。我用 BCC 自带的offcputime工具,附加到所有 Nginx worker 进程上,采样 30 秒,看看这些进程在内核态被切换出去时,到底停在了哪些函数上:

/usr/share/bcc/tools/offcputime -K -p $(pgrep -d, nginx) 30 > offcpu.stack

-K表示只记录内核态栈,-p指定进程号集合。这个工具的原理是在finish_task_switch的 tracepoint 上工作,每当某个进程被切换出去,就记录下它从哪一行代码离开 CPU,然后聚合统计"离开 CPU 的总时长 × 次数"。

输出最有价值的一段长这样(做了简化):

lock_sock_nested+0x1b2 inet_csk_accept+0x1f8 do_accept+0x44 __x64_sys_accept4+0x18 do_syscall_64+0x38 entry_SYSCALL_64_after_hwframe+0x63 -- tid 15234 (nginx worker) -- total offcpu time: 4.7s

正常情况下降,Nginx worker 的内核态 offcpu 分布在epoll_wait的睡眠上,而lock_sock_nested这个名字的出现让我眼睛一亮。这是 socket lock 等待路径,说明有 worker 在等一把被别的上下文持有的 socket 锁。更关键的是比例:总 offcpu 时间是 12 秒,光这把锁的等待就占了 4.7 秒,接近 40%。在晚高峰窗口期,这个比例已经足以解释 P99 的飙升。

3.3 第三分钟:验证调度延迟,锁定"唤醒-运行"间隔

拿到了锁竞争的证据,我还想确认另一件事:是不是还有调度层面的延迟在叠加?因为单纯一把锁竞争的话,持锁方释放后等待方应该很快就能抢到,一般不至于产生几百毫秒的尖刺。除非持锁方本身被调度出去了,或者等待方被唤醒后排队排了很久。

这里我用了 bpftrace 直接跟踪sched_wakeup和sched_switch,计算 Nginx worker 从"被唤醒"到"真正上 CPU 运行"的间隔(runqueue delay):

bpftrace -e ' tracepoint:sched:sched_wakeup /args->pid == 15234/ { @wake_ns[tid] = nsecs; } tracepoint:sched:sched_switch /args->next_pid == 15234/ { if (@wake_ns[tid]) { @rdelay_us = quantize((nsecs - @wake_ns[tid]) / 1000); delete(@wake_ns[tid]); } }'

结果一片腥红:这个 worker 的唤醒-运行间隔 P99 高达 380ms,最夸张的一次接近 900ms。CPU 明明有大量空闲,但被唤醒的 worker 就是没被安排去运行——这不太像是单纯的 CPU 资源不够,更像是一种"局部拥挤"或"优先级/亲和性导致的不均衡"。

到这一步,整个问题的轮廓已经清楚了:worker 在处理连接时有相当概率要去抢一把 listen socket 上的锁;抢不到锁的时候,它回到睡眠态,而再次被唤醒后还会因为调度延迟多等几百毫秒。两段延迟叠加,就是用户感知到的"转圈"。

3.4 第四到五分钟:把锁的持有者找出来

最后一块拼图,是要搞清楚那把锁到底被谁拿着。我在lock_sock_nested的入口挂了一个 kprobe,专门记录锁地址和持有者的内核栈,同时又用kstack聚合了所有获取锁失败的调用点——其实更直接的方法是看持锁时间最长的栈。我用 BCC 的funclatency挂release_sock,从释放侧看锁被持有了多久:

/usr/share/bcc/tools/funclatency -i 10 -m release_sock -p $(pgrep -d, nginx)

输出显示,release_sock的调用绝大部分在 10 微秒以内,但有一小撮调用持锁时间超过 40ms。虽然 fanciful 比例不到 0.1%,但正是这一小撮在晚高峰被放大成了连锁反应。我再用trace功能把持锁超过 1ms 的调用栈捞出来看了一眼,看到的是inet_csk_accept→tcp_v4_syn_recv_sock→ 路由查找和内存分配的路径。也就是说,某个 worker 在 accept 一个全新连接时,如果路由表 cache miss 或者内存分配慢,会让它在持锁状态下停留很久;而这把锁又是全局共享的,其他 worker 和软中断路径全在排队。

到这里,从发问到拿全证据,我看了看表:差不多五分钟出头。方向已经完全明确。

4. 真凶复盘:共享 listen socket 的锁竞争与唤醒延迟

4.1 根因链条:epoll 唤醒、accept 锁、软中断三方拉扯

把证据串起来,真凶是这样一幅画卷:

Nginx 默认多个 worker 共享同一个 listen socket。每个新连接完成 TCP 握手后,内核要把它挂到 accept 队列上,并唤醒正在epoll_wait的 worker 来处理。这个过程中涉及两把关键锁:一把是 listen socket 本身的锁,保护 accept 队列和 socket 状态;另一把是 epoll 等待队列的锁,负责唤醒的分发。

平时这把锁每一瞬间就被人抢走,持有几微秒就释放,大家相安无事。但一旦某个 worker 在accept新连接时碰上了路由 cache miss、内存节点分配变慢这类偶发事件,持锁时间就会从微秒级涨到几十毫秒级。这个窗口期内,其他 worker 被唤醒后赶来抢锁,抢不到就被迫睡眠;而它们睡眠后要再次被唤醒,又得走一遍 epoll 的唤醒机制,叠加调度器的 runqueue 延迟。于是,一次本来 1ms 就能完成的请求处理,被拉到几百毫秒。

为什么压测复现不了?因为压测长连接没有大量 accept 事件,锁的竞争频率低,偶发的持锁慢根本触发不了临界条件。真实流量里大量短连接在晚高峰猛烈冲击 accept 队列,竞争概率被放大了几十倍,问题就暴露无遗。

4.2 为什么"CPU 很闲"却还有调度延迟

很多读者可能会困惑:CPU 总体负载不到 20%,为什么被唤醒的 worker 还要等几百毫秒才能上 CPU?这里有个容易忽略的细节:负载看的是全局平均,而调度看的是每个 CPU 各自的 runqueue。Nginx 配置了worker_cpu_affinity,worker 进程被钉在指定 CPU 上,这本来是降低缓存抖动的好实践,但也意味着:如果那个 CPU 上正好有软中断(ksoftirqd/cpu 的网卡收包处理)在持续占用,worker 即使被唤醒也只能排到队尾。

当晚的观测确实支持这一点:被拖住的 worker 恰好固定在软中断比较繁忙的第 3 核和第 7 核上。也就是说,共享锁竞争是导火索,CPU 亲和性带来的局部调度拥挤是放大器,两者一叠加,延迟尖刺就拦不住了。

4.3 修复方案与效果验证

修复分两步走,先改配置止血,再调内核参数兜底。

第一步是 Nginx 层面的核心改动:启用reuseport。在listen指令后加上这个参数,内核会为每个 worker 创建独立的 listen socket,各自拥有独立的 accept 队列和锁。连接由内核通过哈希分发到不同 worker,完全消除了跨 worker 的锁竞争。这是我个人在生产环境验证过最有效的方案,没有之一。

http { server { listen 80 reuseport; listen 443 ssl reuseport; # 其余配置保持不变 } }

第二步是调大内核的 accept 队列相关参数,给瞬时并发留出缓冲:

sysctl -w net.core.somaxconn=16384 sysctl -w net.ipv4.tcp_max_syn_backlog=16384

net.core.somaxconn决定 accept 队列的最大长度,tcp_max_syn_backlog决定 SYN 队列长度。在未开启 reuseport 的架构下,如果这两个值太小,短连接洪峰到来时内核会直接丢弃握手包,客户端只能靠重传,延迟自然飙升。

改完后的效果立竿见影:P99 从 620ms 回落到 48ms,P999 从 2.1s 降到 180ms,整个晚高峰没有再出现一次抖动。为了确认不是碰巧,我特意观察了一周,曲线稳定得跟手术刀切过一样。

5. 这套排查方法能带走:eBPF 排查高延迟的标准打法

5.1 五步走的排查路径

这次实战之后,我把 eBPF 排查高延迟问题的方法沉淀成了固定套路,适用于 Nginx、网关、消息队列等各种网络服务:

  1. 先用ss、top、tcpdump把网络层和资源层的大方向扫一遍,确认问题不在常规层面。
  2. 挂tcp_sendmsg/tcp_recvmsg的延迟直方图,快速确认系统调用本身是否正常,把用户态和内核态拆开。
  3. 用offcputime -K抓内核阻塞栈,看时间消耗在哪些函数上,找出锁竞争或睡眠路径。
  4. 对可疑函数用funclatency看延时分布,或用 kprobe 查看锁的持有者调用栈。
  5. 如果怀疑调度问题,用sched_wakeup+sched_switch计算 runqueue delay,验证唤醒-运行间隔。

这套打法的核心思想是:先找时间去哪了,再问为什么去那里,最后才动手改。很多人一上来就调内核参数,属于隔山打牛,运气成分太大。

5.2 我在实战里踩过的几个坑

第一个坑:直接用 kprobe 挂热点函数。eBPF 用 kprobe 挂tcp_sendmsg这类高频函数时,如果脚本里做的处理太多,开销会明显放大延迟,相当于观测行为本身改变了被测系统。优先使用 tracepoint 和 fentry/fexit(如果内核支持),它们更安全、开销更小。BCC 工具对 tracepoint 的支持已经非常完善,没必要硬上 kprobe。

第二个坑:只抓锁等待,不抓锁持有。看到lock_sock_nested出现在 offcpu 栈上时,我差点直接下结论是"锁竞争太激烈",但锁竞争的严重程度取决于持锁方的持锁时长,而不是等待方的等待次数。必须从release_sock这侧去看持锁分布,才能确定是锁本身被不合理地长期占用,还是只是竞争频率过高。

第三个坑:忽视 CPU 亲和性。如果 Nginx 配置了worker_cpu_affinity,排查调度延迟时一定要把 CPU 编号考虑进去,否则你看到"全局 CPU 空闲但 worker 排队"会觉得不可思议。其实只要把被阻塞的 worker 绑定的那个 CPU 的上下文切换次数和软中断占用拉出来对比,真相立刻清楚。

5.3 这类问题还能用 eBPF 挖到什么程度

这次查的是 Nginx 网关,但方法完全能迁移到别的场景:Kafka 客户端高延迟可以看tcp_sendmsg+lock_sock,数据库连接池满可以看connect系统调用的阻塞栈,Java 服务周期性卡顿可以看 GC 线程之外的内核态调度行为。eBPF 的价值不在于能给你一个玄学结论,而在于把无人能辩驳的现场证据摆在你面前:哪一行内核代码、哪一把锁、哪一个 CPU、哪一个时间戳。有了这些,开发同事和运维同事之间就不存在"我觉得是网络问题""我觉得是程序问题"的争论了。

最后再分享一个小技巧:生产环境临时排查尽量用 bpftrace 写单行命令,用完即走,不留下常驻进程;如果需要长期观测某个指标,再考虑把脚本转换成 libbpf + CO-RE 的私有工具,配合 cron 落盘。eBPF 用对了是神器,用滥了也会成为事故的源头——热路径上挂太多探针,本身就是一种风险。

返回列表