半个月前我遇到一个印象很深的线上问题反向代理层Nginx的RT响应时间突然从 10ms 左右飙到 300ms而且不是持续高是随机偶发跳变。第一反应是后端节点抖动翻了一圈监控后端响应没问题第二反应是网络问题从客户端到服务器 ping 却稳定在 0.2ms。最后只能登录机器用常规工具排查结果什么都看不出来。折腾到后来我意识到这类“偶发、高延迟、系统资源看不出异常”的问题大概率不在应用层而在内核态。于是我搬出 eBPF花了几分钟就在内核里锁定了真凶连接跟踪模块的锁竞争。这篇文章会把完整的排查思路、实操命令和根因讲清楚。Nginx、高延迟、内核这三个词放在一起最容易让人陷入“怀疑配置、怀疑网络、怀疑代码”的死循环而 eBPF 的价值恰恰是把隐藏在系统调用之下、TCP 协议栈内部、甚至网络过滤钩子里的耗时热点原样暴露出来。适合正在折腾性能问题、想了解可观测性的后端和运维同学看。1. 现象复现诡异的 Nginx 高延迟从哪来1.1 业务背景与最初判断当时架构很简单一台 Nginx 服务器作为反向代理接收外部网关流量转发给几个内网后端服务。流量不算大每秒大概两千到三千请求连接数也就几千CPU 负载常年在 20% 以下。Nginx 配置也中规中矩worker_processes autokeepalive开了后端连接池也做了怎么看都不像会出问题的样子。但监控曲线非常难看平均 RT 只有 15ms 左右P99 却时不时冲到 300ms 甚至 500ms。我把时间线和多个周期的数据叠在一起看发现高延迟不是固定某个时段而是随机出现在白天和晚上的任意时间持续几秒到几十秒又自己恢复。这种“毛刺型”延迟最烦人因为 reducers 和告警经常被触发值班同事被叫起来熬夜可等我们登录机器问题往往已经消失了。第一轮排查集中在应用层。检查后端服务耗时不正常吗没有后端日志显示它们的处理时间很平稳。检查Nginx日志$request_time高的时候$upstream_response_time却很正常说明耗时不在上游。检查网络客户端到 Nginx 的ping和mtr都没有丢包和跳变。于是怀疑是 Nginx worker 本身阻塞重启 Nginx 能好转几分钟但问题照旧。1.2 常规排查手段为什么失效在拿到 eBPF 之前我用了几乎所有常规套路这里直接说结论top/htopCPU 占用完全正常没有软中断飙高没有 worker 100% 跑满。ss -tn查看 TCP 连接状态没看到大量 TIME_WAIT、SYN_RECV 堆积accept 队列也没有溢出。netstat -sTCP 层没有明显的丢包、重传计数器暴涨ListenOverflows偶尔几个但不是大量增长。strace -p nginx_pid跟踪 worker 的系统调用看到的无非是accept、epoll_wait、read、write没有任何一个阻塞超过几十毫秒的系统调用。perf top抓内核热点函数排行里根本没看到明显的异常只有native_write_msr、__x64_sys_epoll_wait之类常见项。乍一看这服务器“健康得离谱”。但延迟是真实存在的问题一定在某个我们看不到的地方。后来我想明白了strace只能看到用户态进程进入内核的“边界”看不到系统调用返回之后内核继续跑的某段逻辑perf top偏采样统计适合被频繁调用的热点而这种偶发、短促、由特定数据包路径触发的延迟很容易被稀释掉。要精确定位必须找一个能挂在内核函数入口和出口按请求或者按包去统计耗时的黑科技——这就是 eBPF。2. eBPF 为什么能解决这类问题2.1 eBPF 本质在内核里跑一段“安全探针”eBPF扩展 Berkeley Packet Filter最早源于抓包优化但现在已经变成一套通用的内核动态追踪框架。你可以把它理解成往内核的关键路径上插微型探针不用改内核源码、不用重新编译、不需要重启系统。探针由内核验证器检查安全性后通过 JIT 编译成原生指令运行。传统内核模块也能做这件事但需要自己管理内存、锁、生命周期一个野指针就能把整台服务器搞死。eBPF 探针运行在受限沙箱里有复杂度限制、有内存访问边界校验、有死循环检测所以生产环境也可以放心临时挂载。对我这种“只想查个问题、没有勇气写内核模块”的人来说完全是救命级别的能力。我这次用到的核心挂载点是kprobe也就是内核函数探针。kprobe可以在任意非内联内核函数入口插入自定义代码kretprobe则捕获函数返回。两者配合可以精确算出某段内核代码的执行耗时。除了 kprobe还有 tracepoint内核预置的稳定跟踪点、fentry/fexit基于 BPF 的轻量探针等可选但 kprobe 的最大好处是无所不贴找问题时最灵活。2.2 它到底“看”到了什么拿这次的问题来说我需要在 Nginx worker 收包路径上找到真实瓶颈。网络收包从网卡驱动、到协议栈、到 Nginx 之间会经历很多函数tcp_v4_rcv、ip_rcv、nf_conntrack_in、tcp_v4_syn_recv_sock……任何一个函数出现瓶颈都会影响整体延迟但它们在常规监控里都没有独立指标。eBPF 的另一个强大之处在于可以按 CPU、按进程、按函数聚合分布。比如我写一个探针统计tcp_v4_rcv的耗时直方图能立刻看到是不是绝大多数请求都很短只是尾部有一批很长的异常点再按 CPU 核分开又能判断是不是某个核的中断处理失衡。这种“分布”比平均值、最大值更能反映问题本质。bpftrace是我最推荐的上手解析工具它提供类似 awk 的语法几行就能写完一个探针脚本。如果你不想手写 bpftrace还可以用 BCC 里的现成工具比如funclatency、trace、profile一行命令就能输出某个内核函数的耗时分布。下面我完整还原 5 分钟定位过程。3. 五分钟定位真凶实操全过程3.1 准备确认内核支持 eBPF 并安装工具先说明环境Linux 内核 5.4发行版是 CentOS 7生产环境不能随便重启。eBPF 在内核 4.9 以后基本可用5.x 更加完善如果内核较老或者没有开启 BTF可以使用 kprobe 方式作为兜底。安装 bpftrace# CentOS 7 / 8 使用 yum 安装 yum install -y bcc bpftrace # Debian/Ubuntu 使用 apt apt install -y bpfcc-tools bpftrace如果没有现成软件源也可以下载安装包或用源码编译但通常多花点时间。装完后先用bpftrace -l kprobe:tcp_v4_rcv列出目标符号确认探针可挂载。注意不要在生产环境同时挂太多探针否则 CPU 开销会放大。检查权限eBPF 需要 root 用户或者至少具备CAP_BPF、CAP_SYS_ADMIN。容器场景下需要给 privileged 或者显式添加 capabilities否则挂载时会遇到Operation not permitted。3.2 先确认延迟现象确实存在于内核路径为了量化耗时到底发生在哪个阶段我从 Nginx 的收包入口tcp_v4_rcv开始追踪统计这个函数从进入到返回的耗时分布。命令如下bpftrace -e kprobe:tcp_v4_rcv { start[tid] nsecs; } kretprobe:tcp_v4_rcv /start[tid]/ { rcv_usecs hist((nsecs - start[tid]) / 1000); delete(start[tid]); }正常情况下tcp_v4_rcv只是在 TCP 接收路径上做一些状态处理耗时应该是微秒级。但结果让我精神一振直方图长这样rcv_usecs: [1, 2) 124766 [2, 4) 31645 [4, 8) 2334 [8, 16) 569 [16, 32) 128 [32, 64) 14 [64, 128) 9 [512, 1024) 4 [4096, 8192) 2绝大部分请求都在几微秒内处理完但尾巴上出现了 4 到 8 毫秒的超大值。这就是我们要追的“幽灵延迟”。接着我又按 CPU 拆了一遍发现异常值集中在同一块 CPU 的softirq处理路径上说明不是 Nginx 用户态进程主动阻塞而是内核在处理网络包时偶发卡顿。3.3 用 bpftrace 聚焦“腐败”嫌疑函数tcp_v4_rcv只是一个容器真正耗时要继续往下钻。这台服务器为了满足业务的外网访问iptables 规则里开了 NAT 和部分转发所以我第一怀疑对象就是连接跟踪模块nf_conntrack_*。这里有个背景知识只要加载了nf_conntrack并且有数据包要判定是否属于已有连接那么每个首次进入的连接或者每个被 NAT 转发的报文都会经过nf_conntrack_in和nf_conntrack_confirm这类函数。连接多、表项多、锁竞争严重时这里会成为灾难。继续对nf_conntrack_in做耗时统计bpftrace -e kprobe:nf_conntrack_in { start[tid] nsecs; } kretprobe:nf_conntrack_in /start[tid]/ { ct_usecs hist((nsecs - start[tid]) / 1000); delete(start[tid]); }结果非常有说服力ct_usecs: [1, 2) 18520 [2, 4) 3471 [4, 8) 228 [8, 16) 45 [16, 32) 12 [32, 64) 6 [64, 128) 8 [256, 512) 5 [512, 1024) 3 [4096, 8192) 2注意nf_conntrack_in的单次耗时居然能到 8 毫秒对于每次请求只是查一下表而已这个数值反常到了什么程度类比一下你每天路过小区门口的快递柜正常时 5 秒就能取走一个件但现在偶尔要站在柜门前等 8 分钟因为柜门锁卡住了还排队。再用 BCC 工具funclatency快速验证一遍避免是我手写探针的问题funclatency -m nf_conntrack_in输出同样显示大部分调用耗时小于 1ms但存在极端分布。到这里问题范围基本收窄高延迟来自连接跟踪模块的偶发严重耗时。3.4 找到真凶连接跟踪表锁竞争既然怀疑是锁竞争就需要再抓一层。连接跟踪表里查找的时候会调用__nf_conntrack_find它需要遍历哈希槽位的链表并且要持有对应锁。我挂探针统计它的耗时bpftrace -e kprobe:__nf_conntrack_find { start[tid] nsecs; } kretprobe:__nf_conntrack_find /start[tid]/ { find_usecs hist((nsecs - start[tid]) / 1000); delete(start[tid]); }结果让我直接确认根因首先__nf_conntrack_find的命中率非常高说明几乎每个包都要走一次查找。其次它的耗时分布和nf_conntrack_in高度吻合同样是几十微秒到几毫秒都有。最关键的证据当我用bpf_trace_printk临时记录一次较长耗时的调用栈看到/sys/module/nf_conntrack/parameters/hashsize只有 65536但当前活跃的 conntrack 条目数是net.netfilter.nf_conntrack_count达到了 6 万多哈希槽的平均冲突链长度接近 1高峰时某些槽位链长超过 50。冲突链长了之后查找需要遍历链表的时间变长更致命的是并发情况下同一槽位的锁需要被不同 CPU 互相争抢一旦 CPU 忙不过来处理网络包的软中断就会被卡住Nginx 那一个请求的延迟直接就上去了。这个现象在我用mpstat -P ALL 1观察时也有印证异常的毫秒级延迟期间某个 CPU 的softirq占比短暂跳到 90% 以上。顺手验证了dmesg果然看到过nf_conntrack: table full, dropping packet的日志。虽然只在连接数打满时偶尔出现但佐证了连接跟踪表确实处在“濒临爆满”的状态。3.5 处理方案与效果根因清晰后处理就不复杂了三步走确认这台 Nginx 服务器上真正需要 NAT 的流量只有某几个网段其他流量完全是内部转发不需要做连接跟踪。在 iptables 的 raw 表里加上NOTRACK规则让大部分流量绕过nf_conntrack只保留必要部分的连接跟踪。同时调大连接跟踪表参数避免未来扩展时再次触发瓶颈。具体命令大致如下# 查看当前连接跟踪表状态 sysctl net.netfilter.nf_conntrack_count net.netfilter.nf_conntrack_max # 调大表上限和哈希桶大小在启动脚本或 sysctl 文件里持久化 sysctl -w net.netfilter.nf_conntrack_max1048576 echo 262144 /sys/module/nf_conntrack/parameters/hashsize # 对不需要跟踪的接口流量设置 NOTRACK iptables -t raw -A PREROUTING -i eth0 -p tcp --dport 443 -j NOTRACK iptables -t raw -A PREROUTING -i eth0 -p tcp --dport 80 -j NOTRACK注意hashsize修改对已有表不生效需要先清理或重启服务所以我建议是在低峰期操作。如果只是临时救火可以先设置nf_conntrack_max增大容量再重点观察锁问题是否缓解。调整后我再跑了一遍之前的bpftrace探针__nf_conntrack_find的最大耗时从几毫秒降回了几十微秒Nginx 的 P99 也从 300ms 回落到 15ms 左右。在这个案例里Nginx 根本不是问题所在它只是一个无辜的“受害者”。4. 常见问题与排查技巧实录4.1 eBPF 探针使用时的几个坑把这次操作复盘一下有几个容易被新手忽视的坑。第一个是kprobe 的稳定性问题。kprobe 是在内核函数入口动态修改指令如果函数被标记为noline或被优化内联探针可能挂不上或者误挂到奇怪的位置。所以生产环境挂探针之前尽量先用bpftrace -l kprobe:foo*确认符号存在。另外不要长时间大面积挂 kprobe它会影响 CPU 指令缓存和流水线导致性能损耗。像这次排查单段脚本跑几分钟足够了。第二个是内核版本符号差异。不同版本里nf_conntrack_in的符号名可能不一样老版本还可能是nf_conntrack_in更新内核里可能变成nf_conntrack_in的 inline 展开或者有新的追踪点。建议直接使用 bpftrace 的通配符bpftrace -l kprobe:nf_conntrack*先把候选符号拉出来再精确定位。这个动作花不了一分钟但能省下大量“探针明明挂上却不触发”的疑惑。第三个是探针脚本里 map 竞争的问题。在多个 CPU 同时命中 kprobe 时如果使用全局变量共享 start 时间可能出现互踩。我在上面的例子里用tid线程 ID作为 map key保证同一个 CPU 上嵌套调用不串数据。如果你想更严谨可以用cpu作为 key写一个嵌套计数器。不过大多数场景下tid够用。还有一个容易忽略的点bpftrace 输出 hist 时单位前缀要注意。上面我除以 1000 得到微秒看到直方图里[4096, 8192)就是 4 到 8 毫秒如果不除以 1000默认按纳秒统计你会看到一长串 0 到几百万纳秒反而不好读。4.2 没有 eBPF 时的替代排查路径如果你手上的老内核实在不支持 eBPF也可以用传统手段缩小范围但效率会低不少。perf trace可以跟踪系统调用但看不到内核内部函数。perf record -g -a全系统采样加调用栈适合高频热点对偶发延迟的命中率较低。ftrace老牌动态追踪框架可以开 function graph 跟踪指定函数但输出量大、上手门槛比 bpftrace 高。netstat -s、dmesg、conntrack -S用于观察连接跟踪模块的统计和丢包虽然没有函数级精度但能给出方向性线索。如果确认是连接跟踪问题直接看这几个指标最有价值指标正常危险信号nf_conntrack_count远小于 max 的一半接近nf_conntrack_maxnf_conntrack_max按业务流量合理预留过小导致表满丢包__nf_conntrack_find耗时分布几乎全部 50 微秒存在大量 1ms 尾部conntrack -S的insert_failed和drop0 或极低持续增长说明丢连接单 CPU softirq 占比多核均衡某个核频繁飙高我这里也分享一个经常被忽视的细节很多机器上的 conntrack 默认表上限是 65536看起来不小但如果你一个 HTTP 请求会经过INPUT、FORWARD、OUTPUT等多个方向再加上服务主动连后端时创建新的连接表项几千 QPS 就能很快吃满。解决方向从来不是“把表调大”一条路最大化收益是绕过它。对无需状态过滤和 NAT 的路径尽量用 raw 表的NOTRACK剪掉跟踪负担能不开 NAT 就少开 NAT能升级到 nftables 就升级它比 iptables 更轻量、维护更友好。5. 写在最后的个人体会这次排查之后我养成了一个习惯遇到偶发高延迟不再只盯着 Nginx 日志和 CPU 平均负载而是先问一个问题——“应用层和系统资源都正常那么时间究竟消耗在内核的哪段路上” eBPF 给我的不只是工具层面的能力提升更重要的是一种思维转变系统调用的边界不是排查的终点内核函数本身也应该被观测。如果你也想上手这套技能建议先在测试环境跑跑 bpftrace 的官方示例重点理解hist、count、kprobe这几个基础概念。后面遇到真正线上问题时你就能像我这次一样挂上探针、看直方图、缩小范围、找到真凶整个过程可能也就一杯咖啡的功夫。最后再分享一个小技巧如果 bpftrace 脚本里某段逻辑不生效先用printf(hit\n)打印一下触发点确认探针确实在被调用再往下加统计逻辑。排查内核问题先证明自己看到的是真相再去找答案能少走很多弯路。