威努特工控安全 03月26日
深入TCP连接:定位与解决性能问题现场实战
index_new5.html
../../../zaker_core/zaker_tpl_static/wap/tpl_guoji1.html

 

文章讲述了在工控产品管理平台中,由于Netty框架的Selector空轮询问题,导致大量终端离线的问题排查与解决过程。通过对CPU、线程、连接状态的分析,以及抓包和源码解读,最终定位到问题根源是Netty框架在OOM异常处理时不够健壮,以及旧版本客户端的频繁连接请求。解决方案包括升级客户端版本、统一Netty版本、以及优化服务端代码,从而解决了终端离线问题。

🧐 平台终端大面积离线,运维反馈,研发介入,初步定位为TCP长连接心跳通信异常。

🔍 通过CPU、线程、连接数等指标排查,发现大量连接处于CLOSE_WAIT状态,且持续存在,引起怀疑。

📡 抓包分析,确认FIN包未被回复,结合Netty框架特性,锁定问题可能出在未注册连接事件。

💥 结合OOM异常日志,定位到Netty代码在OOM时未正确处理连接关闭,导致问题发生。

🔄 通过分析堆栈和源码,发现Selector空轮询BUG,以及旧版本客户端频繁建连导致问题加剧。

🛠️ 最终通过升级客户端、统一Netty版本、优化服务端代码等方式,解决了终端离线问题。

在一个略显疲惫但依然坚守的下午,随着在键盘上噼里啪啦地敲下最后一行return Result.ok(“success”),接口搞定,任务完成;眼睛瞥了下右下角时间:18:32,得,伸个懒腰,揉把眼睛,下楼干饭走起!


就在刚起身还没来得及扶下伴我忙碌了一天的镜框,微信头像轻轻跳动,线上项目维护群里,一个运维同事反馈,管理平台上显示主机卫士全离线了,已经有半个多小时了,始终没法重新上线,问题很严重,十万火急。我当时就想,难道是网络不通了,不应该呀,这等基础原因运维也不会找到研发这边呀,秉着始终客户至上原则,当时就叫他都先别操作了,保留现场,协调一个远程环境,立马重新坐下撸起袖子开干!


该现场包含一个工控产品,多个车间部署终端,然后通过管理平台统一管控,其中判断终端是否能被正常管控到(比如网络可达等),采用的是客户端-服务端建立TCP长连接心跳进行通信,服务用的Netty框架。


现场定位


终端离线了,那最直接的原因铁定是心跳处理接口出错了,要不TCP断连了,要不就是处理逻辑报错了,没能重置在线状态。


话不多说,现场问题,跑不了的第一步,查看cpu使用率。



观察了一段时间,cpu基本持续在50%-70%之间,没什么问题。


既然cpu性能上没问题,那就再看一下处理终端上线状态的线程是否还存活以及TCP连接的情况,走的是4575端口。


Jstack  2646319  |  grep  HeartBeatThread  -C  10  命令查看线程情况。



没问题,线程依然存活着。


netstat - ant  |  grep  4575继续用命令查看下连接数。



瞬间惊呆,一脸的不可思议,现场三千多台终端,也就是三千多个连接,基本上全是CLOSE_WAIT状态了,没有几台正常建连的,而且这些CLOSE_WAIT的连接出现以后不会消失。


第一时间,这不得不让我又开始怀疑起一开始运维同事所反馈的,端到端的网络可达性了。不废话,直接抓包,讲究的就是一个以德服人。


随着抓包结果一出,还真让我的自信心稍微地一颤,这不科学呀,cpu资源没问题,线程也活着,网络也可达,这难道真的要上升到玄学了吗?


不急不急,谁让我们学的专业就是计算机科学与技术呢,先让我们简单地回顾下这TCP三次握手四次挥手收发包的过程。

TCP三次握手四次挥手示意图


我们可以看到,CLOSE_WAIT状态出现在被动关闭方,当收到对端FIN以后回复ACK,但是自身没有发送FIN包之前,所以这里的原因就很清楚了,出现永远存在的CLOSE_WAIT的连接是因为,收到了对端的FIN包,但是自己一直没有回复FIN。


接下来就再次重新看下我们前面抓包的信息,也证实了这点。



那问题就落在了为什么没有回复 FIN,这是一个客户端发起的请求,三次握手成功以后,终端服务会马上发送 FIN,理论上Netty服务也会立刻回复 FIN,但是没有任何反应。


对于使用的Netty来说,它就是一个普通的tcp服务端,无非就这几步:


    bind、listen

    注册 accept 事件到 epoll

    epoll_wait 等待连接到来

    连接到来时,调用 accept 接收连接

    注册新连接的 EPOLLIN、EPOLLERR、EPOLLHUP 等事件到 epoll

    epoll_wait 等待事件发生


如果是没有发送 fin,有几个比较明显的可能原因:


    第 2 步没有做,压根没有注册 accept 事件(可以排除,肯定有注册)

    第 4 步没有做,连接到来时,netty 「忘了」调用 accept 把连接从内核的全连接队列里取走。这里的「忘」可能是因为逻辑 bug 或者 netty 忙于其他事情没有时间取走,这个待会验证

    第 5 步没有做,取走了连接,三次握手真正完成,但是没有注册新连接的后续事件


第 2 个原因可以通过半连接队列、全连接队列的积压来确认。ss 命令可以查看全连接队列的大小和当前等待accept的连接个数。



处于 LISTEN 状态的 socket,Recv-Q 表示当前 socket 的完成三次握手等待用户进程 accept 的连接个数,Send-Q 表示当前 socket 全连接队列能最大容纳的连接数。


对于非 LISTEN 状态的 socket,Recv-Q 表示 receive queue 的字节大小,Send-Q 表示 send queue 的字节大小。


通过 ss 命令确认过 Recv-Q 为 0,全连接队列没有积压。



至此最大的嫌疑在第 3 个原因,netty 确实调用了 accept 取走了连接,但是没有注册此连接的任何事件,导致后面收到了 fin 包以后无动于衷。


为什么netty没有能注册事件?


到这里暂时陷入了僵局,但是有一个跟此次问题强相关的现象浮出了水面,就是业务实例在凌晨1点有个定时任务,一开始就load了大量的数据到内存中,导致堆内存占满,持续进行fullgc。



netty 线程也有打印 oom 异常。



这里的OOM异常上面的一个warning表示很可疑,去netty源码中一搜索,发现出现在org.jboss.netty.channel.socket.nio.NioServerBoss#process方法中。



第80行netty调用accept从全连接队列取走连接,第85行调用registerAcceptedChannel,将当前fd设置为非阻塞同时为新连接fd注册事件,具体的逻辑是在org.jboss.netty.channel.socket.nio.NioWorker.RegisterTask#run中。


从错误日志中可以知道,这个方法确实抛出了java.lang.OutOfMemoryError异常。


因此这里的原因就很清楚了,netty这里的处理确实不健壮,一个try-catch包裹了accept连接和注册事件这两个逻辑,当第80行accept成功,但在85行registerAcceptedChannel内部尝试注册事件时因为线程OOM排除异常时就凉凉了,没有close这个新连接,就导致了后面收到fin以后根本不会回复任何包(epoll里压根没有这个fd的感兴趣事件)。


模拟复现


直接改netty源码加点日志重新模拟运行程序。



这个CLOSE_WAIT就一直存在了直到netty进程退出。再来一次然后断开就又多了一个 CLOSE_WAIT。


而且在现场用tcpdump命令抓包的过程中以及分析log日志,发现存在好些IP客户端在重复发起建连,一秒内达到八九次,根本不符合超时重连机制原则,所以获取对应IP客户端的log日志和源码分析,发现是现场客户端V3R6C01B060等几个老版本,总数量1388台,TCP发起建连的逻辑存在错误,会持续频繁地发起连接请求,所以导致OOM期间 CLOSE_WAIT持续增加。


小  结


到这里的问题就很清楚了,总结就是 netty 的代码不够健壮,一个 try-catch 包裹的逻辑太多,在 OOM throwable 异常处理时,没能成功注册事件也没有 close 已创建的连接,导致连接存在但是没有人监听事件处理。


那又是什么原因导致发生OOM呢?


性能问题定位,当然少不了堆栈的一顿分析。


jmap  -dump:format=b,file=4575.hprof  2646319  使用jmap命令,从客户现场环境导出dump文件,使用JProfiler工具直接打开分析。



可以看到这个ConcurrentHashMap其实存储了netty的channel对象,最大规格也就是3000台终端对应了3000条数据而已,但这会儿竟然达到了2.5GB多,绝对不正常,继续往下看,然后就发现了EPollSelectorImpl这个对象实例一直在增加。



没办法,只能继续薅源代码了,其实到这一步,问题的原因越来越清晰了,就待破解这内存异常占用问题了。



可以看到,在io.netty.channel.nio#select方法中,呼之欲出netty的老问题就来了——Selector空轮询BUG。


Netty的解决办法总览

    对Selector的select操作周期进行统计,每完成一次空的select操作进行一次计数,若在某个周期内连续发生N次空轮询,则触发了epoll死循环bug。

    重建Selector,判断是否是其他线程发起的重建请求,若不是则将原SocketChannel从旧的Selector上去除注册,重新注册到新的Selector上,并将原来的Selector关闭。


Netty解决空轮询的4步骤


第一部分:定时阻塞select(timeMillins)

    先定义当前时间currentTimeNanos

    接着计算出一个执行最少需要的时间timeoutMillis

    定时阻塞select(timeMillins)

    每次对selectCnt做++操作


第二部分:有效IO事件处理逻辑


第三部分:超时处理逻辑

如果查询超时,则seletCnt重置为1


第四部分: 解决空轮询 BUG

    一旦到达SELECTOR_AUTO_REBUILD_THRESHOLD阈值,就需要重建selector来解决这问题

    这个阈值默认是512

    重建selector,重新注册channel通道


在家里模拟环境验证,搭建了一套和现场一模一样版本的管理平台服务,终端也是同样各个高低版本分布情况和数量规格上压力测试,观察后发现EPollSelectorImpl对象始终没有增加。


不由得怀疑是由于系统上的某些参数设置不同导致的,因为我们研发平时使用好几套不同厂商不同型号的服务器做测试,以及研发测试环境经常修改参数做功能适配,然后和现场环境对比,发现文件句柄数、服务系统参数等都一致,只是服务器配置不一样,现场的是内存128G/48核的,远比家里的16G/4核的高出不少,问题已经定位到这一步了,所以为了能够排除最后一丝的差异性,又协调过来一台相同配置的服务器,重新部署上管理平台服务上压力。


这次很明显地可以发现这个EPollSelectorImpl对象在不断地增加, 然后结合Netty针对这个空轮询的处理方式,猜想原因可能就是,服务器性能太高了,再加上错误版本的客户端频繁异常发送请求连接,导致这个时间段次次瞬间就命中默认阈值条件,触发了重建selector的条件。


为了最后一次验证这个猜想,我们临时把SELECTOR_AUTO_REBUILD_THRESHOLD这个阈值配置修改为3,也就是在Netty中关闭了该重建selector功能,再次验证,发现cpu消耗了很多,不过EPollSelectorImpl实例不会再异常地增加。


结  论


过量的请求连接,异常导致了对Netty 的Selector空轮询BUG的触发,使其EPollSelectorImpl对象实例异常不断增加,也就是内存增大导致内存泄漏。


问题解决


    对现场出问题的客户端进行最新版本的升级;


    平台多个微服务使用了多个netty版本进行了整理统一,使用较新的版本;


    对服务整体代码进行了梳理,尤其是针对获取tcp心跳报文接口的逻辑处理,包括一些不必要的加锁,阻塞访问数据库逻辑操作等进行了性能优化。



渠道合作咨询   田先生 15611262709

稿件合作   微信:shushu12121

📍发表于:中国 北京

Fish AI Reader

Fish AI Reader

AI辅助创作,多种专业模板,深度分析,高质量内容生成。从观点提取到深度思考,FishAI为您提供全方位的创作支持。新版本引入自定义参数,让您的创作更加个性化和精准。

FishAI

FishAI

鱼阅,AI 时代的下一个智能信息助手,助你摆脱信息焦虑

联系邮箱 441953276@qq.com

相关标签

Netty 工控平台 TCP Selector空轮询 OOM
相关文章