背景
使用了腾讯云封装的 Pulsar 作为云消息队列,消费中有大致就是一个异步 MQ 日志落库的逻辑。我们日志库使用的 ClickHouse,那天 CK 出现了一段时间的连接异常导致 MQ 消费一直消费异常,进而 Consumer 没再接收到任何消息,但是我本地主动发起了一笔请求,消息成功消费日志落库,一通迷惑现象!
排查过程
首先大致梳理一下关键的时间节点如下:
2024-06-26 12:33:00.000 ~ 2024-06-26 13:47:00.000 CK异常持续时间
2024-06-26 12:53:00.000 ~ 2024-06-26 13:11:00.000 异常集中爆发时间
2024-06-26 13:11:00.000 ~ 2024-06-26 14:27:53.000 消息开始积压,无任何消息被消费
2024-06-26 14:27:53.000 ~ 2024-06-26 14:40:00.000 积压消息陆续得到消费
2024-06-26 13:11:00.000 不再向消费者推送消息
2024-06-26 14:27:53.000 服务进行了重启,开始陆续消费积压消息
2024-06-26 14:40:00.000 积压消息全部得到消费,服务恢复正常
通过观察异常时间段日志及其 CK 数据落库情况,发现虽然 CK 连接异常,但是由于MQ 超时机制,重试后的消息都能正常获取到 CK 连接进而正常落库。
这个都还好理解,MQ 自带的异常重试机制能规避这种异常情况,但是有一个时间点后 Consumer 不再接收任何消息这是有点奇怪的点,难道因为消费者异常消费过多 TDMQ Pulsar 自带服务降级功能,然后触发了服务降级所致吗?
查阅了下 TDMQ Pulsar 版本架构图 ,确实包含降级处理,但是对于这块没有具体描述,其他文章也未对类似情况做过多描述,结合目前表现判定大概率应该是对 Consumer 降级了,出于保护机制导致 MQ 不再投递消息所致。然后后面服务重启了,消费立马恢复正常。
那么接下来就是第二个问题了,为什么我本地请求的能正常落库?当时困惑了好久...太诡异了这事情,查日志,查落库数据,确实也都有,而且其前后依旧有大量 Producer 发送 MQ 但是未被消费,且日志库改笔自测数据创建时间前后也确实无任何其他数据落库。
这个问题一直没到解,也就是今天才去复盘了下这个问题,脑海里突然蹦现了一个猜想,会不会这笔请求根本不是来来自于 PROD!!!!!!
因为该业务PROD 与 UAT 是公用库表的,带着这个疑问去追溯了下当时入库记录 ID(因该业务分布式 ID 生成器 UAT 与 PROD 的累加值不同可以判别)
破案了!!!中间红框圈的两笔就是 Consumer 不在接收消费,但是本地测试请求正常落库的两笔,泪目啊,果然还是老话说的好:事出反常必有妖、往往越诡异的事情成原反而是最简单的。
在使用腾讯云封装的 Pulsar 作为云消息队列的过程中,遇到了ClickHouse(CK)连接异常的问题。由于 CK 连接异常,导致 MQ 消费异常,之后 Consumer 停止接收消息。通过排查,初步判断是 TDMQ Pulsar 的服务降级机制启动,保护了 Consumer。在服务重启后,消费恢复正常。
然而,在 Consumer 停止接收消息期间,出现了一条迷惑的现象:本地发起的一笔请求消息被正常消费并写入了 CK。经过进一步排查发现,这条消息并非来自生产环境(PROD),而是来自用户验收测试环境(UAT)。由于 PROD 与 UAT 共享数据库表,这条消息被误认为是来自生产环境的正常消费。
最终,通过分布式 ID 生成器的不同累加值,确定了这条消息的来源,解决了问题。
总结
遇到问题如果是理论上的问题,可能还是直接从官方手册能得到正解,在平时的修炼过程中多了解下所使用中间件的原理及架构图才能更好更正确的运用。
标题:记一次 MQ 消费失败引发的一系列问题
作者:JonLv
地址:http://39.108.183.139:8080/articles/2024/08/23/1724404094020.html