开发者社区 > 云原生 > 正文

[BUG]-Dledger:逻辑队列顺序可能错误

一.基本信息 版本: 4.5.1 部署模式: Dledger 部署状况: 1个broker,broker包含3个rocketmq节点 配置文件:

  1. 节点1配置文件

    fileReservedTime=72 autoCreateTopicEnable=false autoCreateSubscriptionGroup=false flushDiskType=SYNC_FLUSH brokerRole=SYNC_MASTER brokerClusterName = c1 brokerName=c1b1 listenPort=30911 storePathRootDir=/home/rocketmq/store/node00 storePathCommitLog=/home/rocketmq/store/node00/commitlog enableDLegerCommitLog=true dLegerGroup=RaftNode01 dLegerPeers=n0-192.168.4.3:40911;n1-192.168.4.4:40911;n2-192.168.4.5:40911 dLegerSelfId=n0 sendMessageThreadPoolNums=64 queryMessageThreadPoolNums=16 pullMessageThreadPoolNums=64 useEpollNativeSelector=true useReentrantLockWhenPutMessage=true

  2. 节点2配置文件

    fileReservedTime=72 autoCreateTopicEnable=false autoCreateSubscriptionGroup=false flushDiskType=SYNC_FLUSH brokerRole=SYNC_MASTER brokerClusterName = c1 brokerName=c1b1 listenPort=30911 storePathRootDir=/home/rocketmq/store/node00 storePathCommitLog=/home/rocketmq/store/node00/commitlog enableDLegerCommitLog=true dLegerGroup=RaftNode01 dLegerPeers=n0-192.168.4.3:40911;n1-192.168.4.4:40911;n2-192.168.4.5:40911 dLegerSelfId=n1 sendMessageThreadPoolNums=64 queryMessageThreadPoolNums=16 pullMessageThreadPoolNums=64 useEpollNativeSelector=true useReentrantLockWhenPutMessage=true

  3. 节点3配置文件

fileReservedTime=72 autoCreateTopicEnable=false autoCreateSubscriptionGroup=false flushDiskType=SYNC_FLUSH brokerRole=SYNC_MASTER brokerClusterName = c1 brokerName=c1b1 listenPort=30911 storePathRootDir=/home/rocketmq/store/node00 storePathCommitLog=/home/rocketmq/store/node00/commitlog enableDLegerCommitLog=true dLegerGroup=RaftNode01 dLegerPeers=n0-192.168.4.3:40911;n1-192.168.4.4:40911;n2-192.168.4.5:40911 dLegerSelfId=n2 sendMessageThreadPoolNums=64 queryMessageThreadPoolNums=16 pullMessageThreadPoolNums=64 useEpollNativeSelector=true useReentrantLockWhenPutMessage=true

二.异常情况 1.异常说明: 异常发生在n1节点上,异常日志位于storeerror.log:

[2019-08-16 15:13:59.817] WARN ReputMessageService - [BUG]logic queue order maybe wrong, expectLogicOffset: 247183480 currentLogicOffset: 247183460 Topic: DD_SYNC_SUB QID: 11 Diff: 20 [2019-08-16 15:13:59.818] WARN ReputMessageService - [BUG]logic queue order maybe wrong, expectLogicOffset: 247183500 currentLogicOffset: 247183480 Topic: DD_SYNC_SUB QID: 11 Diff: 20 [2019-08-16 15:13:59.820] WARN ReputMessageService - [BUG]logic queue order maybe wrong, expectLogicOffset: 247183520 currentLogicOffset: 247183500 Topic: DD_SYNC_SUB QID: 11 Diff: 20 [2019-08-16 15:13:59.860] WARN ReputMessageService - [BUG]logic queue order maybe wrong, expectLogicOffset: 244686580 currentLogicOffset: 244686560 Topic: LY_SUB QID: 1 Diff: 20 [2019-08-16 15:13:59.871] WARN ReputMessageService - [BUG]logic queue order maybe wrong, expectLogicOffset: 247181980 currentLogicOffset: 247181960 Topic: DD_SYNC_SUB QID: 0 Diff: 20 [2019-08-16 15:13:59.874] WARN ReputMessageService - [BUG]logic queue order maybe wrong, expectLogicOffset: 247183060 currentLogicOffset: 247183040 Topic: DD_SYNC_SUB QID: 3 Diff: 20 [2019-08-16 15:13:59.888] WARN ReputMessageService - [BUG]logic queue order maybe wrong, expectLogicOffset: 244686600 currentLogicOffset: 244686580 Topic: LY_SUB QID: 1 Diff: 20

2.可能的原因: n1节点的机器发生过宕机,宕机时间段为 2019-8-03 16:16:40 ~ 2019-8-03 17:08:00 。由于是16日发现的异常,发现时间较晚,8月3日的日志已清除了。无法追溯当时恢复时的状况。

3.尝试解决的方法: (1) 对n1节点进行重启,发现启动恢复过程后,日常日志仍存在。下面为启动过程中数据恢复日志:

[2019-08-18 21:14:54.429] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/%RETRY%DD_SYNC_CG/0/00000000000024000000 0 0 0 [2019-08-18 21:14:54.430] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/%RETRY%DD_SYNC_CG/0/00000000000024000000 28271400 [2019-08-18 21:14:54.434] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/2/00000000000000000000 0 0 0 [2019-08-18 21:14:54.434] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/2/00000000000000000000 4406240 [2019-08-18 21:14:54.435] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/3/00000000000000000000 0 0 0 [2019-08-18 21:14:54.435] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/3/00000000000000000000 838700 [2019-08-18 21:14:54.437] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/4/00000000000000000000 0 0 0 [2019-08-18 21:14:54.437] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/4/00000000000000000000 798960 [2019-08-18 21:14:54.438] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/5/00000000000000000000 0 0 0 [2019-08-18 21:14:54.438] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/5/00000000000000000000 818040 [2019-08-18 21:14:54.439] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/6/00000000000000000000 0 0 0 [2019-08-18 21:14:54.439] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/6/00000000000000000000 854180 [2019-08-18 21:14:54.440] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/7/00000000000000000000 0 0 0 [2019-08-18 21:14:54.440] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/7/00000000000000000000 919960 [2019-08-18 21:14:54.442] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/8/00000000000000000000 0 0 0 [2019-08-18 21:14:54.442] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/8/00000000000000000000 1429200 [2019-08-18 21:14:54.444] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/9/00000000000000000000 0 0 0 [2019-08-18 21:14:54.444] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/9/00000000000000000000 1496860 [2019-08-18 21:14:54.446] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/10/00000000000000000000 0 0 0 [2019-08-18 21:14:54.446] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/10/00000000000000000000 1585000 [2019-08-18 21:14:54.448] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/11/00000000000000000000 0 0 0 [2019-08-18 21:14:54.448] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/11/00000000000000000000 1682000 [2019-08-18 21:14:54.450] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/12/00000000000000000000 0 0 0 [2019-08-18 21:14:54.451] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/12/00000000000000000000 1791980 [2019-08-18 21:14:54.453] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/13/00000000000000000000 0 0 0 [2019-08-18 21:14:54.453] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/13/00000000000000000000 1920000 [2019-08-18 21:14:54.456] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/14/00000000000000000000 0 0 0 [2019-08-18 21:14:54.456] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/14/00000000000000000000 1978020 [2019-08-18 21:14:54.458] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/15/00000000000000000000 0 0 0 [2019-08-18 21:14:54.458] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/15/00000000000000000000 2032680 [2019-08-18 21:14:54.459] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/16/00000000000000000000 0 0 0 [2019-08-18 21:14:54.459] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/16/00000000000000000000 2081820 [2019-08-18 21:14:54.460] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/17/00000000000000000000 0 0 0 [2019-08-18 21:14:54.460] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/SCHEDULE_TOPIC_XXXX/17/00000000000000000000 4304240 [2019-08-18 21:14:54.462] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/0/00000000000252000000 [2019-08-18 21:14:54.479] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/0/00000000000258000000 [2019-08-18 21:14:54.498] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/0/00000000000258000000 0 0 0 [2019-08-18 21:14:54.498] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/0/00000000000258000000 262186580 [2019-08-18 21:14:54.524] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/1/00000000000252000000 [2019-08-18 21:14:54.526] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/1/00000000000258000000 [2019-08-18 21:14:54.528] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/1/00000000000258000000 0 0 0 [2019-08-18 21:14:54.528] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/1/00000000000258000000 262187460 [2019-08-18 21:14:54.529] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/2/00000000000252000000 [2019-08-18 21:14:54.531] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/2/00000000000258000000 [2019-08-18 21:14:54.532] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/2/00000000000258000000 0 0 0 [2019-08-18 21:14:54.532] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/2/00000000000258000000 262186940 [2019-08-18 21:14:54.534] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/3/00000000000252000000 [2019-08-18 21:14:54.536] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/3/00000000000258000000 [2019-08-18 21:14:54.537] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/3/00000000000258000000 0 0 0 [2019-08-18 21:14:54.537] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/3/00000000000258000000 262187080 [2019-08-18 21:14:54.539] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/4/00000000000252000000 [2019-08-18 21:14:54.540] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/4/00000000000258000000 [2019-08-18 21:14:54.542] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/4/00000000000258000000 0 0 0 [2019-08-18 21:14:54.542] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/4/00000000000258000000 262185960 [2019-08-18 21:14:54.544] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/5/00000000000252000000 [2019-08-18 21:14:54.545] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/5/00000000000258000000 [2019-08-18 21:14:54.547] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/5/00000000000258000000 0 0 0 [2019-08-18 21:14:54.547] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/5/00000000000258000000 262187740 [2019-08-18 21:14:54.548] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/6/00000000000252000000 [2019-08-18 21:14:54.550] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/6/00000000000258000000 [2019-08-18 21:14:54.551] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/6/00000000000258000000 0 0 0 [2019-08-18 21:14:54.551] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/6/00000000000258000000 262189360 [2019-08-18 21:14:54.553] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/7/00000000000252000000 [2019-08-18 21:14:54.555] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/7/00000000000258000000 [2019-08-18 21:14:54.556] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/7/00000000000258000000 0 0 0 [2019-08-18 21:14:54.556] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/7/00000000000258000000 262187220 [2019-08-18 21:14:54.558] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/8/00000000000252000000 [2019-08-18 21:14:54.560] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/8/00000000000258000000 [2019-08-18 21:14:54.561] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/8/00000000000258000000 0 0 0 [2019-08-18 21:14:54.561] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/8/00000000000258000000 262187680 [2019-08-18 21:14:54.563] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/9/00000000000252000000 [2019-08-18 21:14:54.564] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/9/00000000000258000000 [2019-08-18 21:14:54.566] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/9/00000000000258000000 0 0 0 [2019-08-18 21:14:54.566] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/9/00000000000258000000 262188560 [2019-08-18 21:14:54.567] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/10/00000000000252000000 [2019-08-18 21:14:54.569] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/10/00000000000258000000 [2019-08-18 21:14:54.570] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/10/00000000000258000000 0 0 0 [2019-08-18 21:14:54.570] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/10/00000000000258000000 262187460 [2019-08-18 21:14:54.572] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/11/00000000000252000000 [2019-08-18 21:14:54.574] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/11/00000000000258000000 [2019-08-18 21:14:54.575] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/11/00000000000258000000 0 0 0 [2019-08-18 21:14:54.575] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/11/00000000000258000000 262187520 [2019-08-18 21:14:54.577] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/12/00000000000252000000 [2019-08-18 21:14:54.578] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/12/00000000000258000000 [2019-08-18 21:14:54.580] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/12/00000000000258000000 0 0 0 [2019-08-18 21:14:54.580] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/12/00000000000258000000 262187060 [2019-08-18 21:14:54.582] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/13/00000000000252000000 [2019-08-18 21:14:54.583] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/13/00000000000258000000 [2019-08-18 21:14:54.584] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/13/00000000000258000000 0 0 0 [2019-08-18 21:14:54.585] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/13/00000000000258000000 262186460 [2019-08-18 21:14:54.586] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/14/00000000000252000000 [2019-08-18 21:14:54.588] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/14/00000000000258000000 [2019-08-18 21:14:54.589] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/14/00000000000258000000 0 0 0 [2019-08-18 21:14:54.589] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/14/00000000000258000000 262185940 [2019-08-18 21:14:54.591] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/15/00000000000252000000 [2019-08-18 21:14:54.593] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/15/00000000000258000000 [2019-08-18 21:14:54.594] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/15/00000000000258000000 0 0 0 [2019-08-18 21:14:54.594] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/DD_SYNC_SUB/15/00000000000258000000 262184560 [2019-08-18 21:14:54.595] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/%RETRY%LY_SUB_CG/0/00000000000000000000 0 0 0 [2019-08-18 21:14:54.595] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/%RETRY%LY_SUB_CG/0/00000000000000000000 1693640 [2019-08-18 21:14:54.596] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/0/00000000000252000000 [2019-08-18 21:14:54.598] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/0/00000000000258000000 [2019-08-18 21:14:54.599] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/0/00000000000258000000 0 0 0 [2019-08-18 21:14:54.599] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/0/00000000000258000000 259639420 [2019-08-18 21:14:54.600] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/1/00000000000252000000 [2019-08-18 21:14:54.602] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/1/00000000000258000000 [2019-08-18 21:14:54.602] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/1/00000000000258000000 0 0 0 [2019-08-18 21:14:54.602] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/1/00000000000258000000 259639020 [2019-08-18 21:14:54.604] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/2/00000000000252000000 [2019-08-18 21:14:54.606] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/2/00000000000258000000 [2019-08-18 21:14:54.606] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/2/00000000000258000000 0 0 0 [2019-08-18 21:14:54.606] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/2/00000000000258000000 259639660 [2019-08-18 21:14:54.608] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/3/00000000000252000000 [2019-08-18 21:14:54.610] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/3/00000000000258000000 [2019-08-18 21:14:54.610] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/3/00000000000258000000 0 0 0 [2019-08-18 21:14:54.610] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/3/00000000000258000000 259639200 [2019-08-18 21:14:54.612] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/4/00000000000252000000 [2019-08-18 21:14:54.614] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/4/00000000000258000000 [2019-08-18 21:14:54.614] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/4/00000000000258000000 0 0 0 [2019-08-18 21:14:54.614] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/4/00000000000258000000 259638580 [2019-08-18 21:14:54.616] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/5/00000000000252000000 [2019-08-18 21:14:54.618] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/5/00000000000258000000 [2019-08-18 21:14:54.618] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/5/00000000000258000000 0 0 0 [2019-08-18 21:14:54.618] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/5/00000000000258000000 259638100 [2019-08-18 21:14:54.620] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/6/00000000000252000000 [2019-08-18 21:14:54.622] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/6/00000000000258000000 [2019-08-18 21:14:54.622] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/6/00000000000258000000 0 0 0 [2019-08-18 21:14:54.622] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/6/00000000000258000000 259638300 [2019-08-18 21:14:54.624] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/7/00000000000252000000 [2019-08-18 21:14:54.626] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/7/00000000000258000000 [2019-08-18 21:14:54.626] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/7/00000000000258000000 0 0 0 [2019-08-18 21:14:54.626] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/7/00000000000258000000 259639180 [2019-08-18 21:14:54.628] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/8/00000000000252000000 [2019-08-18 21:14:54.630] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/8/00000000000258000000 [2019-08-18 21:14:54.630] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/8/00000000000258000000 0 0 0 [2019-08-18 21:14:54.630] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/8/00000000000258000000 259638680 [2019-08-18 21:14:54.632] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/9/00000000000252000000 [2019-08-18 21:14:54.633] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/9/00000000000258000000 [2019-08-18 21:14:54.634] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/9/00000000000258000000 0 0 0 [2019-08-18 21:14:54.634] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/9/00000000000258000000 259638660 [2019-08-18 21:14:54.636] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/10/00000000000252000000 [2019-08-18 21:14:54.637] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/10/00000000000258000000 [2019-08-18 21:14:54.638] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/10/00000000000258000000 0 0 0 [2019-08-18 21:14:54.638] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/10/00000000000258000000 259640000 [2019-08-18 21:14:54.640] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/11/00000000000252000000 [2019-08-18 21:14:54.641] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/11/00000000000258000000 [2019-08-18 21:14:54.642] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/11/00000000000258000000 0 0 0 [2019-08-18 21:14:54.642] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/11/00000000000258000000 259639400 [2019-08-18 21:14:54.644] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/12/00000000000252000000 [2019-08-18 21:14:54.645] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/12/00000000000258000000 [2019-08-18 21:14:54.646] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/12/00000000000258000000 0 0 0 [2019-08-18 21:14:54.646] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/12/00000000000258000000 259638200 [2019-08-18 21:14:54.648] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/13/00000000000252000000 [2019-08-18 21:14:54.649] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/13/00000000000258000000 [2019-08-18 21:14:54.650] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/13/00000000000258000000 0 0 0 [2019-08-18 21:14:54.650] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/13/00000000000258000000 259638920 [2019-08-18 21:14:54.651] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/14/00000000000252000000 [2019-08-18 21:14:54.653] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/14/00000000000258000000 [2019-08-18 21:14:54.654] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/14/00000000000258000000 0 0 0 [2019-08-18 21:14:54.654] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/14/00000000000258000000 259638720 [2019-08-18 21:14:54.655] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/15/00000000000252000000 [2019-08-18 21:14:54.657] INFO main - recover next consume queue file, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/15/00000000000258000000 [2019-08-18 21:14:54.658] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/15/00000000000258000000 0 0 0 [2019-08-18 21:14:54.658] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/EH_GM_LY_SUB/15/00000000000258000000 259638980 [2019-08-18 21:14:54.659] INFO main - recover current consume queue file over, /home/rocketmq/store/node00/consumequeue/%DLQ%DD_SYNC_CG/0/00000000000000000000 0 0 0 [2019-08-18 21:14:54.659] INFO main - recover current consume queue queue over /home/rocketmq/store/node00/consumequeue/%DLQ%DD_SYNC_CG/0/00000000000000000000 2228340 [2019-08-18 21:14:54.660] INFO main - load /home/rocketmq/store/node00/commitlog/00000000442381631488 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000443455373312 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000444529115136 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000445602856960 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000446676598784 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000447750340608 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000448824082432 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000449897824256 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000450971566080 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000452045307904 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000453119049728 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000454192791552 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000455266533376 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000456340275200 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000457414017024 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000458487758848 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000459561500672 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000460635242496 OK [2019-08-18 21:14:54.661] INFO main - load /home/rocketmq/store/node00/commitlog/00000000461708984320 OK [2019-08-18 21:14:54.662] INFO main - load /home/rocketmq/store/node00/commitlog/00000000462782726144 OK [2019-08-18 21:14:54.662] INFO main - load /home/rocketmq/store/node00/commitlog/00000000463856467968 OK [2019-08-18 21:14:54.662] INFO main - load /home/rocketmq/store/node00/commitlog/00000000464930209792 OK [2019-08-18 21:14:54.662] INFO main - load /home/rocketmq/store/node00/commitlog/00000000466003951616 OK [2019-08-18 21:14:54.662] INFO main - load /home/rocketmq/store/node00/commitlog/00000000467077693440 OK [2019-08-18 21:14:54.662] INFO main - load /home/rocketmq/store/node00/commitlog/00000000468151435264 OK [2019-08-18 21:14:54.662] INFO main - load /home/rocketmq/store/node00/commitlog/000000004692251770

三. 寻求 1.导致触发这个Bug的原因可能有哪些? 2.这个异常有解决方法吗?

从恢复日志中看出,在执行org.apache.rocketmq.store.dledger.DLedgerCommitLog#recover方法时,dLedgerFileStore.recover() 发生了异常,导致不能执行后续的 super.recoverNormally(maxPhyOffsetOfConsumeQueue)。

恢复日志中异常日志: [2019-08-18 21:14:58.515] INFO main - Recover data file to the end of /home/rocketmq/store/node00/commitlog/00000000492847497216 io.openmessaging.storage.dledger.exception.DLedgerException: [code=414,name=DISK_ERROR,desc=] pos 0 != 492973339454 at io.openmessaging.storage.dledger.utils.PreConditions.check(PreConditions.java:41) ~[dledger-0.1.jar:na] at io.openmessaging.storage.dledger.store.file.DLedgerMmapFileStore.recover(DLedgerMmapFileStore.java:216) ~[dledger-0.1.jar:na] at org.apache.rocketmq.store.dledger.DLedgerCommitLog.recover(DLedgerCommitLog.java:266) [rocketmq-store-4.5.1.jar:4.5.1] at org.apache.rocketmq.store.dledger.DLedgerCommitLog.recoverAbnormally(DLedgerCommitLog.java:323) [rocketmq-store-4.5.1.jar:4.5.1] at org.apache.rocketmq.store.DefaultMessageStore.recover(DefaultMessageStore.java:1334) [rocketmq-store-4.5.1.jar:4.5.1] at org.apache.rocketmq.store.DefaultMessageStore.load(DefaultMessageStore.java:197) [rocketmq-store-4.5.1.jar:4.5.1] at org.apache.rocketmq.broker.BrokerController.initialize(BrokerController.java:256) [rocketmq-broker-4.5.1.jar:4.5.1] at org.apache.rocketmq.broker.BrokerStartup.createBrokerController(BrokerStartup.java:218) [rocketmq-broker-4.5.1.jar:4.5.1] at org.apache.rocketmq.broker.BrokerStartup.main(BrokerStartup.java:58) [rocketmq-broker-4.5.1.jar:4.5.1] [

原提问者GitHub用户faryang-sh

展开
收起
芬奇福贵 2023-05-26 15:56:42 6220 0
1 条回答
写回答
取消 提交回答
  • INFO日志正常,可以忽略。这是一个代码风格的问题。 当恢复日志文件时,它将结束。

    最好将恢复的正常端和异常端分开

    原回答者GitHub用户dongeforever

    2023-05-26 17:53:19
    赞同 展开评论 打赏

阿里云拥有国内全面的云原生产品技术以及大规模的云原生应用实践,通过全面容器化、核心技术互联网化、应用 Serverless 化三大范式,助力制造业企业高效上云,实现系统稳定、应用敏捷智能。拥抱云原生,让创新无处不在。

相关电子书

更多
低代码开发师(初级)实战教程 立即下载
冬季实战营第三期:MySQL数据库进阶实战 立即下载
阿里巴巴DevOps 最佳实践手册 立即下载