加餐01 | 案例分析：怎么解决海量IPVS规则带来的网络延时抖动问题？

本文仅作为学习记录，非商业用途，侵删，如需转载需作者同意。

一、问题背景

虚拟机迁移到了 Kubernetes 平台上。迁移之后，用户发现他们的应用在容器中的出错率很高，相比在之前虚拟机上的出错率要高出一个数量级。

分析了应用程序的出错日志，发现在 Kubernetes 平台上，几乎所有的出错都是因为网络超时导致的。

经过网络环境排查和比对测试，我们排除了网络设备上的问题，那么这个超时就只能是容器和宿主机上的问题了。

在虚拟机中的出错率是 0.001%，而在容器中的出错率是 0.01%~0.04%。偶发的问题，排查的难度就增大了。

===

查看了节点的 CPU使用率、Load Average、内存使用、网络流量和丢包数据、磁盘I/O等，没有看到异常。

使用tcpdump来排查问题有个难点：
1、问题是偶发的，需要长时间抓取数据，数据量就会比较大
2、抓取数据后，需要设计一套分析程序来找到长延时的数据包
3、找到长延时的数据包，也无法定位网络超时的根本原因

二、调试过程

2.1、ebpf的破冰

猜测：因为产生在节点上，所以可以推测，延时有很大的概率发生在Linux 内核处理数据包的过程中。

可以给每个数据包在内核协议栈关键的函数上都打上时间戳，然后计算数据包在每个函数之间的时间差，如果时间差比较大，就可以说明问题出现在两个内核函数之间。

下面图片就是Linux 内核在接收数据包和发送数据包的时候的主要函数

在不修改内核源代码的情况，要截获内核函数，我们可以利用 tracepoint 和 kprobe 的接口。

有两种方法使用这两个接口：
一是直接写 kernel module 来调用kprobe 或者 tracepoint 的接口
二是通过 ebpf 的接口来调用他们

这里我们选择第二种方法，也就是ebpf 来调用内核接口，记录数据包处理过程中这些协议栈函数的每一次调用。

选择ebpf有两个原因：

• ebpf的程序在内核中加载会做很严格的检查，这样在生产环境中使用比较安全
• ebpf map 功能可以方便的进行内核态与用户态的通信，这样实现一个工具也比较容易

决定了这个方法后，这里我们需要先实现一个ebpf工具，然后用这个工具对内核网络函数做trace。

工具的具体实现：
针对用户的一个TCP/IP 数据流，记录这个流的数据发送包与数据接收包的传输过程。
也就是数据发送包从容器的Network Namespace发出，一直到它到达宿主机的 eth0 的全过程，以及数据接收包从宿主机 eth0 返回容器 Network Namespace的 eth0 的全程。

在收集了数十万条记录后，我们对数据做了分析，找出前后两步时间差大于50 毫秒(ms)的记录，最终发现了下面这段记录：

在这段记录中，我们先看一下Network Namespace 这一列，编号3 对应的 Namespace ID 4026535252 是容器里面的，而 ID4026532057 是宿主机上的 Host Namespace。

数据包从1到7的数据表示，一个数据包从容器里的eth0 通过 veth 发送到宿主机上的peer veth cali29cf0fa56ce 然后再通过路由从宿主机的obr0（openvswith）接口和 eth0 接口发出。

这个过程中发现数据包从容器的eth0 发送到宿主机上的cali29cf0fa56ce，也就是从第3步到第4步之间，花费的时间是 10865291752980718-10865291551180388=201800330。

因为时间戳的单位是纳秒 ns，而 201800330 超过了 200 毫秒（ms），这个时间显然是不正常的。

在17讲中说过 veth pair 之间数据的发送，它会触发一个 softirq ，并且在ebpf的记录中也看到，当数据包到达 cali29cf0fa56ce 后，就是 softirq 进程在CPU32上对它处理。

这个时候再去重点关注下 CPU32的softirq 处理上，仔细看看 CPU32上的si （softirq）的CPU 使用情况（运行top命令之后再按一下数字键1，可以看出每个CPU的使用率），就会发现CPU32上时不时出现si CPU 使用率超过20%的情况。

%Cpu32 :  8.7 us,  0.0 sy,  0.0 ni, 62.1 id,  0.0 wa,  0.0 hi, 29.1 si,  0.0 st

这个情况，在节点监控数据上是不容易发现的，因为节点有80个CPU，单个CPU si 偶尔超过20%，平均到80个CPU上就只有 0.25%了。
对于一个普通的节点，1%的si 使用率都是很正常的。

为什么在 CPU32 上的 softirq CPU 使用率会时不时突然增高？

2.2、perf 定位热点

对于查找高CPU 使用率情况下的热点函数，perf 是最有力的工具，我们只需要执行一下后面这条命令，看一下CPU32上的函数调用的热度。

# perf record -C 32 -g -- sleep 10

为了方便查看，我们可以把 perf record 输出的结果做成一个火焰图，具体的方法我在下一讲里介绍，这里你需要先理解定位热点的整体思路。

重点关注在 softirq 中被调用到的函数。

图中可以看出来 run_timer_softirq 所占的比例比较大的，而在 run_timer_softirq 中的绝大部分比例又是被一个叫作 estimation_timer() 的函数所占用的。

运行完 perf 之后，我们离真相又近了一步。现在，我们知道了 CPU32 上 softirq 的繁忙是因为 TIMER softirq 引起的，而 TIMER softirq 里又在不断地调用 estimation_timer() 这个函数。

对于 TIMER softirq 的高占比，一般有这两种情况，一是 softirq 发生的频率很高，二是 softirq 中函数执行的时间比较长。

用/proc/softirqs 查看CPU32 上 TIMER softirq 每秒钟的次数，就会发现 TIMER softirq 在CPU32 上的频率其实并不高。

这样第一种情况就排除了，那我们下面就来看看，Timer softirq 中的那个函数 estimation_timer()，是不是它的执行时间太长了？

2.3、ftrace 锁定长延时函数

怎样才能得到 estimation_timer() 函数的执行时间呢？

14讲中用过 ftrace，当时我们把 ftrace 的 tracer 设置为 function_graph，通过这个办法查看内核函数的调用时间。在这里我们也可以用同样的方法，查看 estimation_timer() 的调用时间。

这时候，我们会发现在 CPU32 上的 estimation_timer() 这个函数每次被调用的时间都特别长，比如下面图里的记录，可以看到 CPU32 上的时间高达 310 毫秒！

现在，我们可以确定问题就出在 estimation_timer() 这个函数里了。

接下来，我们需要读一下 estimation_timer() 在内核中的源代码，看看这个函数到底是干什么的，它为什么耗费了这么长的时间。其实定位到这一步，后面的工作就比较容易了。

estimation_timer() 是 ipvs 模块中每隔2秒钟就要调用的一个函数，它主要用来更新节点上每一条 IPVS规则的状态。 kubernetes Cluster 里每建一个 service，在所有节点上都会为这个 service 建立相应的 IPVS 规则。

通过下面这条命令，我们可以看到节点上 IPVS 规则的数目：

# ipvsadm -L -n | wc -l
79004

节点上已经建立了将近 80K 条 IPVS 规则，而 estimation_timer() 每次都需要遍历所有的规则来更新状态，这样导致 estimation_timer() 函数时间开销需要上百毫秒。

我们还有最后一个问题，estimation_timer() 是 TIMER softirq 里执行的函数，那它为什么会影响到网络 RX softirq 的延时呢？

这个问题，我们看下 softirq 的处理函数 __do_softirq() ，在同一个CPU上，_do_softirq()会串行处理每一种类型的 softirq，所以 TIMER softirq 执行的时间长了，就会影响到下一个RX softirq的执行。

三、问题小结

这个延时偶尔发生，并且出错率在0.01%~0.04%，所以监控上无法查看到异常。

我们想到的方法是使用 ebpf 调用 kprobe/tracepoint 的接口，这样就可以追踪数据包在内核协议栈主要函数中花费的时间。

前提是，问题出现在节点上，猜测是内核相关的问题。

我们实现了一个ebpf 工具，并且用它缩小了问题范围，我们发现当数据包从容器的 veth 接口发送到宿主机上的 veth 接口，在某个CPU 上的 softirq 处理时间有很长的延时，看到对应CPU上的 si 使用率 20%，比其他CPU 高很多。

然后使用perf 工具专门查找了这个CPU上的热点函数，发现 TIMER softirq 中调用 estimation_timer() 的占比是比较高的。

使用 ftrace 进一步确认了，在这个特定的CPU上 estimation_timer() 所花费的时间需要几百毫秒。

最终锁定了问题出现在 IPVS 这个 estimation_timer() 函数里，也找到了问题根本原因。 我们在节点上存在大量的 IPVS 规则， 每次遍历这些规则都会消耗很多时间，最终导致了网络超时的现象。

知道了原因之后：因为我们在生产环境并不需要读取IPVS的规则状态，为了快速解决生产环境的问题，我们可以使用内核 livepatch 机制在线把 estimation_timer() 函数替换成一个空函数。

这样就短期解决了因为estimation_timer() 耗时长影响其他的 softirq 的问题，至于长期的解决方案，我们可以把IPVS 规则的状态统计从 TIMER softirq 中转移到 kernel thread 中处理。

四、评论

1、
问题：
softirq 通常是节点内网络延迟的重要线索。不借助 eBPF 工具时，可以先采用传统工具 top、mpstat 重点观测下 softirq CPU 使用率是否存在波动或者持续走高的情况。如果存在，进一步使用 perf 进行热点函数分析。

不过使用现有的 eBPF softirq 相关工具更方便。

回答：
这里的问题就是一开始如何就认为是softirq这里出问题。在节点有80核的情况下，简单看一下top里的si， 它的usage是不多的。

2、
问题：
大集群就容易遇到IPVS规则过多的问题吧。

有点好奇
1 集群中的其他节点应该也会存在类似的问题吧。
2 每次都是固定在这一个核上做这个事情么？

回答：
.> 集群中的其他节点应该也会存在类似的问题吧。
是的，在kubernetes cluster里，每个节点都会有同样的问题。ipvs rules是为每个service的in cluster vip设置的，在所有节点上的配置都是一样的。

.> 每次都是固定在这一个核上做这个事情么？
是的，对于timer函数，在哪个cpu核上注册，后面就一直在那个核上执行了。

3、
问题：
“把 IPVS 规则的状态统计从 TIMER softirq 中转移到 kernel thread 中处理”，这个事情是通过什么配置就可以实现的吗？总不能改内核模块吧？

回答：
不能通过配置来实现，需要改内核。

4、
问题：
请问老师，IPVS过多是由于service导致的么？还是旧service遗留导致的呢？
另外，不知可否分享下您实现的ebpf工具呢？

回答：
对的IPVS是由于cluster中有大量的service, 不是残留。
我们的ebpf工具和这个有些类似吧。
https://github.com/yadutaf/tracepkt

我们增加了更多的tracepoint点和kprobe点，多了一些event的信息