caojiaqiang commented on issue #10911:
URL: https://github.com/apache/rocketmq/issues/10911#issuecomment-5262146483
Additional production evidence for the incident is provided below.
Production identifiers have been replaced with stable aliases while preserving
the correlations relevant to the investigation.
Important correlation boundary:
- The persisted corrupted message is `AC1A...557A`, with
`UNIQ_KEY=AC11...e110`, born at `2026-08-10 01:54:35.168` from
`producer-host-A:47870`.
- The producer-side decoder exception shown later is from the same producer
host but another TCP connection, `producer-host-A:48252`. It contains the
adjacent request `UNIQ_KEY=AC11...e109`, born at `01:54:35.167`, one
millisecond earlier.
- Therefore, the decoder exception is not claimed to be the target message
itself. It shows that the Broker receive/decode stream for the same producer
host was already interleaved with a `PULL_MESSAGE` frame immediately before the
target message was persisted with a corrupted body.
## 1. Target message metadata
Command:
```bash
sh mqadmin queryMsgById \
-n '<redacted-nameserver>' \
-i 'AC1A...557A'
```
Output:
```text
Topic: business-topic-order-flags
Tags: [null]
Keys: [null]
Queue ID: 6
Queue Offset: 197168851
CommitLog Offset: 1463990167229818
Reconsume Times: 0
Born Timestamp: 2026-08-10 01:54:35,168
Store Timestamp: 2026-08-10 01:54:35,282
Born Host: producer-host-A:47870
Store Host: broker-host-A:10915
System Flag: 0
Properties: {TRACE_ON=true, SHARDING_KEY=<redacted>,
MSG_REGION=DefaultRegion, UNIQ_KEY=AC11...e110, CLUSTER=<redacted-cluster>}
Message Body Path: /tmp/rocketmq/msgbodys/AC1A...557A
MessageTrack [consumerGroup=target-consumer-group-A,
trackType=SUBSCRIBED_BUT_PULL, exceptionDesc=null]
MessageTrack [consumerGroup=target-consumer-group-B,
trackType=UNKNOW_EXCEPTION, exceptionDesc=MQBrokerException: CODE: 206 DESC:
consumer group not online]
```
## 2. Stored message body
The following is the body returned by the message query, with business
identifiers and values redacted.
The `�` characters are the terminal representation of non-text/binary
frame-prefix bytes. The body was also extracted directly from CommitLog as
exactly 2063 bytes; its calculated CRC32 matches the stored BODYCRC as
described in the issue body.
```text
{"eventType":"UPDATE","executeTime":1786298074,"indicator":0,"lastIndicator":0,"schema":"business_schema","tableName":"business_table","inboundIndex":0,"subscribeType":"","rowData":[{"business_id":{"v":"<redacted>"},"flag_a":{"v":0},"flag_b":{"v":0},"flag_c":{"v":1},"flag_d":{"v":0��{"code":11,"extFields":{"queueId":"7","maxMsgNums":"32","sysFlag":"4","suspendTimeoutMillis":"20000","commitOffset":"0","topic":"consumer-topic-A","queueOffset":"0","subscription":"*","clientLogicIdc":"logic-idc-A","subVersion":"0","consumerGroup":"consumer-group-A"},"flag":0,"language":"JAVA","opaque":308838062,"version":190}��{"code":11,"extFields":{"queueId":"0",��{"code":11,"extFields":{"queueId":"0","maxMsgNums":"32","sysFlag":"4","suspendTimeoutMillis":"20000","commitOffset":"0","topic":"consumer-topic-B","queueOffset":"692","subscription":"*","clientLogicIdc":"logic-idc-A","subVersion":"0","consumerGroup":"consumer-group-B"},"flag":0,"language":"JAVA","opaque":265700666,"version":190
}MsgNums":"32","sysFlag":"4","suspendTimeou��{"code":38,"extFields":{"consumerGroup":"consumer-group-C"},"flag":0,"language":"JAVA","opaque":358602024,"version":190}...��{"code":11,"extFields":{"queueId":"2","maxMsgNums":"32","sysFlag":"4","suspendTimeoutMillis":"20000","commitOffset":"0","topic":"consumer-topic-D"...��{"code":11,"extFields":{"queueId":"4","maxMsgNums":"32","sysFlag":"4","suspendTimeoutMillis":"20000","commitOffset":"0","topic":"consumer-topic-E","queueOffset":"0","subscription":"*","clientLogicIdc":"logic-idc-A","subVersion":"0","consumerGroup":"consumer-group-E"...
```
This body contains complete or partial `PULL_MESSAGE` (`code=11`) and
`GET_CONSUMER_LIST_BY_GROUP` (`code=38`) request headers belonging to unrelated
consumers.
## 3. Initial decoder-error burst at 01:54:30
Log analysis for the first incident second gives:
```text
2026-08-10 01:54:30:
decode exception count: 76
distinct remote connections: 76
TooLongFrameException count: 76
2026-08-10 01:54:30 through 01:54:35:
decode exception count: 258
```
The first exception was:
```text
2026-08-10 01:54:30 ERROR NettyServerCodecThread_1 - decode exception,
consumer-host-A:45700
io.netty.handler.codec.TooLongFrameException: Adjusted frame length exceeds
16777216: 3886452713 - discarded
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.fail(LengthFieldBasedFrameDecoder.java:503)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.failIfNecessary(LengthFieldBasedFrameDecoder.java:489)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.exceededFrameLength(LengthFieldBasedFrameDecoder.java:376)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.decode(LengthFieldBasedFrameDecoder.java:419)
at
org.apache.rocketmq.remoting.netty.NettyDecoder.decode(NettyDecoder.java:42)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.decode(LengthFieldBasedFrameDecoder.java:332)
at
io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
at
io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at
io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:61)
at
io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:370)
at
io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:66)
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at java.lang.Thread.run(Thread.java:745)
```
## 4. Producer-host decoder exception at 01:54:35
This is the key exception from `producer-host-A`. The JSON starts as a valid
`SEND_MESSAGE` (`code=10`) header, then after `unitMode=false` it contains
binary frame-prefix bytes followed by the beginning of a `PULL_MESSAGE`
(`code=11`) header:
```text
2026-08-10 01:54:35 ERROR NettyServerCodecThread_6 - decode exception,
producer-host-A:48252
com.alibaba.fastjson.JSONException: illegal identifier : <NUL> pos 444, line
1, column 445
{"code":10,"language":"GO","version":317,"opaque":268771467,"flag":0,"remark":"","extFields":{"defaultTopic":"TBW102","defaultTopicQueueNums":"4","bornTimestamp":"1786298075167","flag":"0","reconsumeTimes":"0","batch":"false","properties":"SHARDING_KEY\u0001<redacted>\u0002UNIQ_KEY\u0001AC11...e109\u0002","producerGroup":"producer-group-A","topic":"business-topic-base-info","queueId":"0","sysFlag":"0","unitMode":"false"<binary
frame prefix>{"code":11,"extFie
at
com.alibaba.fastjson.parser.JSONLexerBase.scanSymbolUnQuoted(JSONLexerBase.java:831)
at
com.alibaba.fastjson.parser.deserializer.MapDeserializer.parseMap(MapDeserializer.java:145)
at
com.alibaba.fastjson.parser.deserializer.JavaBeanDeserializer.deserialze(JavaBeanDeserializer.java:866)
at
com.alibaba.fastjson.parser.DefaultJSONParser.parseObject(DefaultJSONParser.java:688)
at com.alibaba.fastjson.JSON.parseObject(JSON.java:396)
at
org.apache.rocketmq.remoting.protocol.RemotingSerializable.fromJson(RemotingSerializable.java:46)
at
org.apache.rocketmq.remoting.protocol.RemotingCommand.headerDecode(RemotingCommand.java:190)
at
org.apache.rocketmq.remoting.protocol.RemotingCommand.decode(RemotingCommand.java:168)
at
org.apache.rocketmq.remoting.netty.NettyDecoder.decode(NettyDecoder.java:46)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.decode(LengthFieldBasedFrameDecoder.java:332)
at
io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:507)
at
io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:446)
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
at
io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:370)
at
io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:66)
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
at java.lang.Thread.run(Thread.java:745)
2026-08-10 01:54:35 INFO NettyServerNIOSelector_4_1 - closeChannel: close
the connection to remote address[producer-host-A:48252] result: true
```
## 5. Matching consumer request on another connection
The target body contains the request for aliased `consumer-topic-B`, queue
`0`, offset `692`, and `consumer-group-B`. The same request appears in a
decoder exception on a different remote connection during the same second:
```text
2026-08-10 01:54:35 ERROR NettyServerCodecThread_5 - decode exception,
consumer-host-B:40412
com.alibaba.fastjson.JSONException: illegal identifier : <NUL> pos 38, line
1, column 39
{"code":11,"extFields":{"queueId":"0",<binary frame
prefix>{"code":11,"extFields":{"queueId":"0","maxMsgNums":"32","sysFlag":"4","suspendTimeoutMillis":"20000","commitOffset":"0","topic":"consumer-topic-B","queueOffset":"692","subscription":"*","clientLogicIdc":"logic-idc-A","subVersion":"0","consumerGroup":"consumer-group-B"},"flag":0,
```
This provides a concrete correlation between bytes persisted in the target
business body and a malformed remoting stream observed on another TCP client
connection at the same timestamp.
--
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: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
