
这篇博客来源于我在今日头条的一次问题追查经历,这一次追查基本颠覆了我对TCP一些处理逻辑的认识,包括TCP中的WAIT队列、ACCEPT队列的概念,以及TCP可以在不发FIN或RST的情况下就直接让一个ESTABLISHED状态的连接消失等。
希望这篇博文能对大家理解TCP或日后追查线上问题时有帮助。
0 背景
正常而言,client与server建立TCP连接,并由client端主动关闭,会依次经过以下几个状态变化:
然而最近(2016年10月21号前后)头条的一个服务出现奇怪的现象,在深夜大约2点左右会出现服务高概率Hung死,几乎所有的worker都不工作。
而当时现场的TCP连接状态更是奇怪:从client端看已经没有与server端的连接了,但从server端看仍然保留有与client端的连接,且连接处于ESTABLISHED状态。
我负责跟进这个问题,并开始了从我入职以来持续时间最长、最痛苦的追查。
所幸的是最终问题查到了,而且也知道了问题发生的原因。
PS1:在追查的时候也考虑过是否其中一台机器掉电了而导致出现两端TCP连接不一致的情况,但是这个原因被排除了,因为从日志看两台机器都一直在运行。
PS2:出于公司保密等原因,下面文章中一部分真实截图、IP、目录结构等已替换成对应的示意图或示意文字。
PS3:为了保证阅读体验,可以到 http://blog.reetsee.com/archives/570 查看原文。
1 现象
下面描述的现象中,10.163.0.175是client端机器,10.171.118.80是server端机器。
1.1 TCP连接在client于server两端状态不一致
使用netstat命令查看TCP连接状态。
client端与server端机器看到的TCP连接状态不一致,在server端能看到与client之间的连接:
xuruiqi@server:~$ netstat -apn | grep '10.171.118.80:2095' tcp6 0 0 10.171.118.80:2095 10.163.0.175:51555 ESTABLISHED 200111/python xuruiqi@10.171.118.80:~$
在client端却看不到与server的连接:
xuruiqi@client:~$ netstat -apn | grep '10.171.118.80' xuruiqi@client:~$
1.2 server端进程卡在recvfrom系统调用上
在server端使用strace命令查看进程系统调用情况。
xuruiqi@server:~$ strace -p 1149 -s 256 -f ... accept(14, {sa_family=AF_INET6, sin6_port=htons(51555), inet_pton(AF_INET6, "::ffff:10.163.0.175", &sin6_addr), sin6_f... ... getpeername(16, {sa_family=AF_INET6, sin6_port=htons(51555), inet_pton(AF_INET6, "::ffff:10.163.0.175", &sin6_addr), s... ... recvfrom(16,
这个现象和1.1中的是一致的
1.3 server端机器CPU、网络流量骤降
机器当时的ListenOverflows非常高:
CPU的利用率掉了一个坑:
网络传输量也掉了一个坑:
1.4 client端、server端同一个请求的日志时间对不上
头条内部可以使用logid搜索全量的后端日志构建调用链,从构建的调用链看,client端、server端对于同一个请求(logid相同)的处理时间跨度相差非常大。
例如我们从client端看到的日志是这样的:
TRACE 2017-03-24 03:47:52,282 10.163.0.175 2016102103475201016300017527503A cost=8740ms status=RPCTimedout …
而server端看到的日志是这样的(注意日志时间):
TRACE 2016-10-21 03:48:01,421 10.171.118.80 2016102103475201016300017527503A cost=4ms …
相当于从client发送请求开始,到client端超时返回,是在03:47:52,282。而神奇的server端竟然在client端已经返回的情况下,经过了9秒才看到这个“穿越”过来的请求,而且还>把它处理了,处理得还很快,只花了4ms,当server端想要返回数据的时候出现了错误日志[Error 107] Transport endpoint is not connected。
1.5 深夜2点时server端的日志突然停止又恢复
从现象来看有一段时间server端在无重启的情况下日志停止了数秒,后又恢复。
上面的现象比较多,简单总结最需要关注的点如下:
- TCP状态在client端和server端不一致;
- server的进程总是hung死在recvfrom上;
- 同一个请求的日志时间在client端和server端对应不上;
- 深夜时有什么东西导致了server端抖动,进程可能因为抖动而出现停止。
2 初步推论
根据上面的现象,我们列出以下几个可能的推论。
- client端在建连后没有执行close,导致server进程卡死。排除。在重新检视client端代码后,认为不会出现这个问题,即便出了这个问题,client端也应该能看到TCP连接。
- client端突然崩溃死机或者被拔网线了。排除。线上机器不会这么干,而且也解释不了为什么client和server的日志打印时间会差那么远。
- server端内部卡死,例如卡在读数据库或其它的IO操作上了。排除。从strace的结果来看,最后是卡在读客户端内容上(可以从strace中的fd看出来,上面的fd=16对应了客户端的连接套接字)。
- TCP的三次握手完成并不需要我们在代码中执行accept,而是系统底层默认完成握手。有可能。我以前总是认为只有客户端发起connect,然后服务端执行accept,才是建立了连接。但从上面的现象来说,感觉在应用层执行accept函数前,三次握手就已经完成了。如果真的是这样,那么对于server端来说,这个时候Read Buffer已经处于ready的状态,即client可以把请求直接发送到server端,然后server端等待应用层去读。一句话就是:server在代码执行accept之前,其实建连已经完成,并且client已经把请求的内容发到了server端。这就解释了为什么client的日志和server的连接accept日志在时间上对应不起来,但server又能处理这个“穿越”而来的请求。
- 深夜2点时有定时任务被执行,执行的时候导致业务的CPU或者IO被抢占从而无法处理正常的请求。有可能。咨询过不少写机器定时任务、预装脚本、网络组的同事,都没有在2点的时候做特殊的操作。以前也怀疑过是不是网络丢包导致FIN没有被收到,但这个解释不了为什么受影响的总是一个业务。关于这个暂时没有太多头绪。
- TCP连接存在一种不发FIN或者RST就能使得连接单方面直接关闭的方式。有可能?如果这都能信我就是颠覆了我对TCP的认识,为了验证不可能存在这种方法,最近一周看这方面的内容比大学四年加起来还多。
来看看最经典的TCP状态迁移图:
连接只要进入ESTABLISHED状态,无论后面怎么走到CLOSED,都一定会发送FIN,或者RST。
除非是从SYN_SENT状态进行关闭或者超市,但如果只是在SYN_SENT状态,客户端怎么可能发送请求数据给服务端?所以处于SYN_SENT状态的可能性很低。
上面的几个推论中,只要4、5、6都同时成立,那么就能解释所有看到的现象。
3 验证与复现
推论5是最快出结果的,因为有同事在观察到Redis出现抖动时,client端会报大量Could not connect to这样的错误,这些错误和晚上server卡死前的错误很像。
当时咨询了一下负责Redis的同学,发现会抖动是因为使用了存储型的Redis,其本身有Background Rewrite,定期把数据刷盘。而出问题的业务所访问的Redis会在凌晨2点一级早上10点发生刷盘操作。
服务队Redis的操作超时设置使用了默认的500ms,当刷盘时间持续较长时,每个请求的处理时间最多可以达到半秒,服务本身的单机QPS比较高,使用的是同步阻塞IO,服务端使用的是多进程模型,70个worker,因此一旦Redis的刷盘时间持续到了1秒,就会堆积约400 – (1 / 0.5) * 70 = 260个请求(凌晨2点QPS为400多),1s内堆积的260个请求中的最后一个要被处理完,也需要在260 / 70 * 0.5 = 1.8秒后,如果刷盘时间再长点,那么越往后的请求会越迟被处理。
上面的计算只是粗略的,不一定精确,但可以定性地认为在抖动期间每个请求的处理时间被大大延长,而这个时候处理能力不足(worker进程数少)会导致越往后的请求被叠加的处理时间越长。
解决的办法:
- 通过询问业务后,Redis可以不使用存储型的,这样就不会有Background Rewrite;
- 短期内可以提高工作进程数量,但长期来看还是要使用更先进的进程模型以及异步IO的方式。
3.2 推论4
推论4确实是对的,头条的线上机器(我感觉对于不少的Linux发行版也成立)三次握手的完成与否不取决于应用层是否执行了accept,而是由操作系统自动完成的。
自己做实验时,可以让server端在accept前sleep足够长的时间(超过client端的超时时间即可)。这时就会发现即便server没有`accept`且client已超时,在sleep结束后server依然能接收到一条穿越而来的请求。
在创建一个socket并对其进行listen时,我们会指定一个叫做“backlog”的参数:
int listen(int sockfd, int backlog);
backlog就是最大允许的队列等待长度,因为一个socket上可能同时来了多个连接,这些连接不可能在一瞬间就被处理完,在被accept前,这些连接需要在这个队列中进行等待。
当这个队列满了,后续的连接是不是就进不来了?并非如此,请看下文。
3.2.1 WAIT队列与ACCEPT队列
WAIT队列、ACCEPT队列这两个名字是我参考网上的说法起的。
当一个新连接到达时,实际这个连接会先被放到WAIT队列中,然后对该连接回复三次握手的第二个分节(SYN+ACK)。当ACCEPT队列没有满的时候,就会从WAIT队列的队头取一个连接放到ACCEPT队列。
连接进入ACCEPT队列后,就会等待应用层通过accept函数来将其取出。取出后ACCEPT队列又会腾出一个空位,WAIT队列中队头的连接又会被放到ACCEPT队列中,以此循环。
因此只要一个连接被server端放到ACCEPT队列,client端就会收到三次握手的第二个分节(SYN+ACK)并回复第三个分节(ACK)。
这就造成了即便server端的应用层没有执行accept,client端也会发送数据的现象。
示意图如下:
示意图表示的是同一时刻从client端视角和server端视角看连接的状态。
好了,现在有另一个问题:是不是只要进入了WAIT队列,就总有一天能飞升到ACCEPT队列? —— 不是的,取决于机器里面的一个参数: /proc/sys/net/ipv4/tcp_abort_on_overflow。
当这个值为0的时候:WAIT队列中的队头连接会检查是否可以进入ACCEPT队列,如果队列有位置,则放到ACCEPT队列,如果没有位置,则让连接继续待在WAIT队列中;
当这个值为1的时候:WAIT队列中的队头连接也会检查是否能进入ACCEPT队列,如果队列有位置,则放到ACCEPT队列,如果没有位置,则直接丢弃连接。
头条线上的机器值都是0,哪怕ACCEPT队列满了,WAIT队列的队头也不会被抛弃掉。
3.2.2 请求穿越
从上面的分析就知道请求穿越的具体原理了,场景如下:
- client连接server端,server端将连接放到WAIT队列中,并给client端回复了三次握手的第二个分节(SYN+ACK);
- client端收到了server端的SYN+ACK,于是回复ACK,三次握手完成,client端认为server端已经准备好接收数据了,于是发送请求数据;
- server端连接此时也进入了ACCEPT队列,client端的请求数据到达server端,被放到连接关联的read buffer中,由于应用层没有执行accept,因此请求数据没有得到实际处理;
- client端发现server端迟迟没有回复数据,发生超时,关闭了连接,并打印日志认为这次请求已经结束;
- 在server端过了一段时间,应用层执行了accept,从read buffer中读取到了请求数据,于是开始处理,处理完后打印日志认为请求处理完成。回写socket时发现client端已经关闭。
3.3 连接消失
(PS:需要注意的是,其实有了推论4和推论5之后,我们就基本有对应的解决方案了,但问题发生的详细机理还没理清)
明确了推论4和推论5,最后只剩下推论6 —— 是不是真的存在client端的连接能突然消失的情况光靠YY已经无法得出进一步结论了,试一下复现,万一真的复现就赚了。
我们构造了以下试验环境:
- 客户端:100个进程(不用线程,尽量保证和线上一致),使用与头条线上环境相似的client不断请求server;
- 服务端:server端只启动一个worker处理请求,这个worker监听的套接字对应backlog为4。
然后架设好所有的“摄像头”监控进程、网络状态,预先将strace以及tcpdump打开,strace用于查看进程系统调用情况,tcpdump在client端和server端都打开并将对应端口的数据包悉数保存。
现在只求上天保佑能复现一次(我到这一步已经持续追查这个问题4天以上了)。
在这里就不描写主人公在复现问题后欣喜若狂的心理细节。复现后我们将tcpdump的结果放到Wireshark中进行分析,如下图所示:
出于保密性的考虑以及便于理解,我将头条的IP全部替换成了client、server字样。
在client端和server端看到的包信息时一样的,client端确实没有发FIN或RST,然后连接就在client端莫名其妙地消失了。
从上图来看诡异的地方有这么几个:
- server端重传了三次握手的第二个分节(见编号68340、68891的SYN+ACK),但这个分节在一开始就传送过了(编号68023);
- client端一直在重传自己的数据(编号68133~68295,68341~68720),因为server端没有对这些数据包回复ACK;
- client端没有发送过FIN、RST,后面就再也没有交互了,与TCP状态迁移图中结束连接的流程不一致。
server端处于一个很奇怪的状态:它收到了client端发来的数据包(因为client和server端的tcpdump里都看到了这些包),但是却全部不回复ACK。
3.3.1 不断重传SYN+ACK的解释
在一筹莫展的时候找贴吧的老同事讨论,以下为保护联系人隐私,将其化名森神。森神分享了一篇文章: http://www.nosa.me/2015/09/16/%E5%85%B3%E4%BA%8E-tcp-syn-%E9%98%9F%E5%88%97%E5%92%8C-accept-%E9%98%9F%E5%88%97/,里面提到了一个比较关键的思路:
- 若/proc/sys/net/ipv/tcp_abort_on_overflow为0且ACCEPT队列满,则WAIT队列队头的连接会丢弃它收到的ACK及数据包,如果它不忽略三次握手的第三个分节(ACK),则它会变成ESTABLISHED状态,这种状态要求它必须进入ACCEPT队列,这和ACCEPT队列已经满的现状冲突,所以它必须忽略三次握手的第三个分节;
- 当服务端的连接处于SYN_RECV状态时,它会一直尝试发送三次握手的第二个分节(SYN+ACK)给client端,因为服务端“可能”觉得自己没有进入ESTABLISHED状态的原因是client端没有发送ACK。这里说“可能”是因为我没找到直接证据,只是这种猜测和现象极其吻合。
这样Wireshark抓包的结果就有了一个解释:
- server端的连接在WAIT队列中,连接状态为SYN_RECV,这个时候三次握手第二分节(SYN+ACK)已经从server端发出,server端等待三次握手第三分节(ACK);
- client端收到了SYN+ACK,(高兴地?)发送了三次握手第三分节(ACK)给server端;
- server端收到这个ACK后,看了一下ACCEPT队列,发现满了,所以不能接受这个ACK,直接丢弃掉,连接因此保持在SYN_RECV状态;
- 由于TCP的三次握手成功就认为建连成功,因此client端与server端在经过上述第3步后就产生了偏差,client端认为建连成功进入ESTABLISHED状态,server端认为建连没有成功处于SYN_RECV状态(实际是它自己把别人送给它的ACK给丢了);
- client端进入ESTABLISHED状态,就开始发送数据包给server端,server端收到数据包后也会像没事一样直接丢弃(从tcpdump没看到server端对数据包回复ACK);
- server端过了一会儿检查了连接,发现仍然处在SYN_RECV状态,认为是client端没有收到自己刚才发送的三次握手第二分节(SYN+ACK),于是又发送了一遍;
- client端突然收到了server端重发的SYN+ACK,礼貌性地回复了一个ACK,希望server端知道建连已经成功了(老铁);
- 过了一段时间(在达到tcp_synack_retries次数前?),server端的ACCEPT队列终于有了位置,连接被从WAIT队列取出放到ACCEPT队列中,这个时候server端的连接才真正进入了ESTABLISHED状态,不会重发SYN+ACK;
- 然后诡异的是client端就没音讯了,server端由于处在阻塞读阶段,因此卡住。
上述行为的示意图如下:
这样就能解释连接在消失前的大部分行为了。
只剩最后一个硬骨头:client端的连接是怎么从ESTABLISHED直接变成CLOSED的?
4 最后的推论6
文过三巡,再复述一下推论6:TCP连接存在一种不发FIN或者RST就能使得连接直接关闭的方式。
现在问题不在于推论6是否正确,因为现象明确了推论6肯定是正确的,问题在于推论6在什么情况下才能够发生。
这里先直接说结论,Linux在发送超时重传达到给定次数后,便会直接释放连接,可以从ESTABLISHED直接变为CLOSED状态。
具体可以参见内核源码中的tcp_write_timeout函数(https://github.com/torvalds/linux/blob/ae50dfd61665086e617cc9e554a1285d52765670/net/ipv4/tcp_timer.c#L179),在判断所有重传都失败后会执行tcp_write_err。
在tcp_write_err中会执行tcp_done(https://github.com/torvalds/linux/blob/ae50dfd61665086e617cc9e554a1285d52765670/net/ipv4/tcp_timer.c#L34):
static void tcp_write_err(struct sock * sk) { sk->sk_err = sk->sk_err_soft ? : ETIMEDOUT; sk->sk_error_report(sk); tcp_done(sk); __NET_INC_STATS(sock_net(sk), LINUX_MIB_TCPABORTONTIMEOUT); }
最后再看看tcp_done里面干了什么(https://github.com/torvalds/linux/blob/d038e3dcfff6e3de132726a9c7174d8170032aa4/net/ipv4/tcp.c#L3281):
void tcp_done(struct sock * sk) { struct request_sock *req = tcp_sk(sk)->fastopen_rsk; if (sk->sk_state == TCP_SYN_SENT || sk->sk_state == TCP_SYN_RECV) TCP_INC_STATS(sock_net(sk), TCP_MIB_ATTEMPTFAILS); tcp_set_state(sk, TCP_CLOSE); tcp_clear_xmit_timers(sk); if (req) reqsk_fastopen_remove(sk, req, false); sk->sk_shutdown = SHUTDOWN_MASK; if (!sock_flag(sk, SOCK_DEAD)) sk->sk_state_change(sk); else inet_csk_destroy_sock(sk); }
在里面会直接将连接的状态设置为CLOSED —— tcp_set_state(sk, TCP_CLOSE)。
上面只是代码的冰山一角,而且实际在写这篇文章前我们是先构造出了场景确认行为后,再看代码。
为了方便观察,我们要构造以下的场景:
- 从client端的角度看,client端与server端要建连成功;
- client端因为建连成功,所以可以发送数据包,它需要不断重复发送一个数据包,直到重传超时;
- server端对所有的数据包都不予回应(不回复ACK)。
如果有兴趣亲身体会一下整个过程的,可以见下面4.1部分,没有兴趣的可以直接跳到4.2看构造的结果截图。
4.1 构造连接消失的场景
找两台能互相连通的机器,一台作为client端,一台作为server端,并确保你拥有一个足够权限的账户(例如root)来执行下列所有操作。
另外是请记下你的client端ip与server端ip,下面涉及到的命令中,请大家将“{client端ip}”替换成你们自己的client端ip地址,将“{server端ip}”替换成你们自己的server端ip地址。
同时下面在修改TCP参数前,可以通过cat命令记录一下修改前的数据,例如要修改/proc/sys/net/ipv4/tcp_retries1,可以先通过cat /proc/sys/net/ipv4/tcp_retries1查看一下它原本的值是多少。
4.1.1 client端的准备工作
在client端使用gcc命令gcc client.c -o client编译以下代码,得到可执行的client文件:
// @file: client.c #include <errno.h> #include <memory.h> #include <netdb.h> #include <stdio.h> #include <sys/socket.h> #include <sys/types.h> #define BUFLEN 128 int main(int argc, char *argv[]) { // wait char c; scanf("%c", &c); struct addrinfo *ailist, *aip; struct addrinfo hint; int sockfd, err, n; memset(&hint, 0, sizeof(hint)); hint.ai_socktype = SOCK_STREAM; hint.ai_canonname = NULL; hint.ai_addr = NULL; hint.ai_next = NULL; if (getaddrinfo("{server端ip}", "2095", &hint, &ailist) != 0 || ailist == NULL) { // 请注意将上面的 {server端ip} 替换成你的server端对应ip printf("getaddrinfo failed.\n"); return 1; } aip = ailist; sockfd = socket(aip->ai_family, aip->ai_socktype, aip->ai_protocol); if (sockfd == -1) { printf("Create socket failed.\n"); return 2; } // connect err = connect(sockfd, aip->ai_addr, aip->ai_addrlen); if (err != 0) { printf("connect failed.\n"); return 3; } char buf[BUFLEN] = "hello from c client\n\0"; // send n = send(sockfd, buf, strlen(buf), 0); printf("Sent %d. Errno is %d\n", n, errno); // recv n = recv(sockfd, buf, BUFLEN, 0); printf("Received %d. Errno is %d\n", n, errno); return 0; }
在client端命令行依次执行下列命令设置TCP参数(执行前可以先保存旧的参数值):
root@client$ echo 3 > /proc/sys/net/ipv4/tcp_retries1 root@client$ echo 3 > /proc/sys/net/ipv4/tcp_retries2 root@client$ echo 3 > /proc/sys/net/ipv4/tcp_syn_retries root@client$ echo 2 > /proc/sys/net/ipv4/tcp_synack_retries root@client$
打开三个命令行的窗口,下面以窗口1~3称呼。
在client端窗口2先开启tcpdump进行抓包:
root@client$ tcpdump -i enp0s3 ip host {server端ip} -w client.cap tcpdump: listening on ..., link-type ..., capture size ... bytes
需要注意的是上述的enp0s3请替换成你自己的网卡接口,普通的机器会是eth0等,可以通过ifconfig命令查看自己的client端ip对应的是那个网卡接口。
在client端窗口1运行编译好的client二进制文件,执行命令:./client。
这个时候client还没开始工作,等输入一个字符并回车后,client才开始于server通信(现在先别回车)。
在client端窗口3可以准备好这条命令date +’%F %T.%N’ && netstat -apn | grep ‘:2095’。这样在client、server开始通信后可以观察到TCP连接状态。
4.1.2 server端的准备工作
在server端通过gcc命令gcc server.c -o server编译以下代码得到可执行文件server:
// @file: server.c #include <errno.h> #include <memory.h> #include <netdb.h> #include <stdio.h> #include <sys/socket.h> #include <sys/types.h> int init_server() { int err; int sockfd = socket(AF_INET, SOCK_STREAM, 0); if(sockfd < 0) { printf("Create socket error.\n"); return sockfd; } int reuse = 1; if(setsockopt(sockfd, SOL_SOCKET, SO_REUSEADDR, &reuse, sizeof(reuse)) < 0) { printf("setsockopt error\n"); close(sockfd); return -1; } struct sockaddr_in addr; memset(&addr, 0, sizeof(addr)); addr.sin_family = AF_INET; addr.sin_port = htons(2095); addr.sin_addr.s_addr = inet_addr("{server端ip}"); // 记得将{server端ip}替换成自己的server端地址 if((err = bind(sockfd, (struct sockaddr *)&addr, sizeof(addr))) < 0) { close(sockfd); printf("Bind address error.\n"); return -1; } if((err = listen(sockfd, 4)) < 0) { close(sockfd); printf("Listen error.\n"); return -1; } return sockfd; } int main(int argc, char *argv[]) { int listen_sock = init_server(); if (listen_sock < 0) { printf("init server failed.\n"); return -1; } int client_addr_len = 0; struct sockaddr_in client_addr; char buf[2048]; int clientfd = accept( listen_sock, (struct sockaddr *)&client_addr, &client_addr_len); if (clientfd < 0) { printf("Accept client error\n"); return -1; } while (1) { int n = read(clientfd, buf, 1024); if (n == 0) { printf("Client closed connection\n"); return 0; } if (n < 0) { printf("Read socket error: %d, %s\n", errno, strerror(errno)); return -1; } buf[n] = '\0'; printf("%s", buf); fflush(stdout); n = write(clientfd, buf, n); } return 0; }
在server端命令行执行下列命令设置TCP参数:
root@server$ echo 10 > /proc/sys/net/ipv4/tcp_synack_retries root@server$
然后我们使用iptables命令使得server端对于来自client端的包进行全部丢弃,除了带SYN标记的包外。最后使用iptables -nL查看规则是否创建成功:
root@server$ iptables -I INPUT -s {client端ip} -p tcp -j DROP root@server$ iptables -I INPUT -p tcp --tcp-flags ALL SYN -j ACCEPT root@server$ iptables -nL Chain INPUT (policy ACCEPT) target prot opt source destination ACCEPT tcp -- 0.0.0.0/0 0.0.0.0/0 tcp flags:0x3F/0x02 DROP tcp -- {client端ip } 0.0.0.0/0 Chain FORWARD (policy ACCEPT) target prot opt source destination Chain OUTPUT (policy ACCEPT) target prot opt source destination
上面记得将命令中的client端ip地址进行替换。
然后打开两个窗口1~2。
在server端的窗口2开启tcpdump进行抓包:
root@server$ tcpdump -i enp0s3 ip host {client端ip地址} -w server.cap tcpdump: listening on ..., link-type ... capture size ... bytes
同样的上面的enp0s3替换成你的server端ip对应的网卡接口,{client端ip}替换成你的client端地址。
在server端的窗口1中运行编译好的server二进制文件,执行命令:./server。
4.1.3 开始观察
下面我们就可以开始观察了,在client端的窗口1,敲入一个字符(一个字符就好),然后回车,client端就开始工作了,这个时候迅速切换到client端的窗口3,不断执行命令date +’%F %T.%N’ && netstat -apn | grep ‘:2095’,查看TCP连接的变化,就可以观察到连接从ESTABLISHED突然消失。
在连接消失后,分别到client端的窗口2与server端的窗口2按Ctrl-C终止tcpdump,这样我们就分别得到了两个抓包记录client.cap与server.cap,可以下载Wireshark软件
打开这两个包以client/server端角度观察TCP连接的整个过程。
观察结束后,就可以将TCP参数重置成你设置前的内容,或者直接重启系统。
对于server端的iptables设置,如果你确认直接没有其它iptables规则,那么可以通过命令iptables -F清除掉,如果不想清除所有规则,就一条一条对着删就行。
4.2 现象截图
通过4.1的步骤,在client端上不断使用netstat可以看到的现象如下:
连接从2017-03-29 17:37:54.726070386就为ESTABLISHED状态,一直持续到2017-03-29 17:37:59.524452336,然后在2017-03-29 17:37:59.890126826突然消失,中间没有经过任何其它状态。
再来看看tcpdump的结果,client.cap与server.cap观察到的是一样的,所以下面只贴出client.cap的结果:
可能有人有疑问,不是说ESTABLISHED到CLOSED不发FIN或者RST吗,为什么图里面有个RST呢?
可以看一下这个RST发出的时间是2017-03-29 17:38:00.131660,而我们在client端上通过netstat看的连接在2017-03-29 17:37:59.890126826时就已经没有了,因此这个RST是在连接消失后才发送的,发送的原因就在于这个连接已经不存在了,但是server端还在尝试往该连接发送SYN+ACK,而操作系统直接就通过RST希望重置server端的连接。
结合netstat与tcpdump的结果,client端的连接确实在ESTABLISHED状态直接就变成CLOSED,而且转变之前不需要发送FIN或者RST。
另外一个细节是,在4.1.3中,client端代码在recv阶段会返回110错误,有一篇文章(http://blog.csdn.net/u010419967/article/details/24405037)进行了关键解释:
在程序中表现为,当tcp检测到对端socket不再可用时(不能发出探测包,或探测包没有收到ACK的响应包),select会返回socket可读,并且在recv时返回-1,同时置上errno为ETIMEDOUT。
关于超时重传更多代码上的分析,可以见源码,也可以与这篇博客一起对照查看:http://blog.csdn.net/zhangskd/article/details/35281345。
我们相当于从代码、现象两个角度证实了推论6。
5 结论
5.1 请求穿越的发生
- 该业务依赖的Redis是存储型的,在凌晨2点进行Background Rewrite,这个持续时间非常长,对Redis的读超时过长导致一瞬间大量Worker会卡在读Redis上;
- 该业务在凌晨2点时,由于进程处理速度过慢,导致ACCEPT队列中的连接被处理的速度非常慢;
- 当连接位于ACCEPT队列时,实际对于client端、server端而言三次握手就成功了(应用层不需要执行accept),因此client端此时就已经将数据发送到server端了,server将数据存在read buffer中;
- server端在应用层accept时,取到的连接有可能是在几秒或者几十秒前建立的,这时client端早已超时结束请求并打出日志,而server端发现可以从连接中读出数据,于是处理了请求并打出日志,造成了“请求穿越”的现象。
5.2 server端hung死的原因
- server端在抖动之后一直处于处理能力不足的状态,ACCEPT队列满,因此WAIT队列中的连接一直没法从SYN_RECV状态转换为ESTABLISHED状态,server端系统发现连接一直处于SYN_RECV状态,所以认为client端没有回复三次握手的第三个分节(ACK),因此不断重传SYN+ACK;
- client端一直在发送数据包,但由于server端设置了/proc/sys/net/ipv4/tcp_abort_on_overflow为0,因此在ACCEPT队列没有空位前,会丢弃掉自己接收到的ACK与数据包;
- client端一直没有收到server端对数据包的ACK,于是不断重传数据包,同样server端也因为自己处于SYN_RECV状态,不断重传SYN+ACK。现场一片混乱;
- 最终client端没有耐心了,底层判断连接的server端已经处于不可用状态,遂静默关闭一个ESTABLISHED状态的连接,没发RST与FIN,直接进入CLOSED状态;
- 而不幸的是此时server端的ACCEPT队列刚好有了空位,WAIT队列中这个连接转正进入了ACCEPT队列,因此server端不会再往client端发送SYN+ACK(这样client端就不会回复RST把连接reset掉),同时client端因为早就丢弃了连接也不会往server端发送数据包(这样server端连接的read buffer中就不会有数据);
- 最终server端执行accept,执行完便立即执行recv,由于此时read buffer中无数据,所以server端就hung死了,也直接导致了在client端已经看不到连接,但在server端还能看到一个处于ESTABLISHED状态的连接。
可以看到上面最重要的是第5步的时机,client端刚好丢弃连接,server端连接刚好进入ACCEPT队列从而不发SYN+ACK避免了被reset。
6 解决方案
知道了整个事情的起因,解决方案就好说了:
- 该业务部适用存储型Redis,并对Redis的读超时进行更合理的设置;
- server端的连接开启keepalive,以确保出现极端情况时最终能恢复;
- 业务根据需求进行扩容或重构、迁移到具有更先进服务模型的方案上。
7 总结
对于不知道上述TCP知识的人(例如我)来说,这次追查真的是费尽九牛二虎之力,但也因为追查才了解到有WAIT队列、ACCEPT队列(应用层不用执行accept就建连成功)、ESTABLISHED直接到CLOSED状态等颠覆我以往认识的内容。
在线上机器中,为了内网连接的Fail Fast,会将tcp_retries2等参数调小,这样client端在发现连接不上时不会持续数分钟的发包重传,占用网络资源。当然实际各个TCP参数调成多少要根据线上环境决定。
以上内容都是出于我个人的观察总结,如果文中有任何地方描述有问题或者不完善,欢迎大家指出。
- 真·在Mac英文版Chrome下使用印象笔记
- 一种低成本的分布式调用追踪系统方案
萌新瑟瑟发抖。(崇拜脸)233