1. 事故现场P99 莫名飙高常规排查全部落空1.1 故障现象与监控数据那天晚上八点刚过运维群里就炸了。图片上传大面积转圈接口响应时间翻着跟头往上涨。我拉出监控一看Nginx 网关层的 P99 延迟从平日的 40ms 左右直接飙到 600msP999 更是偶发突破 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 握手再加上一次主动 closeaccept 队列和 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_BPFCAP_PERFMON。我图省事直接在容器外以 root 跑的但说实话在多人共用的机器上建议用 capability 的最小化授权别把 root 撒得到处都是。2.3 观测目标设计先量化、再抓栈、再做关联eBPF 能观测的东西太多了不加设计就上脚本容易被海量输出淹没。我在动手之前先定了三个明确的问题一个请求从网卡中断到 Nginx 处理延迟的大头到底在哪一段如果是 worker 被卡住了卡在内核的哪个函数上如果是唤醒延迟唤醒源是谁调度延迟有多长带着这三个问题我给自己设了个时间盒每个问题最多花两分钟找证据找不到就换下一个假设。事实证明这个先量化、再抓栈、再做关联的节奏非常重要它避免了在错误的方向上深挖。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_nested0x1b2 inet_csk_accept0x1f8 do_accept0x44 __x64_sys_accept40x18 do_syscall_640x38 entry_SYSCALL_64_after_hwframe0x63 -- 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 delaybpftrace -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_affinityworker 进程被钉在指定 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.somaxconn16384 sysctl -w net.ipv4.tcp_max_syn_backlog16384net.core.somaxconn决定 accept 队列的最大长度tcp_max_syn_backlog决定 SYN 队列长度。在未开启 reuseport 的架构下如果这两个值太小短连接洪峰到来时内核会直接丢弃握手包客户端只能靠重传延迟自然飙升。改完后的效果立竿见影P99 从 620ms 回落到 48msP999 从 2.1s 降到 180ms整个晚高峰没有再出现一次抖动。为了确认不是碰巧我特意观察了一周曲线稳定得跟手术刀切过一样。5. 这套排查方法能带走eBPF 排查高延迟的标准打法5.1 五步走的排查路径这次实战之后我把 eBPF 排查高延迟问题的方法沉淀成了固定套路适用于 Nginx、网关、消息队列等各种网络服务先用ss、top、tcpdump把网络层和资源层的大方向扫一遍确认问题不在常规层面。挂tcp_sendmsg/tcp_recvmsg的延迟直方图快速确认系统调用本身是否正常把用户态和内核态拆开。用offcputime -K抓内核阻塞栈看时间消耗在哪些函数上找出锁竞争或睡眠路径。对可疑函数用funclatency看延时分布或用 kprobe 查看锁的持有者调用栈。如果怀疑调度问题用sched_wakeupsched_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_sendmsglock_sock数据库连接池满可以看connect系统调用的阻塞栈Java 服务周期性卡顿可以看 GC 线程之外的内核态调度行为。eBPF 的价值不在于能给你一个玄学结论而在于把无人能辩驳的现场证据摆在你面前哪一行内核代码、哪一把锁、哪一个 CPU、哪一个时间戳。有了这些开发同事和运维同事之间就不存在我觉得是网络问题我觉得是程序问题的争论了。最后再分享一个小技巧生产环境临时排查尽量用 bpftrace 写单行命令用完即走不留下常驻进程如果需要长期观测某个指标再考虑把脚本转换成 libbpf CO-RE 的私有工具配合 cron 落盘。eBPF 用对了是神器用滥了也会成为事故的源头——热路径上挂太多探针本身就是一种风险。