qsrg opened a new issue #3292:
URL: https://github.com/apache/rocketmq/issues/3292
jdk：1.8
rocketmq：4.3.2
when we open ssl, and broker's configuration of transferMsgByHeap is true，we
found consumer will consume normally at first，but throw exception after a
while。and search message timeout in rocketmq-console 。when we set
transferMsgByHeap=fasle，everything is ok。This seems a bug。
Some logs are as follows：
- consumer:
2021-03-12 11:50:00,001 INFO MQClientFactoryScheduledThread P2
RocketmqClient [PULL_RT] [xx@preProcessGroup] Stats In One Minute, SUM: 40166
TPS: 669.43 AVGPT: 8033.20
2021-03-12 11:50:00,001 INFO MQClientFactoryScheduledThread P2
RocketmqClient [PULL_RT] [xx@xx-GROUP] Stats In One Minute, SUM: 0 TPS: 0.00
AVGPT: 0.00
0:00,001 INFO MQClientFactoryScheduledThread P2 RocketmqClient [PULL_RT]
[XXX@xx-GROUP] Stats In One Minute, SUM: 0 TPS: 0.00 AVGPT: 0.00
2021-03-12 11:50:49,336 ERROR NettyClientWorkerThread_2 P2 RocketmqRemoting
decode exception, xxxx:10911
io.netty.handler.codec.TooLongFrameException: Adjusted frame length exceeds
16777216: 2654792721 - discarded
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.fail(LengthFieldBasedFrameDecoder.java:522)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.failIfNecessary(LengthFieldBasedFrameDecoder.java:500)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.exceededFrameLength(LengthFieldBasedFrameDecoder.java:387)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.decode(LengthFieldBasedFrameDecoder.java:430)
at
org.apache.rocketmq.remoting.netty.NettyDecoder.decode(NettyDecoder.java:43)
at
io.netty.handler.codec.LengthFieldBasedFrameDecoder.decode(LengthFieldBasedFrameDecoder.java:343)
at
io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:502)
at
io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:441)
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:278)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
at
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
at io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1432)
at
io.netty.handler.ssl.SslHandler.decodeJdkCompatible(SslHandler.java:1199)
at io.netty.handler.ssl.SslHandler.decode(SslHandler.java:1243)
at
io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:502)
at
io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:441)
at
io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:278)
at
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
at
io.netty.channel.AbstractChannelHandlerContext.access$600(AbstractChannelHandlerContext.java:38)
at
io.netty.channel.AbstractChannelHandlerContext$7.run(AbstractChannelHandlerContext.java:353)
at
io.netty.util.concurrent.DefaultEventExecutor.run(DefaultEventExecutor.java:66)
at
io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:897)
at java.lang.Thread.run(Thread.java:748)
2021-03-12 11:50:49,336 INFO NettyClientWorkerThread_2 P2 RocketmqRemoting
NETTY CLIENT PIPELINE: CLOSE xxxx:10911
2021-03-12 11:50:49,336 INFO NettyClientWorkerThread_2 P2 RocketmqRemoting
closeChannel: the channel[xxxx:10911] was removed from channel table
2021-03-12 11:50:49,336 INFO NettyClientWorkerThread_2 P2
RocketmqRemoting NETTY CLIENT PIPELINE: CLOSE xxxx:10911
2021-03-12 11:50:49,337 INFO NettyClientWorkerThread_2 P2 RocketmqRemoting
eventCloseChannel: the channel[null] has been removed from the channel table
before
- server:
2021-03-12 11:50:33 INFO brokerOutApi_thread_4 - register broker to name
server security.122:9876 OK
2021-03-12 11:50:33 INFO brokerOutApi_thread_3 - register broker to name
server security.120:9876 OK
2021-03-12 11:50:49 INFO NettyEventExecutor - NETTY EVENT: remove
channel[ClientChannelInfo [channel=[id: 0x5253444e, L:/security.39.13:10911 !
R:/10.
217.33.65:51290],
clientId=security.33.65@tp2-perf-mid-mqn0201:9876;tp2-perf-mid-mqn0202:9876;tp2-perf-mid-mqn0203:9876#security.33.65@30053,
language=J
AVA, version=277, lastUpdateTimestamp=1615521024340]][security.33.65:51290]
from ProducerManager groupChannelTable, producer group: CLIENT_INNER_PRODU
CER
2021-03-12 11:50:49 WARN NettyEventExecutor - NETTY EVENT: remove not active
channel[ClientChannelInfo [channel=[id: 0x5253444e, L:/security.39.13:109
11 ! R:/security.33.65:51290],
clientId=security.33.65@tp2-perf-mid-mqn0201:9876;tp2-perf-mid-mqn0202:9876;tp2-perf-mid-mqn0203:9876#security.33.65@30053,
language=JAVA, version=277, lastUpdateTimestamp=1615521024340]] from
ConsumerGroupInfo groupChannelTable, consumer group: ONLINE_PRE_PROCESS_MESSAG
E-GROUP
2021-03-12 11:50:49 INFO NettyEventExecutor - unregister consumer ok, no any
connection, and remove consumer group, security-GROUP
2021-03-12 11:50:49 WARN NettyEventExecutor - NETTY EVENT: remove not active
channel[ClientChannelInfo [channel=[id: 0x5253444e, L:/security.39.13:109
11 ! R:/security.33.65:51290],
clientId=security.33.65@tp2-perf-mid-mqn0201:9876;tp2-perf-mid-mqn0202:9876;tp2-perf-mid-mqn0203:9876#security.33.65@30053,
language=JAVA, version=277, lastUpdateTimestamp=1615521024340]] from
ConsumerGroupInfo groupChannelTable, consumer group: preProcessGroup
2021-03-12 11:50:49 INFO NettyEventExecutor - unregister consumer ok, no any
connection, and remove consumer group, preProcessGroup
2021-03-12 11:50:49 WARN PullMessageThread_22 - the consumer's group info
not exist, group: security-GROUP
2021-03-12 11:50:49 ERROR NettyServerNIOSelector_3_2 - processRequestWrapper
response to /security.33.65:51290 failed
java.nio.channels.ClosedChannelException: null
at io.netty.channel.AbstractChannel$AbstractUnsafe.write(...)(Unknown
Source) ~[netty-all-4.0.42.Final.jar:4.0.42.Final]
2021-03-12 11:50:49 ERROR NettyServerNIOSelector_3_2 - RemotingCommand
[code=11, language=JAVA, version=277, opaque=10111243, flag(B)=0, remark=null
, extFields={queueId=7, maxMsgNums=32, sysFlag=3,
suspendTimeoutMillis=15000, commitOffset=196, topic=security, queueOffset=196, e
xpressionType=TAG, subVersion=1615370273826, consumerGroup=security-GROUP},
serializeTypeCurrentRPC=JSON]
2021-03-12 11:50:49 ERROR NettyServerNIOSelector_3_2 - RemotingCommand
[code=24, language=JAVA, version=277, opaque=10111243, flag(B)=1, remark=the
consumer's group info not exist
See http://rocketmq.apache.org/docs/faq/ for further details.,
extFields=null, serializeTypeCurrentRPC=JSON]
2021-03-12 11:50:49 WARN PullMessageThread_121 - the consumer's group info
not exist, group: security-GROUP
2021-03-12 11:50:49 WARN PullMessageThread_65 - the consumer's group info
not exist, group: security-GROUP
2021-03-12 11:50:49 WARN PullMessageThread_121 - the consumer's group info
not exist, group: security-GROUP
2021-03-12 11:50:49 WARN PullMessageThread_121 - the consumer's group info
not exist, group: security-GROUP
2021-03-12 11:50:49 WARN PullMessageThread_65 - the consumer's group info
not exist, group: preProcessGroup
2021-03-12 11:50:49 WARN PullMessageThread_121 - the consumer's group info
not exist, group: preProcessGroup
2021-03-12 11:50:49 WARN PullMessageThread_58 - the consumer's group info
not exist, group: preProcessGroup
2021-03-12 11:50:49 WARN PullMessageThread_65 - the consumer's group info
not exist, group: preProcessGroup
2021-03-12 11:50:49 WARN PullMessageThread_10 - the consumer's group info
not exist, group: preProcessGroup
2021-03-12 11:50:49 ERROR NettyServerNIOSelector_3_2 - processRequestWrapper
response to /security.33.65:51290 failed
java.nio.channels.ClosedChannelException: null
at io.netty.channel.AbstractChannel$AbstractUnsafe.write(...)(Unknown
Source) ~[netty-all-4.0.42.Final.jar:4.0.42.Final]
2021-03-12 11:50:49 ERROR NettyServerNIOSelector_3_2 - RemotingCommand
[code=11, language=JAVA, version=277, opaque=10110408, flag(B)=0, remark=null
, extFields={queueId=10, maxMsgNums=32, sysFlag=3,
suspendTimeoutMillis=15000, commitOffset=197, topic=security, queueOffset=197,
expressionType=TAG, subVersion=1615370273826, consumerGroup=security-GROUP},
serializeTypeCurrentRPC=JSON]
---
From these logs，we can see the connection is closed abnormally
--
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]
