NETTY作为优秀的NIO通讯框架,深受大家喜爱,在我们的发版工具项目启动时,便采用其作为通讯框架,但是使用过程中却踩了一个坑。
踩坑分析报告
项目简介:
在发版工具项目中,由于发版过程会涉及不同的发版环境,对于一次请求,对应的服务提供方IP需根据此次请求消息的附加信息确定,同时考虑到多次请求建链的消耗过程,选择通讯方式为长连接;而考虑到连接的管理和并发控制问题,所以加入连接池。对于NETTY通讯框架,本身已提供连接池,可通过数行代码完成连接池定制过程,故选择NETTY的SimpleChannelPool连接池,同时使用AbstractChannelPoolMap<InetSocketAddress,SimpleChannelPool>管理对应不同IP地址的连接池。
异常场景:
连接池的使用过程为:根据请求数据传入的IP信息,从AbstractChannelPoolMap中选定对应的连接池,进行后续通讯过程。有一次,系统启动后,异常场景出现了,传入的IP为“36.0.12.112”,但是从MAP中通过连接池获取连接时,显示连接IP为“36.0.12.114”!!!
异常场景分析:
首先,从连接池初始化过程看起,初始化代码如下:
该初始化过程发生在此地址对应的第一笔交易时,
如此诡异的问题,“并发问题”首先作为了我们的首要嫌疑犯。
首先进行场景的补全和确认过程,测试环境的日志还在,为我们保留了完整的“犯罪”现场。从代码看,业务代码中存在同步调用和异步调用两个方法,但代码都基本类似,使用过程一般调用同步方法,即使用图一的连接池创建过程。从日志来看,在进程启动后,第一批交易发起过程即出现了该问题,一笔请求对应发送到五个不同的IP地址,则问题应该发生在连接池创建过程或者获取过程中,但是如图一所示,已经使用同步代码块进行控制,虽然此同步代码块作用不详(此处有伏笔),创建过程由不同线程创建不同的连接池,应该不会出现问题,难道MAP存在并发问题?然后就开始越走越远,甚至怀疑人生。。。。
此时,有位同事大神说,已在本地复现,瞬间感觉要看到了光明,但瞬间又熄灭了。能复现问题的测试代码是在图一的基础上去掉了同步代码块,那看来同步代码块还是有作用的,但这并不是问题场景呀。放佛又陷入了无法解决之坑,这会儿,见证了诡异现象的老师忽然灵光一闪,出现异常场景的时候,跟平时流程有所出入,调用的方法不是同步方法,而是异步方法,而异步方法中正好没加入同步代码块控制。
终于事件大白啦,可见混乱中的场景复现是多么的重要。到此,基本可以看到坑的面貌啦,接下来就是详细的分析过程了。
如图四所示,连接池在初始化过程中需要传入第一个参数为bootstrap,由于对应IP不同,所以需要调用bootstrap.remoteAddress(paramK)进行赋值,重点来了,bootsrap实例是作为该类的成员变量存在的,但是bootstrap本身并不是线程安全的。
在并发情况下,该赋值过程会出现问题,导致MAP中KEY值的IP地址与VALUE中连接池真正的地址信息不符,所以会出现根据地址A拿到的连接却指向地址B的诡异现象。
异常场景分析总结:
一次踩坑的排查终于结束啦,曲曲折折,不过为以后问题排查点出了很多注意的事项。
一:一定一定一定要最大限度了解异常场景,不要想当然;
二:对测试环境出现问题保持敏感,并发问题一般比较诡异,很多问题在你放过后可能后续表现都正常,但是它仍然还在隐患中,可能上线后就暴露出来了,所以不要放过测试环境的诡异问题。