微信号:QunarTL

介绍:Qunar技术沙龙是去哪儿网工程师小伙伴以及业界小伙伴们的学习交流平台.我们会分享Qunar和业界最前沿的热门技术趋势和话题;为中高端技术同学提供一个自由的技术交流和学习分享平台.

一个故障带你逐步串起TCP

2018-11-06 09:00 龚珂

看了就要关注我,喵呜~

龚珂,2014年加入Qunar机票事业部, 热爱生活, 喜欢吃喝玩乐, 不带眼睛, 不穿格子衫, 是个非典型的程序员。


本文通过对一次故障的逐步分析,带你一步步定位分析问题的原因,逐步了解TCP相关状态及其影响,及系统/TOMCAT与TCP连接之前千丝万缕的关系。

1.故障现象

通过监控我们发现,业务量会突然掉下来,然后通过重启可以恢复,但维持30分钟左右,业务量又会掉下来,其中的低点为我们重启服务器的时间。

业务监控

通过机器指标,我们发现一些异常监控:

TCP TIME_WAIT数量

TCP CLOSE_WAIT数量

TCP SYN_RECV数量

其他JVM,CPU,LOAD监控均正常。 从以上的监控,能帮助我们定位分析出问题么?

2.问题的定位

这里,我们从另外一个角度,从TCP连接状态这几个监控出发,看看能不能帮助我们定位,分析出问题的所在。

2.1问题的抛出

首先我们根据监控, 抛出几个问题:

• TIMEWAIT数量很多,正常么? • CLOSEWAIT持续增长,正常么? • 为什么CLOSEWAIT增长到200,RECV就开始上升,同时TIMEWAIT就开始下降? • SYN_RECV增长,正常么?

2.2问题的解答

要明白这些问题,我们就要理解TCP三次握手,以及四次握手的过程,及客户端与服务端的状态,这是我们网上经常能看到的一张图。

2.2.1 TIME_WAIT数量很多,正常么?

从图中可以看到,TIMEWAIT是主动关闭连接一方保持的状态。简单来说,TIMEWAIT是TCP关闭过程中,一个正常的状态,然后会保持2*MSL(通常linux系统是1分钟)之后,释放连接。

为什么要保持TIME_WAIT 2*MSL时间?

其中一个原因是,因为客户端无法保证最后一个ack一定发送成功,所以当服务器没有收到最后一个ack时,会重新发送fin,客户端保持TIME_WAIT就是为了能重新给服务端发送ack,如果客户端直接CLOSE,那么被动关闭发出重传FIN包到达,可能出现的问题是: 旧的连接不存在,系统只能返回RST包;新的TCP连接已经建立,延迟包可能会干扰新连接,这都可能导致TCP不可靠。

怎么优化TIME_WAIT数量?

注意! 通常网上资料会这么推荐我们。但这里不推荐这么配置。

修改 /etc/sysctl.conf: net.ipv4.tcptwreuse = 1 表示开启重用。允许将TIME-WAIT sockets重新用于新的TCP连接,默认为0,表示关闭; net.ipv4.tcptwrecycle = 1 表示开启TCP连接中TIME-WAIT sockets的快速回收,默认为0,表示关闭; net.ipv4.tcpfintimeout = 30 

部分文章可能直接解读 “tcpfintimeout就是MSL时间,调小可以减少TIMEWAIT状态的时间。” 这首先就是错的,MSL是系统写死的时间,linux通常是30s。这个参数的意思是TCP从FINWAIT2转换到TIME_WAIT的超时时间。

TIME_WAIT量多少是正常?

通常,我们服务器上TIMEWAIT状态数量是趋于稳定的(而且这个状态的连接占用的内存是很小的),这个值多少是正常的? • 对于客户端来说,这个值不要超过服务器可分配的端口数量; 通过命令 "cat /proc/sys/net/ipv4/iplocalportrange" 可以查看端口范围; 32768 61000
表示端口会建立在32768-61000范围内分配,表示跟同一服务器能同时建立约不到3w个端口连接; • 对于服务器端来说,这个值不要超过ipcontrackmax配置。系统会有一张表记录所有的TCP请求,TCP协议中用四元组(源IP/PORTt+目的IP/PORT)唯一标识一个连接,这个数量默认是65536。 但如果TIMEWAIT生产的速度>消耗的速度,服务器就会逐步累积起大量的TIMEWAIT。不管是在客户端还是服务端这个都是有问题的。

如何解决TIME_WAIT持续增长的问题?

• 最合适的解决办法是增加更多的四元组,简单说就是扩容,增加更多的服务器ip或者可用端口。 • 在某些场景下,尽可能用长连接代替短连接,并设置合理的keepalive。

结论

• 服务器上TIME_WAIT多是一个正常现象,只要在合理范围内,就不会对服务器产生影响。 • 不要盲目的设置reuse/recycle,2MSL存在即合理。

2.2.2 CLOSE_WAIT持续增长,正常么?

从图中可以看到,如果一直维持在CLOSE_WAIT状态,那就只有一种情况,就是对方关闭连接之后,服务器没有进一步发出ACK。 换句话说,就是在对方连接关闭之后,程序里没有检测到,或者程序压根就忘记了这个时候需要关闭连接,于是这个资源就一直被程序占着。 服务器对于程序抢占的资源没有主动回收的权利,除非终止程序运行。

怎么解决CLOSE_WAIT持续增长的问题?

排查代码!!

哪些情况, 会造成CLOSE_WAIT出现?

• 请求没有释放,通常是由于我们写代码的bug,使用完http之后,没有release相关资源。 • 客户端由于超时,主动关闭了连接,同时服务器端没有及时释放。 第一种情况比较好理解,这里主要说下第二种情况,也是我们这次故障产生的原因。通过排查异常日志,一段异常引起了我们的注意。

 
           
  1. ZooKeeperWatcher.keeperException:445 [keeperException] quorum=${ZKHOST}:${ZKPORT}, baseZNode=/hbase/xxxx Received unexpected KeeperException, re-throwing exception

  2. org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss for /hbase/xxxx

  3. at org.apache.zookeeper.KeeperException.create(KeeperException.java:99) ~[zookeeper-3.4.5.jar:3.4.5-1392090]

  4. at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) ~[zookeeper-3.4.5.jar:3.4.5-1392090]

  5. at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151) ~[zookeeper-3.4.5.jar:3.4.5-1392090] at org.apache.hadoop.hbase.zookeeper.RecoverableZooKeeper.getData(RecoverableZooKeeper.java:358) ~[hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  6. at org.apache.hadoop.hbase.zookeeper.ZKUtil.getData(ZKUtil.java:683) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  7. at org.apache.hadoop.hbase.zookeeper.ZKUtil.blockUntilAvailable(ZKUtil.java:1835) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  8. at org.apache.hadoop.hbase.zookeeper.MetaRegionTracker.blockUntilAvailable(MetaRegionTracker.java:183) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  9. at org.apache.hadoop.hbase.client.ZooKeeperRegistry.getMetaRegionLocation(ZooKeeperRegistry.java:58) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  10. at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.locateRegion(HConnectionManager.java:1087) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  11. at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.locateRegionInMeta(HConnectionManager.java:1181) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  12. at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.locateRegion(HConnectionManager.java:1090) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  13. at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.locateRegion(HConnectionManager.java:1047) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  14. at org.apache.hadoop.hbase.client.HConnectionManager$HConnectionImplementation.getRegionLocation(HConnectionManager.java:888) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  15. at org.apache.hadoop.hbase.client.RegionServerCallable.prepare(RegionServerCallable.java:72) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  16. at org.apache.hadoop.hbase.client.RpcRetryingCaller.callWithRetries(RpcRetryingCaller.java:113) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

  17. at org.apache.hadoop.hbase.client.HTable.get(HTable.java:780) [hbase-client-0.98.6-hadoop2.jar:0.98.6-hadoop2]

逐步深入源码,在apache hbase连接zk中我们发现:

当getData失败之后,程序会在一个timeout时间之内以一定的间隔不停进行重试。而这个timeout,我们配置的是300000ms,也就是5min....

至此, 问题的原因已经查明

• 由于当时dba zk故障,ops为了降低zk压力,将一批服务器加入了zk的黑名单,导致程序连接zk获取不到数据; • 获取不到zk数据,程序在5min之内,不停进行retry,导致TCP连接一直没有释放; • 调用方的超时时间是2s,所以当调用端关闭连接之后,服务端进入了CLOSE_WAIT状态,并持续增长。

结论

• 出现大量CLOSE_WAIT,就代表一种错误信息,需要解决; • 通常是代码错误,或者使用不当引起的;

2.2.3 为什么CLOSEWAIT增长到200,RECV就开始上升,同时TIMEWAIT就开始下降?

看到200,我们会想到什么?

我第一反应是tomcat的线程数量。tomcat的配置如下:

<Connector port="8080" protocol="HTTP/1.1"

               maxThreads="200" connectionTimeout="20000"

               enableLookups="false" compression="on"

               redirectPort="8443"

               URIEncoding="UTF-8" />

这样我们就很容易得出结论了,其中RECV的问题,我们在后面一并进行说明。

结论

• CLOSEWAIT导致连接资源一直没有释放; • 打满tomcat连接线程池后,tomcat不能再接收新的请求; • 处于TIMEWAIT状态的套接字经过2*MSL,linux默认1分钟后,都进行了释放,所以TIME_WAIT的数量马上降为0。

2.2.4 SYN_RECV增长,正常么?

再重温下这张经典的图,我们监控显示的SYNRECV其实就对应SYNRCVD这个状态。所以如果保持在这个状态,那说明是在TCP建立连接三次握手过程中,服务器收到了第一次握手后,并没有发出第二次握手,还是说没有收到第三次握手? 没有发出第二次握手? 还是没有收到第三次握手? 答案是,都不是!这里我们就要隆重介绍两个新的名词:  • 全连接队列 • 半连接度队列

什么是全连接队列,半连接队列?

我们可以理解为 • 服务端系统在建立TCP连接时,维护了两个队列,即半连接队列(syns queue),全连接队列(accept queue); • 当服务端发出第二次握手(SYN+ACK)后,会将连接加入半连接队列,这时的状态是SYNRCVD; • 收到第三次握手后,如果全连接队列没满,会将连接从半连接队列拿出,放入全连接队列,同时状态置为ESTABLISHED; 所以当服务器不断出现SYNCRECV,是有问题的。说明全连接队列满了,处于RECV状态的请求无法加入到全连接队列进行建立,处于一种请求阻塞的状态。

怎么知道全连接队列满了?(以下看源文件)

 
           
  1. >>ss -lnt

  2. State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port 

  3. LISTEN     0      50                        *:20077                    *:*     

  4. LISTEN     0      100                       *:8080                     *:*     

  5. LISTEN     0      50                        *:20889                    *:*     

  6. LISTEN     0      100               127.0.0.1:25                       *:*     

  7. LISTEN     0      1                 127.0.0.1:8005                     *:*  

通过命令"ss lnt"我们可以查看服务端口设定的全连接队列情况,第三列Send-Q即为端口可接收的全连接队列长度,第二列Recv-Q为当前全连接队列占用的情况。 我们可以看到8080端口是我们的tomcat服务,默认是100队列长度。20889是dubbo端口,默认50。

 当出问题的时候, 第二列会看到请求堆积:

 
           
  1. >>netstat -s | grep 'listen'

  2. 214204 times the listen queue of a socket overflowed

"netstat -s"是我们一般没有注意过的命令,非常强大,记录了服务器从启动到现在所有网络流量,网络协议的统计数据,信息量很大,推荐多去看看。 其中"listen"这一行,显示的数字即为全连接队列满了之后连接无法加入全连接队列,溢出的数量。 如果这个数量很大,或者一直增长,就说明系统存在问题。 这个值增长的时候,如果执行"ss -lnt"一定会发现Recv-Q是满的了,当然全连接队列也好,半连接队列也好,都有办法进行调整。

全连接队列跟服务线程是什么关系?

可以理解为 • 请求建立连接的过程,是先通过半连接队列->全连接队列,然后再从全连接队列取出分配给服务线程进行处理; • 所以通常半连接队列,全连接队列是空的,因为tcp建立的过程都是瞬时完成的; • 如果出现全连接队列堆积,就说明服务线程吞吐产生了问题,无法将请求分配给服务线程进行数据传输。

结论

• 服务器出现SYNC_RECV状态堆积,说明服务出问题了; • 原因通常是服务线程首先出现了堆积,从而导致建立连接的全连接队列阻塞, 产生的影响就是外部的http请求阻塞; • 通过命令"ss -lnt"及"netstat -s | grep 'listen'" 可以有效的定位这个情况; • 根据实际情况,可以适当调大全连接队列,但核心问题还是要解决服务线程的吞吐。

3. 故障原因概述

上面我们从服务器TCP连接状态出发,抛出了我们的问题,并一一对每个状态进行了深入的介绍,也定位出了故障产生的原因。这里在对整个故障进行一个复盘。

这是一个简单的系统调用过程。

1、上层系统向我们系统发出请求获取数据;

2、我们通过zk获取hbase配置信息;

3、调用hbase获取数据, 进行返回。

3.1 故障表现

• 业务监控量下降; • 服务器CLOSEWAIT持续上升,TIMEWAIT下降,SYNC_RECV上升。

3.2 故障原因

• 故障的起因是因为ZK由于某些原因,临时将我们系统ip加入了黑名单,导致我们系统通过zk无法获取配置信息; • 通过代码定位,看到连zk的client代码在获取不到数据后,会在一个TIMEOUT时间内,反复进行重试; • 我们TIMEOUT设置不合理(5分钟),导致tomcat线程一直被占用,没有释放; • 同时上层系统,对我们进行了降级,2s的超时断开连接,造成了CLOSE_WAIT的产生,并持续积累; • 一段时间后,tomcat200个线程池占满后,导致新的请求无法进行处理,业务监控下降。

3.3 故障解决

设置合理的zk连接超时时间。

4. 总结

本文的重点不在故障具体的原因,目的是希望通过故障,通过监控情况的展示,逐步深入TCP协议,状态的流转,让我们更深入的明白TIMEWAIT,CLOSEWAIT,SYNCRECV产生的原因,对服务器造成的影响,以及如何分析、定位,解决问题。 • TIMEWAIT多不可怕,只要稳定在合理的区间,不要轻易的设置reuse,recycle; • CLOSEWAIT多非常可怕,一定是服务端程序出现了问题。重点排查跟网络连接相关代码; • CLOSEWAIT很有可能占满服务端线程,造成服务不可用; • 了解SYNCRECV的产生过程,请求->半连接队列->全连接队列->服务线程; • 出现SYNCRECV,也说明服务出现了问题,服务线程阻塞。

相关参考

https://mp.weixin.qq.com/s_biz=MjM5ODI5Njc2MA==&mid=2655819541&idx=1&sn=2a37c206702b7b67c3ae30bf4c3f677b&chkm=bd74dac28a0353d45fe0a3d09ee57c181eb5b70d022e3c718842a57463db864161c96dddc9ec&scene=21#wechatredirect https://www.cnblogs.com/sunxucool/p/3449068.html https://blog.csdn.net/Howinfun/article/details/81010177 https://blog.csdn.net/achejq/article/details/51784212?utm_source=blogxgwz0 https://www.cnblogs.com/javawebsoa/archive/2013/05/18/3086034.html


 
Qunar技术沙龙 更多文章 互联网公司时尚穿搭指南 缓存技术原理浅析 Qunar首届CodeReview大赛报名开始啦! 阿里巴巴为什么选择Apache Flink? 2017年应届生回归大会圆满结束
猜您喜欢 群蚁算法理论与实践全攻略 记一次 Epub 阅读器同步功能 JSP入门教程 【大宝】设计中的色彩使用,学会这几招足矣! 辞职后,我后悔的12件事