记一次 XXL-MQ消息消费失败的排查过程

写在前面

     作者一直想深入的去研究一款消息队列MQ,例如 延迟消费,广播消息,失败重试等机制.
 奈何市面上的MQ中间件太多了,如kafka,activeMQ,rocketMQ....所以也一直在纠结该以哪款为入手点,对新人友好?
 想起作者曾深入的研究了xuxueli大佬的分布式调度系统(XXL-JOB),然后进入XXL社区,刚好发现了的另一个开源项目,即分布式消息队列(XXL-MQ).       
   
   简而言之四个字,以小见大,懂得都懂
    

问题复现

 生产者A成功发送了数条有效消息,并且消息中心有对应记录,但是消费者B一直消费失败,没有反应

问题分析

 首先上一张简易图,来描述一个消息从生产到消费的过程
 1 生产者A推送消息至MQ消息中心
 2 MQ消息中心将此消息进行备份保存
 3 消费者B开启定时线程轮训获取MQ消息中心 消息com.xxl.mq.client.consumer.thread.ConsumerThread
 4 消息中心返回消息

结合我们前面的图,消息发送成功,数据库也有对应数据,那就是 3,4 步有问题了,
我们Debug打下断点看下
// pullNewMessage // 向消息中心拉取消息
List<XxlMqMessage> messageList = XxlMqClientFactory.getXxlMqBroker().pullNewMessage(mqConsumer.topic(), mqConsumer.group(), activeInfo.rank, activeInfo.total, 100);

List<XxlMqMessage> list = xxlMqMessageDao.pullNewMessage(XxlMqMessageStatus.NEW.name(), topic, group, consumerRank, consumerTotal, pagesize);

这里我们就看到了这里的DAO层 没有查询出数据库的数据,导致没有拉到消息,
我们用mybatis-log插件来看一下这里的sql查询语句是什么
#MybatisLog插件配置 可用于查看mybatis 底层执行sql 过程，默认关闭,根据业务自行打开
mybatis.configuration.log-impl:org.apache.ibatis.logging.stdout.StdOutImpl

得到查询的sql语句
SELECT *
FROM xxl_mq_message t
WHERE t.topic = 'topic_1'
AND t.group = 'DEFAULT'
AND t.status = 'NEW'
AND t.effectTime < NOW()
AND ((t.shardingId = 0
		AND MOD(t.id, 2) = 0)
	OR (t.shardingId > 0
		AND MOD(t.shardingId, 2) = 0))
ORDER BY t.id ASC
LIMIT 100
 最后发现 执行select now() 本来是获取当前时间的,不应该是17:50:00 这样吗?
 为什么是 07:12:00 这样差这么大?

 然后登录我的Mysql(docker部署)服务器查看时间是否正确,是否有人在演我?
 果然如此 Mysql容器内居然时间是Tue Feb 22 07:56:10 UTC 2022
 和我的虚拟机 2022年 02月 22日 星期二 15:54:45 CST 这种一看就是时间格式时区这些对不上
 也因此导致了查询语句 select now() 匹配的时候不对,然后没有查询出数据,消费者也就没有可消费的

问题解决

既然知道了是Mysql容器时区问题的那就直接暴力点,将mysql的时区修改统一就好,参照以下链接

docker mysql 修改时区

cp /usr/share/zoneinfo/Asia/Shanghai /etc/localtime 然后重启mysql

问题验证/完美解决

写在后面

持续更新分布式消息队列XXL_MQ源码解读
以小见大,由浅入深,逐渐领略消息中间件背后的故事

我是杨少,祝你幸福