性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了

yoursoft
发布于 2023-2-15 14:45
浏览
0收藏

在内网环境中,超时问题,网络表示这个锅我不背。

笔者对于超时的理解,随着在工作中不断实践,其理解也越来越深刻,RocketMQ在生产环境遇到的超时问题,已经困扰了我将近半年,现在终于取得了比较好的成果,和大家来做一个分享。

本次技术分享,由于涉及到网络等诸多笔者不太熟悉的领域,如果存在错误,请大家及时纠正,实现共同成长与进步。

1、网络超时现象


时不时总是接到项目组反馈说生产环境MQ发送超时,客户端相关的日志截图如下:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区

今天的故事将从张图开始。

2、问题排查


2.1 初步分析

上图中有两条非常关键日志:

  • invokeSync:wait response timeout exception网络调用超时
  • recive response,but not matched any request这条日志非常之关键,表示尽管客户端在获取服务端返回结果时超时了,但客户端最终还是能收到服务端的响应结果,只是此时客户端已经等待足够时间后放弃处理了。

关于第二条日志,我再详细阐述一下其运作机制,其实也是用一条链接发送多个请求的编程套路。一条长连接,向服务端先后发送2个请求,客户端在收到服务端响应结果时,怎么判断这个响应结果对应的是哪个请求呢?如下图所示:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


客户端多个线程,通过一条连接发送了req1,req2两个请求,但在服务端通常都是多线程处理,返回结果时可能会先收到req2的响应,那客户端如何识别服务端返回的数据是对应哪个请求的呢?

解决办法是客户端在发送请求之前,会为该请求生成一个本机器唯一的请求id(requestId),并且会采用Future模式,将requestId与Future对象放入一个Map中,然后将reqestId放入请求体中,服务端在返回响应结果时将请求ID原封不动的放入到响应结果中,当客户端收到响应时,先界面出requestId,然后从缓存中找到对应的Future对象,唤醒业务线程,将返回结构通知给调用方,完成整个通信。

故从这里能看到,客户端在指定时间内没有收到服务端的请求,但最终还是能收到,矛头直接指向Broker端,是不是Broker有瓶颈,处理很慢导致的。

2.2 Broker端处理瓶颈分析

在我的“经验”中,RocketMQ消息发送如果出现瓶颈,通常会返回各种各样的Broker Busy,而且可以通过跟踪Broker端写入PageCache的数据指标来判断Broker是否遇到了瓶颈。

grep "PAGECACHERT" store.log

得到的结果类似如下截图:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


温馨提示:上图是我本机中的截图,当时分析问题的时候,MQ集群中各个Broker中这些数据,写入PageCache的时间没有超过100ms的。

正是由于良好的pagecache写入数据,根据如下粗糙的网络交互特性,我提出将矛盾点转移到网络方面:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


并且我还和业务方确定,虽然消息发送返回超时,但消息是被持久化到MQ中的,消费端也能正常消费,网络组同事虽然从理论上来说局域网不会有什么问题,但鉴于上述现象,网络组还是开启了网络方面的排查。

温馨提示:最后证明是被我带偏了。

2.3 网络分析

通常网络分析有两种手段,netstat 与网络抓包。

2.3.1 netstat查看Recv-Q与Send-Q

我们可以通过netstat重点观察两个指标Recv-Q、Send-Q。


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


  • Recv-Qtcp通道的接受缓存区
  • Send-Qtcp通道的发送缓存区

在TCP中,Recv-Q与Send-Q的作用如下图所示:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


  • 客户端调用网络通道,例如NIO的Channel写入数据,数据首先是写入到TCP的发送缓存区,如果发送发送区已满,客户端无法继续向该通道发送请求,从NIO层面调用Channel底层的write方法,会返回0,表示发送缓冲区已满,需要注册写事件,待发送缓存区有空闲时再通知上层应用程序可以发消息。
  • 数据进入到发送缓存区后,接下来数据会随网络到达目标端,首先进入的是目标端的接收缓存区,如果与NIO挂钩的化,通道的读事件会继续,应用从接收缓存区中成功读取到字节后,会发送ACK给发送方。
  • 发送方在收到ACK后,会删除发送缓冲区中的数据,如果接收方一直不读取数据,那发送方也无法发送数据。

网络同事分布在客户端、MQ服务器上通过每500ms采集一次netstat ,经过对采集结果进行汇总,出现如下图所示:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


从客户端来看,客户端的Recv-Q中会出现大量积压,对应的是MQ的Send-Q中出现大量积压。

从上面的通讯模型来看,再次推断是否是因为客户端从网络中读取字节太慢导致的,因为客户端为虚拟机,从netstat 结果来看,疑似是客户端的问题(备注,其实最后并不是客户端的问题,请别走神)

2.3.2 网络抓包

网络组同事为了更加严谨,还发现了如下的包:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


这里有一个问题非常值得怀疑,就是客户端与服务端的滑动窗口只有190个字节,一个MQ消息发送返回包大概有250个字节左右,这样会已响应包需要传输两次才能被接收,一开始以为这里是主要原因,但通过其他对比,发现不是滑动窗口大于250的客户端也存在超时,从而判断这个不是主要原因,后面网络同事利用各种工具得出结论,网络不存在问题,是应用方面的问题。

想想也是,毕竟是局域网,那接下来我们根据netstat的结果,将目光放到了客户端的读性能上。

2.4 客户端网络读性能瓶颈分析

为此,我为了证明读写方面的性能,我修改了RocketMQ CLient相关的包,加入了Netty性能采集方面的代码,其代码截图如下:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


我的主要思路是判断客户端对于一个通道,每一次读事件触发,一个通道会进行多少次读取操作,如果一次读事件触发,需要触发很多次的读取,说明一个通道中确实积压了很多数据,网络读存在瓶颈。

但令人失望的是客户端的网络读并不存在瓶颈,部分采集数据如下所示:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


通过awk命令对其进行分析,发现一次读事件触发,大部分通道读两次即可将读缓存区中的数据抽取成功,读方面并不存在瓶颈,对awk执行的统计分析如下图所示:


性能调优篇:困扰我许久的RocketMQ timeout exception终于破解了-鸿蒙开发者社区


那矛头又将指向Broker,是不是写到缓存区中比较慢呢?

2.5 Broker端网络层面瓶颈

经过上面的分析,Broker服务端写入pagecache很快,维度将响应结果写入网络这个环节并未监控,是不是写入响应结果并不及时,大量积压在Netty的写缓存区,从而导致并未及时写入到TCP的发送缓冲区,从而造成超时。

笔者本来想也对其代码进行改造,从Netty层面去监控服务端的写性能,但考虑到风险较大,暂时没有去修改代码,而是再次认真读取了RocketMQ封装Netty的代码,在此次读取源码之前,我一直以为RocketMQ的网络层基本不需要进行参数优化,因为公司的服务器都是64核心的,而Netty的IO线程默认都是CPU的核数,但在阅读源码发现,在RocketMQ中与IO相关的线程参数有如下两个:

  • serverSelectorThreads默认值为3。
  • serverWorkerThreads默认值为8。

serverSelectorThreads,在Netty中,就是WorkGroup,即所谓的IO线程池,每一个线程池会持有一个NIO中的Selector对象用来进行事件选择,所有的通道会轮流注册在这3个线程中,绑定在一个线程中的所有Channel,会串行进行读写操作,即所有通道从TCP读缓存区,将数据写到发送缓存区都在这个线程中执行。

我们的MQ服务器的配置,CPU的核属都在64C及以上,用3个线程来做这个事情,显然有点太“小家子气”,该参数可以调优。

serverWorkerThreads,在Netty的线程模型中,默认情况下事件的传播(编码、解码)都在IO线程中,即在上文中提到的Selector对象所在的线程,为了降低IO线程的压力,RocketMQ单独定义一个线程池,用于事件的传播,即IO线程只负责网络读、写,读取的数据进行解码、写入的数据进行编码等操作,单独放在一个独立的线程池,线程池线程数量由serverWorkerThreads指定。

看到这里,终于让我心潮澎湃,感觉离真相越来越近了。参考Netty将IO线程设置为CPU核数的两倍,我第一波参数优化设置为serverSelectorThreads=16,serverWorkerThreads=32,在生产环境进行一波验证。

经过1个多月的验证,在集群机器数量减少(双十一之后缩容),只出现过极少数的消息发送超时,基本可以忽略不计。

3、总结


本文详细介绍了笔者排查MQ发送超时的精力,最终定位到的是RocketMQ服务端关于网络通信线程模型参数设置不合理。

之所以耗费这么长时间,其实有值得反思的地方,我被我的“经验”误导了,其实以前我对超时的原因直接归根于网络,理由是RocketMQ的写入PageCache数据非常好,基本都没有超过100ms的写入请求,以为RocketMQ服务端没有性能瓶颈,并没有从整个网络通信层考虑。




文章转载自公众号:   中间件兴趣圈

分类
标签
已于2023-2-15 14:45:59修改
收藏
回复
举报
回复
    相关推荐