eBay云计算“网”事：网络超时篇

导读 eBay自2016年开始将业务迁往Kubernetes容器平台，其间遇到了各种网络问题。云计算“网”事系列旨在介绍 eBay IE Cloud团队 巧妙利用eBPF工具进行排查，并解决这些典型网络问题的事迹。该系列分为三篇： 网络超时篇、网络丢包篇及网络重传篇 。本篇主讲网络超时问题，希望能为类似问题的定位和解决提供思路。

背景介绍

eBay从 2016年 开始将Kubernetes项目作为下一代云平台方案。经过几年的发展实践，已经逐步完成各大主要业务往Kubernetes容器平台上的迁移。在这过程中，碰到大大小小的问题数不甚数。 其中大规模应用场景下的偶发性问题，一直是这些问题中的关键难点。 随机性，小概率发生，不容易复现，都给这类问题的现场捕捉和定位造成重重困难。定位和解决此类问题，一般需要数天甚至数周的时间。通过 eBPF方式 来对内核进行剖析，是目前业内逐步开始探索的一个定位此类问题的方式，而eBay也在定位诸多问题中，渐渐累积开发了针对某些此类问题的eBPF工具。

云计算“网”事 系列文章，将从利用eBPF工具来解决eBay云平台碰到的几个典型网络问题入手，包含 网络延时、网络丢包、网络重传 三个方面，给出详细的摸索和排查分析过程，希望能为定位和解决相关问题提供思路。

应用运行在虚拟机或者物理机上，可以直接通过机器的网络端口进行数据传输，而在Kubernetes的节点上，容器运行在独立的network namespace，通过veth pair 接口来对外进行数据通信。一个常见的容器网络配置如图1所示:

图1

外部来容器的数据，经过物理机网卡eth0接收后，会经过路由，到达运行在主机network namespace的cali端口，再通过veth pair送到容器network namespace的eth0端口。在这中间会经过iptables或者 ipvs 的处理。容器往外发生数据，是接收数据的反向路径。

网络超时篇

案例1

某个运行在Kubernetes集群上的多实例应用，客户端发起的请求偶尔会超时。从现象来看，往某些节点上的服务发起的请求，每个小时的超时数会比其他的节点多几十次或者几百次。该pod提供对后段数据库的查询，然后返回结果给用户。客户端的超时时间是 400ms 。

超时信息：

图2

由图2可见，有一个节点的超时次数比较高，而其他节点的超时次数一个小时内也有100次左右。从总体上来看，一个小时内的调用到达万次以上，因此总体的timeout率不高。

针对这个问题，我们首先做了如下几个排查工作：

1. 因为用户汇报了自从某个时间段开始，发现timeout的数量增加，所以我们先查看了那个时间段，是否有什么版本改动引起了问题，并排查了几个关联的修改，但没有发现和此类问题有直接的联系。
2. 检查出问题机器的网络配置是否正确。为了减少数据包发送的乱序，提高性能，针对cali端口，使能了RPS（Receive Packet Steering)。检查下来，该端口配置都没有问题。
3. 节点的CPU使用率和负载并不高。
4. 检查了出现超时问题比较多的节点及其相关metrics 的信息，没有明显的节点的丢包统计和重传。从timeout的次数和总体的查询次数来看，这个也符合预期。
5. 通过qperf来检测节点的tcp延时，并没有看到明显的延时问题。
6. 使用tcpdump来抓取容器端口的数据并且同步观测容器的出错信息，当日志中打出出错信息的时候，tcpdump上观测到有数据重传，如图3所示。该连接的RTO在 200ms 左右，所以当链路有问题的时候，是很可能发生重传的。

图3

1. 从其他的节点ping该节点，会有间断的延时突发问题。

图4

通过ping pod来复现问题，可以从图4看到有延时突然增多的现象，那就基本可以确定，数据从链路到容器的tcp协议栈，已经出现延时突发的问题了。 通过ping物理机的网卡，可以看到延时突发的现象基本消失，因此主机侧出问题的可能性比较大。

但是定位主机侧的问题，面临着很大的困难。

首先，在大规模的集群上，节点的metrics很多都是以分钟为间隔来进行抓取的，很多时候并不能反应出问题时间段内发生了什么。 假如因为某个时间段内的系统负载突然增高导致了延时问题，从metrics上往往是看不到的。另外，metrics的精细化不够。例如tcp的丢包和重传，反映的是一个时间段内总的增长值，但如果问题是在很短的时间内发生的，那就很难说明两者之间有必然的相关性。 其次，很难直接找到和延时相关的证据。 一般都是看到某些异常，从离散的点去怀疑，不断修改验证，最后观察到问题没有再出现，说明问题已经解决。这也是目前在众多公众号文章看到定位系统问题的普遍解决方式。 因为Linux系统模块之间错综复杂的联系和相互影响，导致很多时候解决问题只能用排除法。 如果排除了怀疑的点后，问题仍旧没有改善，那就只能找新的点继续排除。该方法并不能说是不好，但肯定不是最优的解决问题的方式。因为就算解决了问题，很多时候还是无法找到引起问题的具体原因。 除此之外，利用tcpdump来处理这样的问题，会比较困难 ，得在主机的eth0, cali端口，容器的eth0同时长时间抓包，之后再将抓到的数据进行合并分析，看看是哪一节点引入的延时。另外tcpdump本身的overhead，是否会导致延时的突发也是个未知数，而且也无法诊断是否是iptables/ipvs引起的延时。 还有tcpdump只能输出基本的数据包信息，但是有关内核的信息在定位问题的时候还是不够。 因此tcpdump只能作为一个辅助工具，无法完全依赖。

在这样的基础上，我们只能逐步排查是哪个模块引起的问题。思路是逐步停掉各种业务，然后进行ping测试，如果没有出现突发情况，则说明跟停掉的模块有很大的关系。

通过该方式，我们发现kubelet有很大的嫌疑 ，查看社区问题，找到一个类似的案例：

https://github.com/google/cadvisor/issues/1774#issuecomment-501907566

同我们碰到的问题一样，可以通过drop cache 来进行修复。在继续往下深究的过程中，该问题的处理作者发布了一个博客：

https://github.blog/2019-11-21-debugging-network-stalls-on-kubernetes/

其中详细阐述了他们定位该问题的过程，以及引起该问题的原因。

简单来说，就是pod删除后，cgroup还残留在cache中，导致kubelet获取根cgroup内存统计信息的系统调用耗费太长时间，进而影响了ksoftirqd对softirq的处理。而为何cgroup在容器删除后，还会有信息遗留呢，感兴趣的可以查看链接：

https://lwn.net/Articles/787614/

主机的延时问题会是经常碰到的一个难题 ，因此在定位该问题的过程中，我们就在想如何能够加速该类型问题的定位，而不用像定位本案例的时候，采取逐个排除的方式。主要的想法就是利用工具来快速找到数据产生延时的点，当获知数据在哪个路径上产生了延时之后，就可以针对性缩小范围进行下一步的排查。受开源项目https://github.com/yadutaf/tracepkt的启发， 我们也开发了基于eBPF的工具，来记录数据包在内核里面的处理流程。主要功能包括：

• 通过TRACEEVENT或者kprobe来探测网络协议栈在二层，三层和四层上的典型路径，例如net:netif_rx，net:net_dev_queue，net:napi_gro_receive_entry，net:netif_receive_skb_entry等。可以通过指定IP地址或者端口号等来抓取指定的数据包的处理事件。
• 当对应的函数被调用或者event被触发，则会从skb中获取当前的network namespace、端口信息、CPU核、调用时间、进程号、数据包的五元组、数据包长度等信息。
• 因为我们的节点上会同时使用iptables和ipvs，所以也抓取了iptables和ipvs 各个处理链的入口和出口，用于计算各个处理链的花费时间，以及已经处理链对数据包的处理策略，例如ACCEPT，DROP等。

案例2

某个应用的实例有部署在虚拟机中，也有以容器部署到kuberntes集群中。应用的管理员从监控中发现，调用某个第三方API的超时比例不同，前者在 0.001% ，后者在 0.01%-0.04% ，之间差了数十倍，因此汇报出该问题，让我们去排查为何会有这样的差别。

经过沟通了解到，该用户客户端的超时时间是 100ms ，所有以容器部署的节点，超时的错误率都比运行在虚拟机上要高。于是我们开始着手定位该问题：

1. 开始复现 在节点上进行100次的API调用，每次调用可以在30ms-40ms之间完成。 对节点容器进行1万次的ping操作，并没有发现有延时现象。 因此复现失败。
2. 是否是由之前定位过的kubelet搜集获取memory.stat引起的呢？（详见案例1） 用命令：

来计算读取memory.stat的消耗时间，大部分都超过了50ms。因为客户端的超时时间设置为100ms，而调用API的耗时在30-40ms，再加上这个消耗的50ms，是很可能导致超时的。于是执行drop cache的操作，很遗憾的是drop cache后，并没有让超时问题得到多少改善。

1. 于是继续跑设计的eBPF工具，希望能查找到在主机的哪个位置产生了超时。

在抓取了超十万条数据记录后，用脚本对输出结果进行分析，根据输出条目的时间戳和数据包信息，过滤出在主机上有异常延时的数据包信息，如图5所示：

图5

图5中的第二列代表了当前处理数据包的network namespace，第三列代表当前数据包处理的端口，第四列显示了数据包信息，第五列显示了IPVS或者iptables对数据包的处理，第六列显示了处理softirq的进程信息，第七列显示了当前处理数据的CPU核，第八列显示了处理数据开始的时间戳，是系统的启动时间，单位为ns。

从抓取数据信息来看，有数据包从容器发出到主机端口发送，时间使用10865291752989502 - 10865291551167147 = 201822355ns, 也就是超过了200ms，主要的时间消耗在从第3步到第4步之间 ，从容器的network namespace到主机的network namespace，就超过10865291752980718 - 10865291551180388 = 201800330 (> 200ms)。

在分析了多个数据超时的数据包后，发现他们具有同样的模版，那就是在主机network namespace上处理veth pair端口过来数据包的CPU core，都是 32 。

通过top命令来查看该核的运行情况，发现该核的中断处理时间si会间歇性比较高，经常达到30%的使用率，而节点的load很低，整体CPU的使用率也不高。

如果没有基于eBPF的工具，而是通过类似排查问题1这样的定位手段，想要定位到这一步，是需要很长的时间的，我们可能会注意到32的si会稍微高点，但是很难和网络延时问题进行直接的关联。 而有了eBPF工具，通过抓取数据，很快就得到了这样的关键信息，这些信息对于解决问题可谓是至关重要。

接着通过perf，来查看下具体该核都在做什么事情，并生成火焰图（图6）。

图6

可以看到该核消耗了很大的一部分时间在处理estimation_timer。而si比较高，要么estimation_timer的中断次数很多，要么处理某个中断耗时很长。

先看中断次数是否很多，通过我们自己开发的小工具，从/proc/interrupts获取一段时间内该核的中断数量，结果显示该核上并没有很多timer中断数量，其他类型的中断也很少。

既然没有很多的中断，那么问题大概率是中断处理时间比较长。于是，我们对bcc的softirq 工具https://github.com/iovisor/bcc/blob/master/tools/softirqs.py 进行了修改，让它只统计CPU32 上不同类型的softirq耗时信息。在运行一段时间后，从输出结果中发现有timer的softirq执行时间在 262ms-524ms 之间。

从代码得知,estimation_timer是由ipvs模块进行注册的：

从estimation_timer的函数实现来看，它会调用spin_lock进行锁的操作，并且会查询每一条的ipvs rules进行相关操作。我们集群上的service比较多，因此在节点上，会存在很多的ipvs 规则，导致estimation_timer的执行需要消耗大量的时间。

但是为什么只有在核32上会出现问题呢？

通过ftrace，我们抓取了estimation_timer()的function_graph, 从图7的结果可以看到，estimation_timer()在很多的核上都被执行，但是只有在32核上执行的时候，消耗了很多的时间，其他核上消耗的时间都很少。

图7

在kube-proxy使用ipvs模式的节点上，只有主机的host network namespace才有很多的ipvs rules，而在容器的netowrk namespace里面，并没有ipvs rules存在。从现象来看，核32应该是被用来处理host network namespace的ipvs rules，而其他的核用来处理其它容器network namespace的ipvs rules，所以才会有这么大的差别。

那为什么核32被用来处理host network namespace，而不是其他的核呢？

从实验结果来看，该值是由加载ipvs 模块时候的核决定的，如果通过task_set来设定加载ipvs模块的核，那么会由该核来执行host network namespace的estimation_timer。

至此，我们已经知道了该问题的来龙去脉，解决方法主要是：

• 短期内 通过live patch将estimation_timer的执行功能替换来解决线上的问题，目前我们暂时不需要estimation_timer对不同的链路进行速率等的统计，所以暂时将功能替换为不执行任何操作。
• 在长期方案上 ，我们选择去除该timer，通过kernel thread来定期执行ipvs相关的链路速率、数据包等的统计功能，也就是来完成之前estimation_timer的工作。该方案目前还在进行更多详细的测试。

总结——网络超时篇

网络超时问题，关键还是在于找寻网络超时的时间点。如果可以找出这个时间点，就能快速缩小问题范围，也为最终解决问题提供一个正确有力的指导方向。这事情如同穿衣服，第一个纽扣对上了，后面的其他纽扣也就自然而然对上了。

从上面两个案例的定位方式对比来看， 抛弃手忙脚乱进行各种尝试，而是利用工具，来寻找第一个纽扣 ，是在复杂的Linux环境下，快速定位此类问题的关键方法。利用eBPF可以对内核进行更深入的剖析，让我们初步感受到了它的威力。因此我们也将用它来定位其他类型的问题，详情请关注后续的丢包篇和重传篇。