导语:本文分享了笔者现网遇到的一个文件下载慢的问题。最开始尝试过很多办法,包括域名解析,网络链路分析,AB环境测试,网络抓包等,但依然找不到原因。然后利用网络命令和报文得到的蛛丝马迹,结合内核网络协议栈的实现代码,找到了一个内核隐藏很久但在最近版本解决了的BUG。如果你也想了解如何分析和解决诡异的网络问题,如果你也想温习一下课堂上曾经学习过的慢启动、拥塞避免、快速重传、AIMD等老掉牙的知识,如果你也渴望学习课本上完全没介绍过的TCP的一系列优化比如混合慢启动、尾包探测甚至BBR等,那么本文或许可以给你一些经验和启发。
问题背景
线上用户经过STGW(Secure Tencent Gateway,腾讯安全网关-七层转发代理)下载一个50M左右的文件,与直连用户自己的服务器相比,下载速度明显变慢,需要定位原因。在了解到用户的问题之后,相关的同事在线下做了如下尝试:
1. 从广州和上海直接访问用户的回源VIP(Virtual IP,提供服务的公网IP地址)下载,都耗时4s+,正常;
2. 只经过TGW(Tencent Gateway,腾讯网关-四层负载均衡系统),不经过STGW访问,从广州和上海访问上海的TGW,耗时都是4s+,正常;
3. 经过STGW,从上海访问上海的STGW VIP,耗时4s+,正常;
4. 经过STGW,从广州访问上海的STGW VIP,耗时12s+,异常。
前面的三种情况都是符合预期,而第四种情况是不符合预期的,这个也是本文要讨论的问题。
前期定位排查
发现下载慢的问题后,我们分析了整体的链路情况,按照链路经过的节点顺序有了如下的排查思路:
(1)从客户端侧来排查,DNS解析慢,客户端读取响应慢或者接受窗口小等;
(2)从链路侧来排查,公网链路问题,中间交换机设备问题,丢包等;
(3)从业务服务侧来排查,业务服务侧发送响应较慢,发送窗口较小等;
(4)从自身转发服务来排查,TGW或STGW转发程序问题,STGW拥塞窗口缓存等;
按照上面的这些思路,我们分别做了如下的排查:
1.是否是由于异常客户端的DNS服务器解析慢导致的?
用户下载小文件没有问题,并且直接访问VIP,配置hosts访问,发现问题依然复现,排除。
2.是否是由于客户端读取响应慢或者接收窗口较小导致的?
抓包分析客户端的数据包处理情况,发现客户端收包处理很快,并且接收窗口一直都是有很大空间。排除。
3.是否是广州到上海的公网链路或者交换机等设备问题,导致访问变慢?
从广州的客户端上ping上海的VIP,延时很低,并且测试不经过STGW,从该客户端直接访问TGW再到回源服务器,下载正常,排除。
4.是否是STGW到回源VIP这条链路上有问题?
在STGW上直接访问用户的回源VIP,耗时4s+,是正常的。并且打开了STGW LD(LoadBalance Director,负载均衡节点)与后端server之间的响应缓存,抓包可以看到,后端数据4s左右全部发送到STGW LD上,是STGW LD往客户端回包比较慢,基本可以确认是Client->STGW这条链路上有问题。排除。
5.是否是由于TGW或STGW转发程序有问题?
由于异地访问必定会复现,同城访问就是正常的。而TGW只做四层转发,无法感知源IP的地域信息,并且抓包也确认TGW上并没有出现大量丢包或者重传的现象。STGW是一个应用层的反向代理转发,也不会对于不同地域的cip有不同的处理逻辑。排除。
6.是否是由于TGW是fullnat影响了拥塞窗口缓存?
因为之前由于fullnat出现过一些类似于本例中下载慢的问题,当时定位的原因是由于STGW LD上开启了拥塞窗口缓存,在fullnat的情况下,会影响拥塞窗口缓存的准确性,导致部分请求下载慢。但是这里将拥塞窗口缓存选项 sysctl -w net.ipv4.tcp_no_metrics_save=1 关闭之后测试,发现问题依然存在,并且线下用另外一个fullnat的vip测试,发现并没有复现用户的问题。排除。
根据一些以往的经验和常规的定位手段都尝试了以后,发现仍然还是没有找到原因,那到底是什么导致的呢?
问题分析
首先,在复现的STGW LD上抓包,抓到Client与STGW LD的包如下图,从抓包的信息来看是STGW回包给客户端很慢,每次都只发很少的一部分到Client。
这里有一个很奇怪的地方就是为什么第7号包发生了重传?不过暂时可以先将这个疑问放到一边,因为就算7号包发生了一个包的重传,这中间也并没有发生丢包,LD发送数据也并不应该这么慢。那既然LD发送数据这么慢,肯定要么是Client的接收窗口小,要么是LD的拥塞窗口比较小。
对端的接收窗口,抓包就可以看到,实际上Client的接收窗口并不小,而且有很大的空间。那是否有办法可以看到LD的发送窗口呢?答案是肯定的:ss -it,这个指令可以看到每条连接的rtt,ssthresh,cwnd等信息。有了这些信息就好办了,再次复现,并写了个命令将cwnd等信息记录到文件:
while true; do date +"%T.%6N" >> cwnd.log; ss -it >> cwnd.log; done
复现得到的cwnd.log如上图,找到对应的连接,grep出来后对照来看。果然发现在前面几个包中,拥塞窗口就直接被置为7,并且ssthresh也等于7,并且可以看到后面窗口增加的很慢,直接进入了拥塞避免,这么小的发送窗口,增长又很缓慢,自然发送数据就会很慢了。
那么到底是什么原因导致这里直接在前几个包就进入拥塞避免呢?从现有的信息来看,没办法直接确定原因,只能去啃代码了,但tcp拥塞控制相关的代码这么多,如何能快速定位呢?
观察上面异常数据包的cwnd信息,可以看到一个很明显的特征,最开始ssthresh是没有显示出来的,经过了几个数据包之后,ssthresh与cwnd是相等的,所以尝试按照"snd_ssthresh ="和"snd_cwnd ="的关键字来搜索,按照snd_cwnd = snd_ssthresh的原则来找,排除掉一些不太可能的函数之后,最后找到了tcp_end_cwnd_reduction这个函数。
再查找这个函数引用的地方,有两处:tcp_fastretrans_alert和tcp_process_tlp_ack这两个函数。
tcp_fastretrans_alert看名字就知道是跟快速重传相关的函数,我们知道快速重传触发的条件是收到了三个重复的ack包。但根据前面的抓包及分析来看&#