接到告警和运维反馈,一个 RocketMQ 的节点不见了。此类现象在以前从未发生过,消失肯定有原因,开始查找日志,从集群的 broker.log、stats.log、storeerror.log、store.log、watermark.log 到系统的 message 日志没发现错误日志。集群流量出入在正常水位、CPU 使用率、CPU Load、磁盘 IO、内存、带宽等无明显变化。
继续查原因,最终通过 history 查看了历史运维操作。发现运维同学在启动 Broker 时没有在后台启动,而是在当前 session 中直接启动了。
1 | sh bin/mqbroker -c conf/broker-a.conf |
问题即出现在此命令,当 session 过期时 Broker 节点也就退出了。
标准化运维操作,对运维的每次操作进行评审,将标准化的操作实现自动化运维就更好了。
正确启动 Broker 方式:
1 | nohup sh bin/mqbroker -c conf/broker-a.conf & |
RocketMQ 主节点 CPU 频繁飙高后回落,业务发送超时严重,由于两个从节点部署在同一个机器上,从节点还出现了直接挂掉的情况。
主节点 CPU 毛刺截图:
从节点 CPU 毛刺截图:
说明:中间缺失部分为掉线,没有采集到的情况。
系统错误日志一
1 | 2020-03-16T17:56:07.505715+08:00 VECS0xxxx kernel: <IRQ> [<ffffffff81143c31>] ? __alloc_pages_nodemask+0x7e1/0x960 |
系统错误日志二
1 | 30 2020-03-27T10:35:28.769900+08:00 VECSxxxx kernel: INFO: task AliYunDunUpdate:29054 blocked for more than 120 seconds. |
说明:系统日志显示错误“page allocation failure”和“blocked for more than 120 second”错误,日志目录 /var/log/messages。
GC 日志
1 | 2020-03-16T17:49:13.785+0800: 13484510.599: Total time for which application threads were stopped: 0.0072354 seconds, Stopping threads took: 0.0001536 seconds |
说明:GC 日志正常。
Broker 错误日志
1 | 2020-03-16 17:55:15 ERROR BrokerControllerScheduledThread1 - SyncTopicConfig Exception, x.x.x.x:10911 |
说明:通过查看 RocketMQ 的集群和 GC 日志,只能说明但是网络不可用,造成主从同步问题;并未发现 Broker 自身出问题了。
系统使用 CentOS 6,内核版本为 2.6。通过摸排并未发现 broker 和 GC 本身的问题,却发现了系统 message 日志有频繁的“page allocation failure”和“blocked for more than 120 second”错误。所以将目光聚焦在系统层面,通过尝试系统参数设置,例如:min_free_kbytes 和 zone_reclaim_mode,然而并不能消除 CPU 毛刺问题。通过与社区朋友的会诊讨论,内核版本 2.6 操作系统内存回收存在 Bug。我们决定更换集群的操作系统。
将集群的 CentOS 6 升级到 CentOS 7,内核版本也从 2.6 升级到了 3.10,升级后 CPU 毛刺问题不在乎出现。升级方式采取的方式先扩容后缩容,先把 CentOS 7 的节点加入集群后,再将 CentOS 6 的节点移除,详见前面实战部分“RocketMQ 集群平滑运维”。
1 | Linux version 3.10.0-1062.4.1.el7.x86_64 ([email protected]) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-39) (GCC) ) #1 SMP Fri Oct 18 17:15:30 UTC 2019 |
监控和业务同学反馈发送超时,而且频繁出现。具体现象如下图。
预热现象
说明:上图分别为开启预热时(warmMapedFileEnable=true
)集群的发送 RT 监控、Broker 开启预热设置时的日志。
内存传输现象
说明:上图分别为开启堆外内存传输(transferMsgByHeap=fals
e)时的 CPU 抖动截图、系统内存分配不足截图、Broker 日志截图。
上面展现的两种显现均会导致集群 CPU 抖动、客户端发送超时,对业务造成影响。
预热设置:在预热文件时会填充 1 个 G 的假值 0 作为占位符,提前分配物理内存,防止消息写入时发生缺页异常。然而往往伴随着磁盘写入耗时过长、CPU 小幅抖动、业务具体表现为发送耗时过长,超时错误增多。关闭预热配置从集群 TPS 摸高情况来看并未有明显的差异,但是从稳定性角度关闭却很有必要。
堆外内存:transferMsgByHeap 设置为 false 时,通过堆外内存传输数据,相比堆内存传输减少了数据拷贝、零字节拷贝、效率更高。但是可能造成堆外内存分配不够,触发系统内存回收和落盘操作,设置为 true 时运行更加平稳。
预热 warmMapedFileEnable 默认为 false,保持默认即可。如果开启了,可以通过热更新关闭。
1 | bin/mqadmin updateBrokerConfig -b x.x.x.x:10911 -n x.x.x.x:9876 -k warmMapedFileEnable -v false |
内存传输参数 transferMsgByHeap 默认为 true(即:通过堆内内存传输)保持默认即可。如果关闭了,可以通过热更新开启。
1 | bin/mqadmin updateBrokerConfig -b x.x.x.x:10911 -n x.x.x.x:9876 -k transferMsgByHeap -v true |
配置均采用 8C16G,RocketMQ 的消费线程 20 个,通过测试消费性能在 1.5 万 tps 左右。通过 tcpdump 显示在消费的机器存在频繁的域名解析过程;10.x.x.185 向 DNS 服务器 100.x.x.136.domain 和 10.x.x.138.domain 请求解析。而 10.x.x.185 这台机器又是消息发送者的机器 IP,测试的发送和消费分别部署在两台机器上。
问题:消费时为何会有消息发送方的 IP 呢?而且该 IP 还不断进行域名解析。
通过 dump 线程堆栈,如下图:
代码定位:在消费时有通过 MessageExt.bornHost.getBornHostNameString 获取消费这信息。
1 | public class MessageExt extends Message { |
调用 GetBornHostNameString 获取 HostName 时会根据 IP 反查 DNS 服务器:
1 | InetSocketAddress inetSocketAddress = (InetSocketAddress)this.bornHost; |
消费的时候不要使用 MessageExt.bornHost.getBornHostNameString 即可,去掉该属性,配置 8C16G 的机器消费性能在 3 万 TPS,提升了 1 倍。