RocketMQ的FLUSH_SLAVE_TIMEOUT问题定位

现象

前天11点左右有几个业务方找过来说生产环境RocketMQ一直报FLUSH_SLAVE_TIMEOUT异常,查看源码只知道是主从同步超时,但未找到逻辑上导致这个异常的原因

定位问题

跟运维沟通,了解到在这个时间点开启了一个topic的一个group的消费,经比对跟出现异常的时间匹配上,找对应的业务方,业务方认为这个topic还有其余group在消费,别的group消费没问题,那这个应该也没啥问题,这听起来确实也没法反驳,后面观察该group单台消费能力在5000tps的样子,线上一共有4台机器,也就是会有20000的tps(刚开启时有一百多万的数据堆积)

由于这个业务恰好那次上线半个小时出了点问题,后面下线了,而这个业务业务下次上线时间定在3天后,因此准备在压测环境测试看能否复现这个问题,在压测环境堆积了200w数据后,生产者一直造数据,查看broker日志没有出现FLUSH_SLAVE_TIMEOUT的异常,开启该业务group的消费之后,store.log中一直报FLUSH_SLAVE_TIMEOUT,因此基本可以断定为是该消费者导致

后面在mq store模块中加了一些日志,打包到压测环境环境,发现有大量的延迟消息保存到commitLog,每次压测之前都是清空了存储目录了的,正常来说是不会有延迟消息的,后发现延迟消息都是该业务消费者的延迟消息,也就是说这个业务消费消息一直失败,然后一直sendback到broker,也就是以20000tps的速率发送消息到broker,但就算producer端发送压力大,据以前的经验,也应该是BROKER_BUSY,没办法,只能去看主从同步的源码

主从同步流程如下:

主从同步

正常来说groupTransferService唤醒都是代表当前请求已经同步到slave了,失败也应该是超时(超过5s),但日志显示是没超过5s直接返回的失败,也就是图中的步骤4进行了5次无效唤醒

handleHA方法中封装GroupCommitRequest到groupTransferService,后面发现连着的两个request的写入位置差别很大,大于实际消息体的长度,再次加上一些log打包之后发现,这两个消息中间有很多的延迟消息被put到了commitLog,延迟消息在put之前调用的msgInner.setWaitStoreMsgOK(false),而handleHA中判断该值为true才会封装GroupCommitRequest到groupTransferService,也就是说第一条正常同步的消息跟第二条同步异常的消息中间由于插入了大量的延迟消息,而每次主从同步默认最大只同步32k数据,每同步一次数据slave上报一次offset,只要这中间延迟的消息多就一定会导致slave上报超过5次导致的无效唤醒

备注:mq主从配置为SYNC_MASTER,ASYNC_FLUSH

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 216,372评论 6 498
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 92,368评论 3 392
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 162,415评论 0 353
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 58,157评论 1 292
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 67,171评论 6 388
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 51,125评论 1 297
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 40,028评论 3 417
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 38,887评论 0 274
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 45,310评论 1 310
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 37,533评论 2 332
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 39,690评论 1 348
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 35,411评论 5 343
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 41,004评论 3 325
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 31,659评论 0 22
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 32,812评论 1 268
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 47,693评论 2 368
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 44,577评论 2 353

推荐阅读更多精彩内容