1、问题描述

钉钉告警触发时间：2022-06-23 15:46:35.016 开始，每个几个小时告警一次

钉钉告警触发内容：

2、初步分析

定位mqcloud触发告警代码块，分析堆栈信息：

什么？堆栈信息未在运维项目mqcloud中打印？ 那么先从源码与经验进行分析，并同时添加打印堆栈信息的源代码发布到prod中，进行监测。

2.1 mqcloud源代码分析

handleAlarmMessage方法是告警相关逻辑封装，对于传入的clusterStatList进行解析，不为空则触发告警通知。

mqAdmin.getNameServerConfig(Arrays.asList(addr));是调用NameServer获取配置信息，对应接口code码RequestCode.GET_NAMESRV_CONFIG。

2.2 NameServer源码分析

上述的逻辑，配置信息在NameServer启动时初始化好了，所以不存在Server端代码处理过长原因。

2.3 NameServer源码分析2（源码出错概率太低）

每个NameServer的方法都用了锁，会由于锁竞争导致的资源等待吗？（错误是偶发性的，故不需要考虑死锁情况），那我们继续来排查ReentrantReadWriteLock对象的使用吧。

相关的代码有点多，这里就做下简单的汇总：

NameServer核心逻辑ReentrantReadWriteLock对应方法逻辑排查；每一个方法都会使用读写锁的逻辑：
1）启动时初始化调用方法：registerConfig（writeLock）、setStorePathFromConfig（writeLock）、
2）UPDATE_NAMESRV_CONFIG入口: update(writeLock)->persist（readLock）->getAllConfigsInternal（readLock）->getStorePath（readLock）
3）GET_NAMESRV_CONFIG入口：getAllConfigsFormatString（readLock）

源代码未发现明显漏洞，进一步搜索mqcloud代码的引用，并未发现UPDATE_NAMESRV_CONFIG接口的使用，源代码挺健壮的，至少调用链路不长。

2.4 大流量分析

由于是偶发性问题，很难监测网络情况，目前简单实用netstat、mtr等工具监测。

1） NameServer服务Netty服务端排查，SelectorThreads默认3（worker）和WorkerThreads默认8（业务IO线程池），足够响应客户端的请求数、SO_SNDBUF与SO_RCVBUF都是65536；

2）mqcloud服务Netty客户端排查，相应配置都配套，对应ExecutorGroup默认4（业务IO线程池），足够客户端使用；

3）netstat检测网络数据包大小，双方服务的Recv-Q与Send-Q大约400左右，排除大数据包问题或缓冲区被占满情况；

其中一台NameServer对应的客户端发送情况，与代码1、2对应；

3、堆栈分析

线上的问题的定位，堆栈信息是一个很重要的日志记录（4月份的版本没有打印详细堆栈，本次新增），接下来我们进一步来分析下。

3.1 wait response on the channel

告警信息：ns:10.16.30.79:9876;Exception: wait response on the channel <10.16.30.79:9876> timeout, 5000(ms) |

堆栈信息最终只有到invokeSyncImpl，因为网络层相关的交互其技术框架是无法解决的，比如数据包不可达、网络开小差、服务端接收到但它还在处理中，那我们如何排查呢？既然这样，那我们就直接找寻对应直接在NameServer处理并响应回来的日志即可，通过RocketMQ源码及堆栈，可以定位到：send request to failed异常；

wait response on the channel，最终在客户端会定义为RemotingTimeoutException异常，无论服务端是什么情况，只要客户端没有收到回执且到了超时时间，就强制抛出Timeout类异常，源码如下。

3.2 connect to failed

对应源码它在获取channel时出现问题了，没有成功获取到channel，有两种可能原因：1）获取到的channel后被客户端触发了关闭机制导致channel不是actice状态，2）没有成功创建出channel。

3.3 send request to failed

ns:..30.74:9876;Exception: send request to <..30.74:9876> failed | |


直接定位MQ源代码报错位置，最终可以看到cause异常捕获后throw出来，那我们可以执行去定位堆栈日志。

终于看到了server的异常代码块了，那接下来跟踪下netty源代码，看看该异常是如何产生的。

由于前面RocketMQ的源码发送消息调用的是channel.writeAndFlush，这里直接在write就报错了。

异常终于对上了，引发抛出异常的条件是outboundBuffer = null，继续看一下源码：

channel关闭时触发、或者flush0时候触发。

管道被关闭时触发。

基于以上信息，我们可以推出结论：此问题的原因是客户端的channel被关闭了，接下来再回到RocketMQ的客户端源代码，看看其channel关闭的原理。

4、channel关闭分析

4.1 mqcloud引用的RocketMQ的Netty客户端实现分析

分析下以下4个关闭条件

1）disconnect事件触发条件：java原生NIO SocketChannel不存在，调用Netty NioSocketChannel的disconnect(ChannelPromise promise) 时，会自动转换成close操作，这里可能性很多，一般是网络层与操作系统层触发。

https://blog.csdn.net/weixin_43257196/article/details/104928779

2）close事件触发条件：关闭操作，可能是客户端/服务端主动关闭，也可能是异常关闭。

https://blog.csdn.net/weixin_43257196/article/details/104865942

3）userEventTriggered事件触发条件：心跳监听关闭，文字心跳探测时间为120s；

4）exceptionCaught事件触发条件：业务发现异常，自动捕获；

拔网线的场景：只要足够快，channel还是可以使用，在插拔的区间，不能动channel对象、也不要主动去关闭channel，当netty的SO_KEEPALIVE参数开启后，tcp底层有75s探测的机制，这一块会触发userEventTriggered事件进行关闭。

基于以上内容分析，很有可能是网络抖动或网络状态不佳导致，目前QA环境对应的服务器也出现了网络问题，生产的网络情况已转交给运维进行监测中。

QA环境对应的机器图解：运维针对某个网络的监测图表：（其实运维搞的这一套没有用）

1、netty连接超时（办公网络ping ..17.211、baidu.com）、

2、阿里云连接netty超时（其他外网ping .…17.211）、

3、netty端口延迟（办公网络ping .…108.72、 .…17.211、baidu.com）

4、netty阿里云网络延迟（其他外网ping .…108.72、 .…17.211、ali_baidu.com）、

5、整改措施

基于以上分析及运维给出的一些参考指标，而且网络这一块又是老大难的问题，那么可以重设计与实现方向绕过去，需求实现如下：

结合mqcloud更新NameServer配置信息的逻辑，将原逻辑修改为：接入业务重试逻辑，一共调用三次还失败，则进行NameServer告警。

发布后正常，在以下两个时间点触发了重试机制，日志如下：

根据日志可以看到同一时间节点只有一次错误日志打印，说明重试一次就已经成功访问NameServer。