性能调优篇:困扰我半年之久的RocketMQ timeout exception 终于被破解了

简介: 性能调优篇:困扰我半年之久的RocketMQ timeout exception 终于被破解了

1、网络超时现象


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

f6eb2e268db43bed23836b234e73556b.png

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


2、问题排查


2.1 初步分析


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


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


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


a378d6372f348cbd8fbaa08be0b0e0a8.png

客户端多个线程,通过一条连接发送了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

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


2f06cc951d9755402f8f9b2e9ff203ca.png

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

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


8da5b8b0d8b6e1eaee09f9514470ff34.png

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


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


2.3 网络分析


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


2.3.1 netstat查看Recv-Q与Send-Q


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

7a407cef0523153d8049c0831df9e5ec.png

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


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


ca1701b2e42e61483c6842f5752fa1bc.png

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


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


704122c9cde3b488bdd618ad444e0f61.png

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


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


2.3.2 网络抓包


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


bdd6e27d3568fa556346c5fb3aaa7ace.png

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


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


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


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

d98798eb5252926cac46733ab51361e6.png


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


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

2904f7982c19ecb8485079d64cbcf00f.png

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

7c4f60cc1cab111b43bfea3c3455a917.png

那矛头又将指向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个多月的验证,在集群机器数量减少(双十一之后缩容),只出现过极少数的消息发送超时,基本可以忽略不计。


温馨提示:关于Netty线程模型的详解,可以参考图解Netty线程模型,关注公众号,回复NPDF,即可免费获得《让天下没有难学的Netty》网络通道篇的PDF。

0bf563049b82fe54587f9f83e390e3cb.png


3、总结


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


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


相关实践学习
RocketMQ一站式入门使用
从源码编译、部署broker、部署namesrv,使用java客户端首发消息等一站式入门RocketMQ。
消息队列 MNS 入门课程
1、消息队列MNS简介 本节课介绍消息队列的MNS的基础概念 2、消息队列MNS特性 本节课介绍消息队列的MNS的主要特性 3、MNS的最佳实践及场景应用 本节课介绍消息队列的MNS的最佳实践及场景应用案例 4、手把手系列:消息队列MNS实操讲 本节课介绍消息队列的MNS的实际操作演示 5、动手实验:基于MNS,0基础轻松构建 Web Client 本节课带您一起基于MNS,0基础轻松构建 Web Client
相关文章
|
消息中间件 搜索推荐 RocketMQ
RocketMQ的invokeSync call timeout异常的解决办法
在RocketMQ客户端的DefaultMQPushConsumer的start方法被执行时,时不时会报出invokeSync call timeout异常,如下:
1366 0
RocketMQ的invokeSync call timeout异常的解决办法
|
1月前
|
消息中间件 存储 监控
RabbitMQ:分布式系统中的高效消息队列
RabbitMQ:分布式系统中的高效消息队列
|
4月前
|
消息中间件 NoSQL 数据库
一文讲透消息队列RocketMQ实现消费幂等
这篇文章,我们聊聊消息队列中非常重要的最佳实践之一:消费幂等。
一文讲透消息队列RocketMQ实现消费幂等
|
1月前
|
消息中间件 Java
springboot整合消息队列——RabbitMQ
springboot整合消息队列——RabbitMQ
75 0
|
3月前
|
消息中间件 JSON Java
RabbitMQ消息队列
RabbitMQ消息队列
46 0
|
3月前
|
消息中间件
RabbitMQ 实现消息队列延迟
RabbitMQ 实现消息队列延迟
121 0
|
18天前
|
消息中间件 存储 负载均衡
消息队列学习之RabbitMQ
【4月更文挑战第3天】消息队列学习之RabbitMQ,一种基于erlang语言开发的流行的开源消息中间件。
15 0
|
1月前
|
消息中间件 存储 中间件
【SpringCloud Stream消息驱动、设计思想以及整合rabbitmq消息队列案例--学习笔记】
【SpringCloud Stream消息驱动、设计思想以及整合rabbitmq消息队列案例--学习笔记】
50 0
|
1月前
|
消息中间件 缓存 API
|
1月前
|
消息中间件 存储 Cloud Native
【Spring云原生系列】Spring RabbitMQ:异步处理机制的基础--消息队列 原理讲解+使用教程
【Spring云原生系列】Spring RabbitMQ:异步处理机制的基础--消息队列 原理讲解+使用教程

热门文章

最新文章