关于一次tcp网络拥堵的问题排查与解决

简介

最近线上应用再次发生了TCP接收拥堵，还记的上次服务发生拥堵时我将数据写入Kafka，由Kafka进行削峰异步消费数据，且去除了MongoDB副本来解决磁盘I/O的瓶颈，那为何在运行了几个月后TCP接收缓冲区为何又发生了拥堵？经过一番排查后这里记录一下解决问题的过程和方法。

故障重现

日常服务器监控中通过netstat -tnp |grep port发现一个基于TCP构建的应用层服务中，其端口下的TCP连接Recv-Q接收缓存中产生了大量的堵塞每个通道大概阻塞了1w到20w个字节不等，而收到消息后应用并没有太多的逻辑，只是将消息写入Kafka供下游消费者去消费入库，通过 kafka-consumer-groups 命令查看Kafka的消费组每个消费者的偏移量，发现有没有消费迟滞，又通过top,iostat，java的gc日志去分析 并没有发现异常，但是通过netstat -ts查看系统tcp通讯信息发现failed connection attemptstcp重连次数增长的很快。

TCP抓包

既然是tcp网络问题，又找不到下游处理异常，那第一个想到就是抓包，在linux中通过执行以下tcpdump命令对指定端口和网卡进行抓包并且将数据写入/home/info.pcap文件下

tcpdump -i eth0 port 8080 -w /home/info.pcap

由于执行tcpdump中我并没有指定- c参数指定抓取信息条数，所以这个命令会一直抓取数据，所以在执行几分钟后我手动执行Ctrl + c结束了数据抓取。

将抓取的抓包数据导入到抓包分析工具Wireshark中，

因为抓取的是所有的Tcp通讯信息，所有我们这里只要指定一个tcp连接来分析具体情况

所以在过滤器栏中输入ip.addr == ip要查找过滤的IP，抓取的结果部分截图如下

我们大致可以看到字段如下

• Time 抓取时间戳
• Source 消息的来源IP
• Destination 消息的目的地址IP，这里一般就是你运行tcpdump抓包的机器的IP
• Protcol 抓取的协议，我抓取的都是tcp包，所以这里都显示tcp
• Length 这个消息包的长度，单位字节
• Info tcp消息的具体信息[PSH,ACK]代表的是数据传输 [ACK]代表的是服务端收到消息TCP返回的应答，同理，还有SYN,[SYN,ACK]，代表着TCP连接的三次握手，seq代表着是tcp的序列号，len是tcp的消息体长度，我们可以看到但数据传输时tcp客户端会将当期客户端数据传输的seq序列传给服务端，服务端收到后将Len+seq 的值回传给客户端，告诉客户端下一次上传的seq序列，从而保证tcp传输的可靠性。

在通过对抓包的数据进行浏览后，发现tcp存在ZeroWindow异常

这是由于tcp在发送数据时为了传输效率等原因，不会立马把数据发送出去，而是先将数据发送到缓冲区，然后再发送给服务端，同理服务端也有一个tcp接受的缓冲区,而Linux netstat网络监控命令中对于的Recv-Q和Send-Q字段则分别代表了监控端口的tcp接受缓存，和发送缓存。

问题的解决过程

增加Netty工作线程数

我的第一反应就是Netty的工作现场太少，导致消息无法被线程池及时消费，但是通过top -Hp pid去分析应用现场，发现Netty的工作线程大部分cpu利用资源都很低，而且应用没有执行什么太多的逻辑，所以不太可能是线程不够，但是秉着死马当活马医的态度，我还是尝试增大Netty的工作线程，结果可想而知，肯定是什么卵用也没有。

尝试修改缓冲区大小

​ 那么问题已经明确了，我的第一想法就是调整Netty的接收端缓冲区和Linux系统的最大缓冲区限制，

​ Netty通过以ChannelOption.SO_SNDBUF和ChannelOption.SO_RCVBUF调整缓冲区大小

serverBootstrap.group(bossGroup, workerGroup)
              .childOption(ChannelOption.SO_KEEPALIVE,                                                              tcpSoKeepalive)
           .channel(NioServerSocketChannel.class)
           .option(ChannelOption.SO_SNDBUF, 1024*1024*2)
           .option(ChannelOption.SO_RCVBUF, 1024*1024*2)

而操作系统的调优则通过以下命令调整

echo 65536 > /proc/sys/net/core/rmem_max        #收缓冲区最大值
echo 256960 > /proc/sys/net/core/wmem_max        #发缓冲区最大值
echo 65536 > /proc/sys/net/core/rmem_default        #收缓冲区默认值
echo 65536 > /proc/sys/net/core/wmen_default        #发缓冲区默认值

经过调整后，再次进行抓包，结果发现问题依旧存在，TCP缓冲区依旧存在数据堆积，抓包数据仍然报ZeroWindow异常

抓取java栈信息

经过第一次尝试失败后，仍然找不到原因，于是只能通过java的jstack命令打印栈信息了

执行以下命令，将栈信息保存在文件中，注意：由于jstack会暂停应用的运行，所以基本是不到万不得已也不会使用这个方法，本人打印栈信息大概使应用暂停了15分钟左右

jstack -l pid >/home/stack.txt

接下来开始分析栈，由于我的应用使用的是Netty，那么我们重点查看Netty的工作线程的栈信息，看他卡在什么地方,这边发现有三分之一的Netty的工作线程在卡在HttpClient这个地方，而显而易见这是一个Http调用的方法，通过栈信息找到对应的类和函数，发现了在Netty 的handler中存在一个逻辑就是满足固定条件时会使用Http的方式去通知另一个应用

"nioEventLoopGroup-5-16" #47 prio=10 tid=0x00007f5ed4037000 nid=0x5289d runnable [0x00007f5eb05ee000]
   java.lang.Thread.State: RUNNABLE
   JavaThread state: _thread_in_native
 - java.net.SocketInputStream.socketRead0(java.io.FileDescriptor, byte[], int, int, int) @bci=0 (Compiled frame; information may be imprecise)
 - java.net.SocketInputStream.socketRead(java.io.FileDescriptor, byte[], int, int, int) @bci=8, line=115 (Compiled frame)
 - java.net.SocketInputStream.read(byte[], int, int, int) @bci=114, line=168 (Compiled frame)
 - java.net.SocketInputStream.read(byte[], int, int) @bci=11, line=140 (Compiled frame)
 - java.io.BufferedInputStream.fill() @bci=217, line=252 (Compiled frame)
 - java.io.BufferedInputStream.read1(byte[], int, int) @bci=44, line=292 (Compiled frame)
 - java.io.BufferedInputStream.read(byte[], int, int) @bci=49, line=351 (Compiled frame)
	- locked <0x00000000d29259d8> (a java.io.BufferedInputStream)
 - sun.net.www.http.HttpClient.parseHTTPHeader(sun.net.www.MessageHeader, sun.net.ProgressSource, sun.net.www.protocol.http.HttpURLConnection) @bci=51, line=746 (Compiled frame)
 - sun.net.www.http.HttpClient.parseHTTP(sun.net.www.MessageHeader, sun.net.ProgressSource, sun.net.www.protocol.http.HttpURLConnection) @bci=56, line=689 (Compiled frame)
 - sun.net.www.protocol.http.HttpURLConnection.getInputStream0() @bci=327, line=1604 (Compiled frame)
	- locked <0x00000000d291ed58> (a sun.net.www.protocol.http.HttpURLConnection)
 - sun.net.www.protocol.http.HttpURLConnection.getInputStream() @bci=52, line=1509 (Compiled frame)
	- locked <0x00000000d291ed58> (a sun.net.www.protocol.http.HttpURLConnection)
 - java.net.HttpURLConnection.getResponseCode() @bci=16, line=527 (Compiled frame)
 - cn.hutool.http.HttpConnection.responseCode() @bci=12, line=460 (Compiled frame)
 - cn.hutool.http.HttpResponse.init() @bci=5, line=374 (Compiled frame)
 - cn.hutool.http.HttpResponse.initWithDisconnect() @bci=1, line=350 (Compiled frame)
 - cn.hutool.http.HttpResponse.<init>(cn.hutool.http.HttpConnection, java.nio.charset.Charset, boolean, boolean) @bci=26, line=64 (Compiled frame)
 - cn.hutool.http.HttpRequest.execute(boolean) @bci=61, line=944 (Compiled frame)
 - cn.hutool.http.HttpRequest.execute() @bci=2, line=902 (Compiled frame)
 - cn.hutool.http.HttpUtil.post(java.lang.String, java.util.Map, int) @bci=12, line=171 (Compiled frame)
 - cn.hutool.http.HttpUtil.post(java.lang.String, java.util.Map) @bci=5, line=158 (Compiled frame)

分析Mysql 日志

通过上面栈的分析，我们切换到被调用的那台应用，在使用Top命令对服务器进行资源监控的时候，发现该服务器中的Mysql的cpu使用率高达百分之300，在开启mysql慢日志后发现一条语句查询时长高达10s，这条语句是执行的是一个count语句，接有where过滤条件，语句类似如下

select count(*) from users where username!='Liush'

这张表中有200多万条数据，执行count语句也不应该需要10秒，在对表结构进行查看后发现这表表居然连主键都没有。。。这就导致了每次执行count都不会用到索引，直接走全表扫描，而过滤条件也没有索引，所以导致了效率异常地下，在给这张表建立了主键后，再执行count统计仍然需要2s，经过对表分析后发现该查询语句的where条件过滤的是少数数据，比如上面举例的username字段，基本上每条数据的username都是不同的，及时我再在username上建立索引执行效率也不会太高，最后没办法只能进入代码查看该代码的在业务中的作用来看下有没有优化的空间，最后发现该代码仅仅只是查看是否存在该过滤条件的数据，且业务代码中只有一个地方调用了这个方法，于是乎修改了sql语句,并且在过滤条件中加入了索引

select username from users where username!='Liush'

在修改了这部分语句后执行恢复正常，同样tcp网络阻塞的问题得到了解决。

总结

1. TCP缓冲区拥堵其实本质就是消费数据的速度赶不上产生数据的数据，应该从消费数据的一端入手
2. 项目中基于TCP去构建应用层协议时，为了保证数据传输不丢失，还需要在应用层协议上做一个数据准确性校验或者应答，常用的方法是在应用层中构建一个自增的序列，客户端每次发送消息都将这个序列+1，服务端收到数据后对这个序列的连续性做校验。也许大家会疑问TCP不是可靠的传输协议吗，发送了数据就一点会收到到，为何应用层还需要校验或者设置消息应答？因为在时间中发现，如果tcp缓冲发生了拥堵的情况下，tcp服务端收到数据，将数据存放在缓冲区中，且给客户端应答，告诉数据已经成功接收，但是如果发生了缓冲区拥堵，这时应用层又断掉tcp发起了RST命令，那么连接就会立即关闭，这些数据还没来得及消费就被系统丢弃，tcp正常挥手需要4次，且其会保证数据发送完毕，但是如果tcp发起了rst标志位的话，那边连接就会立即关闭，只是还有消费还没发送，所以在netty中经常看见Connection reset by peer，其就是操作系统由于异常等原因发送了RST标志位断开了连接，且抛给应用层(Netty)消息，而应用层(Netty)并不知道断开连接的原因