rocketmq发送消息偶尔慢或sendKernelImpl exception

1.现象

  观察接口调用耗时,偶尔会出现一笔调用耗时相对较长:超过2s,且都是发送mq的耗时。或偶尔会出现sendKernelImpl exception的错误日志,但消息可以正常消费。

错误时截图

2.环境说明

  rocketmq:4.4.0

  java:1.8

  rocketmq master主要配置:

    brokerRole=SYNC_MASTER

    flushDiskType=ASYNC_FLUSH

3.初次问题排查

  1)最开始怀疑发送mq代码问题,因为只有一个服务出现报错现象,其他服务只是偶尔超过2s。因为代码很少,配置也都一样,比较后排除此原因。

  2)怀疑应用出现full gc。

  幸好我们对应用配置了gc日志,查看出问题前后gc日志,确定没有出现full gc或youthgc,此原因也排除。

3)怀疑mq出现full gc

  登录服务器,查看master、slave的gc日志,没有问题。此时陷入了迷茫……

4.查阅资料后再次排查问题

  在网上搜索异常信息,网上说可能是linux虚拟内存问题,查看/var/log/message日志,发现不符。

  继续查看告警时master的日志,发现store.log中有些不正常,截图如下:

master日志

  继续查看slave的日志,似乎有些问题:

slave日志截图


5.研究rocketmq主从同步原理、源码

  1)slave心跳(HAClient)

    连接master后,会等待5s向master发送心跳(心跳中包含slave的进度),然后每收到master的消息都会更新lasterwritetime。

  线程最长1s运行一次,若当前时间-lasterwritetime>5s(haSendHeartbeatInterval默认为5),就会向master发送心跳。

  若当前时间-lasterwritetime>20s(haHousekeepingInterval)时关闭连接。

  会记录上传mater的进度currentReportedOffset,当存储的数据大于上传进度后会向master发送心跳。

  2)master心跳(HAConnection

  等待slave连接,建立连接后创建一个读处理对象ReadSocketService、写处理对象WriteSocketService。

  读处理对象,最长每1s运行一次,有slave的数据后更新lastReadTime。当当前时间-lastReadTime>20s(haHousekeepingInterval)时关闭连接。

  写处理对象,最长1s运行一次,但是必须等slave上传进度后才会执行后续逻辑(slave建立连接后需要等haSendHeartbeatInterval间隔才会上传心跳)。

  根据slave心跳的进度设置回应进度。当master的进度比slave大时,向slave发送心跳。

  当前时间-最后写slave的时间>haSendHeartbeatInterval时向slave发送心跳。

3)心跳断开原因

  至此,心跳断开的原因已经找到,主从心跳间隔都采用的默认值5s,因为各种原因,当没有新mq消息产生时,主从谁先谁后发心跳是无法保证的。当连续4都是主先发心跳时,slave每次收到心跳后都会更新lasterwritetime,从而无法触发向主发送心跳。而主超过20s都没有收到从的心跳后会认为从已下线,从而关闭从的连接。

4)master接收mq消息处理流程

  因当前配置的是SYNC_MASTER模式,master收到客户端发过来的消息后,首先进行持久化。

  然后检查必须有一个slave在线,并且等待至少有一个slave的进度与当前master一致。

5)偶尔慢或client报错原因

  当slave刚连上master后,此时发送mq消息,master持久化后会等待slave上传心跳并消息进度一致。但slave却需要等5s才第一次向master发送心跳,所以可能会出现发送mq慢或超过3s客户端出现开始时的错误日志。

6.解决方案

  方案1:将主从模式修改为ASYNC_MASTER模式

  这样master持久化后不用检测或等待slave状态。缺点就是当master突然挂掉后,可能存在少量消息没有同步到slave的情况,从而可能丢消息。

  方案2: slave的配置文件中新增haSendHeartbeatInterval=3

  这样就不会出现连续4次都是master先发送心跳,从而保证心跳为长连接。心跳没有重连,也就不会开始的问题。

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