You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@rocketmq.apache.org by GitBox <gi...@apache.org> on 2022/04/29 20:19:10 UTC

[GitHub] [rocketmq] 912988434 opened a new issue, #4226: scheduleMessageOffset异常，延迟消费和消息重试失败

912988434 opened a new issue, #4226:
URL: https://github.com/apache/rocketmq/issues/4226

   版本：4.9.2
   现象： 设置delayLevel=3 时，SCHEDULE_TOPIC_XXXX可以收到消息，但是真正的topic无法收到消息，同时别的topic消息失败时重试也失败(这里应该是默认设置也是从10s开始重试），检查broker状态发现 'scheduleMessageOffset_3 169171,198299' ，猜测和这个相关，感觉是10s这个延时时间调调消息都失败了，查看
   storeerror.log 内容如下：
   `2022-03-13 03:45:38 WARN FlushConsumeQueueService - Offset not matched. Request offset: 18000000, firstOffset: 12000000, lastOffset: 18000000, mappedFileSize: 6000000, mappedFiles count: 1
   2022-03-13 03:45:39 WARN FlushConsumeQueueService - Offset not matched. Request offset: 18000000, firstOffset: 12000000, lastOffset: 18000000, mappedFileSize: 6000000, mappedFiles count: 1
   2022-04-14 19:11:48 WARN FlushConsumeQueueService - Offset not matched. Request offset: 6000000, firstOffset: 0, lastOffset: 6000000, mappedFileSize: 6000000, mappedFiles count: 1
   2022-04-14 19:11:49 WARN FlushConsumeQueueService - Offset not matched. Request offset: 6000000, firstOffset: 0, lastOffset: 6000000, mappedFileSize: 6000000, mappedFiles count: 1
   2022-04-14 19:11:50 WARN FlushConsumeQueueService - Offset not matched. Request offset: 6000000, firstOffset: 0, lastOffset: 6000000, mappedFileSize: 6000000, mappedFiles count: 1`
   
   想问一下这个问题是如何产生的，或者我该去查看哪个日志区排查这个问题，并且该如何去解决？


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] 912988434 commented on issue #4226: scheduleMessageOffset异常，延迟消费和消息重试失败

Posted by GitBox <gi...@apache.org>.
912988434 commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1114024748

   > 你能提供更多的日志吗？比如重试失败日志，查看broker_default.log是否有更多异常日志。
   
   
   
   > Can you provide more log? For example, retry failure logs, and check whether broker_default.log has more abnormal log.
   
   我查看了上面时间段的 broker_default.log 的日志 如下：
   2022-03-13 03:45:13 INFO QuorumAckChecker-n0 - [n0][LEADER] term=3 ledgerBegin=6342959 ledgerEnd=7981971 committed=7981971 watermarks={3:{"n0":7981971,"n1":7981971,"n2":7981971}}
   2022-03-13 03:45:15 WARN PullMessageThread_5 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_98 - Offset not matched. Request offset: 892124376, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_74 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_80 - Offset not matched. Request offset: 892124376, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_60 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_42 - Offset not matched. Request offset: 892124376, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_106 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_115 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_87 - Offset not matched. Request offset: 892124376, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_80 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_62 - Offset not matched. Request offset: 892124376, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_54 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_103 - Offset not matched. Request offset: 892124376, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:15 WARN PullMessageThread_97 - Offset not matched. Request offset: 892492989, firstOffset: 6442450944, lastOffset: 8589934592, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-03-13 03:45:16 INFO QuorumAckChecker-n0 - [n0][LEADER] term=3 ledgerBegin=6342959 ledgerEnd=7982037 committed=7982037 watermarks={3:{"n0":7982037,"n1":7982037,"n2":7982037}}
   
   
   2022-04-14 19:11:15 WARN PullMessageThread_71 - Offset not matched. Request offset: 892124376, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_39 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_1 - Offset not matched. Request offset: 892124376, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_91 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_50 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_83 - Offset not matched. Request offset: 892124376, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_59 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_40 - Offset not matched. Request offset: 892124376, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_93 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_32 - Offset not matched. Request offset: 892124376, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_28 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:15 WARN PullMessageThread_17 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:16 WARN PullMessageThread_47 - Offset not matched. Request offset: 892124376, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   2022-04-14 19:11:16 WARN PullMessageThread_116 - Offset not matched. Request offset: 892492989, firstOffset: 11811160064, lastOffset: 13958643712, mappedFileSize: 1073741824, mappedFiles count: 2
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] dongeforever commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
dongeforever commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1120579377

   @ni-ze 那就是这个原因了。对于二次发送链路，采取特殊的校验逻辑是有必要的。为了确保安全，最好是保留一个比较大的Buffer。


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] ni-ze commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
ni-ze commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1120369770

   > @ni-ze
   > 
   > 你复现的问题，可能跟这个Issue关系不大，但确实是一个比较好的问题，可以考虑单独开一个Issue解决。
   > 
   > 在定时、事务、重试等场景中，不止是会改Topic名字，还会新增一些属性等，这个地方一直是个设计脆弱点。
   > 
   > 看看如下方式能否规避这个问题：
   > 
   > 1. 用户配置的maxMessageSize，只对body生效，不包含属性长度和Topic长度
   > 2. 对于一次发送的链路，Topic长度和属性长度，要按照最大值 - maxBlank来确定；二次发送链路（从定时或者事务里出来的），增加一个特殊的参数，以确保要发送成功；
   
   从该同学的报错日志来看，延迟消息投递失败，的确是长度超长引起的。
   ![image](https://user-images.githubusercontent.com/31175234/167287070-df30c5a0-d70d-464a-a3fd-571b37a62dcc.png)
   
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] duhenglucky commented on issue #4226: scheduleMessageOffset异常，延迟消费和消息重试失败

Posted by GitBox <gi...@apache.org>.
duhenglucky commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1114108379

   @912988434 如果方便的话，可以看下store.log 以及storeerror.log 吗？看一下有没有相关的日志，可以搜一下"schedule CQ offset"


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] ni-ze commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
ni-ze commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1119577186

   https://github.com/apache/rocketmq/pull/4250
   @912988434 请帮忙review下这个pr


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] sunxi92 commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
sunxi92 commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1127406353

   @ni-ze Can you paste your test case,  I want to test if this problem exists in the version we are currently using.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] ni-ze commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
ni-ze commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1118430575

   我用如下方式复现了，broker端设置消息长度最大长度65536，客户端设置不压缩消息体。发送消息body长度为64756，userProperties长度约440，tag长度28，key长度44。结果如下：
   正常发送成功：
   ![image](https://user-images.githubusercontent.com/31175234/166911233-346fa41a-0afb-4644-91d2-fce2d1405f38.png)
   消费失败后sendback长度超长：
   ![image](https://user-images.githubusercontent.com/31175234/166911393-e5765fed-7e32-4758-9e08-05552dba2f46.png)
   
   发送延迟消息成功：
   ![image](https://user-images.githubusercontent.com/31175234/166911591-9b2eeb55-92d9-4393-a60f-0c9885d4cf74.png)
   延迟消息从schedule topic写入正常topic失败：
   ![image](https://user-images.githubusercontent.com/31175234/166911719-7d4ae250-f4af-4e74-b8c3-be604f886c1d.png)
   
   延迟消息一直写，日志反复不断打印，broker重启后仍然打印：
   ![image](https://user-images.githubusercontent.com/31175234/166911896-ca927d8e-462d-4d73-b4c3-923c4e67cc63.png)
   
   
   
   
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] 912988434 commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
912988434 commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1114227636

   > @912988434 如果方便的话，可以看下store.log 以及storeerror.log 吗？看一下有没有相关的日志，可以搜一下"schedule CQ offset",还有搜索一下" Offset for /home/admin/store/consumequeue/SCHEDULE_TOPIC_XXXX/{换成自己的} not matched. " 之类的日志，上面的关键字" grep SCHEDULE_TOPIC_XXXX |grep not matched" 即可以? 如果方便的话，可以微信加 rocketmq666 提供一下日志
   
   好的，已经加你了


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] Git-Yang commented on issue #4226: scheduleMessageOffset异常，延迟消费和消息重试失败

Posted by GitBox <gi...@apache.org>.
Git-Yang commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1113898538

   Can you provide more log? For example, retry failure logs, and check whether broker_default.log has more abnormal log.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] duhenglucky closed issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
duhenglucky closed issue #4226: scheduleMessageOffset exception
URL: https://github.com/apache/rocketmq/issues/4226


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] ni-ze commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
ni-ze commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1129500942

   https://github.com/apache/rocketmq/pull/4338
   @dongeforever @duhenglucky @sunxi92 
   重新提了个PR maxMessageSize只对body生效。看现在的版本客户端这个值就是对body生效的，broker端语意就变成对整个消息长度有效了。


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org

[GitHub] [rocketmq] dongeforever commented on issue #4226: scheduleMessageOffset exception

Posted by GitBox <gi...@apache.org>.
dongeforever commented on issue #4226:
URL: https://github.com/apache/rocketmq/issues/4226#issuecomment-1120124946

   @ni-ze 
   
   你复现的问题，可能跟这个Issue关系不大，但确实是一个比较好的问题，可以考虑单独开一个Issue解决。
   
   在定时、事务、重试等场景中，不止是会改Topic名字，还会新增一些属性等，这个地方一直是个设计脆弱点。
   
   看看如下方式能否规避这个问题：
   1.  用户配置的maxMessageSize，只对body生效，不包含属性长度和Topic长度
   2. 对于一次发送的链路，Topic长度和属性长度，要按照最大值 - maxBlank来确定；二次发送链路（从定时或者事务里出来的），增加一个特殊的参数，以确保要发送成功；


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: dev-unsubscribe@rocketmq.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org