search

apache / rocketmq

Apache RocketMQ is a cloud native messaging and streaming platform, making it simple to build event-driven applications.
https://rocketmq.apache.org/
Apache License 2.0
21.19k stars 11.67k forks source link

the consumer's group info not exist #5479

Closed chenchenfang closed 11 months ago

chenchenfang commented 1 year ago

BUG REPORT

  1. Please describe the issue you observed:

I found that consumers are delayed,then i see the dashboard can not show

image

When I refresh it a few times image

this is the log when consumer group start

broker.log


2022-11-08 13:53:42 INFO HeartbeatThread_2 - new producer connected, group: CLIENT_INNER_PRODUCER channel: ClientChannelInfo [channel=[id: 0xd2e5d255, L:/192.168.1.58:10911 - R:/192.168.1.215:38164], clientId=${clientIP}@33318#1116941996974051, language=JAVA, version=401, lastUpdateTimestamp=1667886822920]
2022-11-08 13:53:42 INFO HeartbeatThread_2 - new producer connected, group: real_db_producer_group channel: ClientChannelInfo [channel=[id: 0xd2e5d255, L:/192.168.1.58:10911 - R:/192.168.1.215:38164], clientId=${clientIP}@33318#1116941996974051, language=JAVA, version=401, lastUpdateTimestamp=1667886822920]
2022-11-08 13:53:43 INFO NettyEventExecutor - NETTY EVENT: remove channel[ClientChannelInfo [channel=[id: 0xd2e5d255, L:/192.168.1.58:10911 ! R:/192.168.1.215:38164], clientId=${clientIP}@33318#1116941996974051, language=JAVA, version=401, lastUpdateTimestamp=1667886822920]][192.168.1.215:38164] from ProducerManager groupChannelTable, producer group: real_db_producer_group
2022-11-08 13:53:43 INFO NettyEventExecutor - NETTY EVENT: remove channel[ClientChannelInfo [channel=[id: 0xd2e5d255, L:/192.168.1.58:10911 ! R:/192.168.1.215:38164], clientId=${clientIP}@33318#1116941996974051, language=JAVA, version=401, lastUpdateTimestamp=1667886822920]][192.168.1.215:38164] from ProducerManager groupChannelTable, producer group: CLIENT_INNER_PRODUCER
2022-11-08 13:53:53 INFO BrokerControllerScheduledThread1 - dispatch behind commit log 0 bytes
2022-11-08 13:53:53 INFO BrokerControllerScheduledThread1 - Slave fall behind master: -7956002611915232475 bytes
2022-11-08 13:53:53 INFO brokerOutApi_thread_1 - register broker[0]to name server 192.168.1.58:9876 OK
2022-11-08 13:53:53 INFO brokerOutApi_thread_3 - register broker[0]to name server 192.168.1.150:9876 OK
2022-11-08 13:53:53 INFO brokerOutApi_thread_4 - register broker[0]to name server 192.168.1.52:9876 OK
2022-11-08 13:54:00 WARN ConsumerManageThread_20 - getConsumerGroupInfo failed, real_db_consumer_group-dsp_error 192.168.1.61:56208
2022-11-08 13:54:00 INFO HeartbeatThread_2 - new consumer connected, group: real_db_consumer_group-dsp_error CONSUME_PASSIVELY CLUSTERING channel: ClientChannelInfo [channel=[id: 0xfeb744d6, L:/192.168.1.58:10911 - R:/192.168.1.61:56208], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886840523]
2022-11-08 13:54:00 INFO HeartbeatThread_2 - subscription changed, add new topic, group: real_db_consumer_group-dsp_error SubscriptionData [classFilterMode=false, topic=real_bigdata_topic, subString=dsp_error, tagsSet=[dsp_error], codeSet=[1635624458], subVersion=1667886839748, expressionType=TAG]
2022-11-08 13:54:00 INFO HeartbeatThread_2 - subscription changed, add new topic, group: real_db_consumer_group-dsp_error SubscriptionData [classFilterMode=false, topic=%RETRY%real_db_consumer_group-dsp_error, subString=*, tagsSet=[], codeSet=[], subVersion=1667886839778, expressionType=TAG]
2022-11-08 13:54:00 INFO HeartbeatThread_2 - registerConsumer info changed ConsumerData [groupName=real_db_consumer_group-dsp_error, consumeType=CONSUME_PASSIVELY, messageModel=CLUSTERING, consumeFromWhere=CONSUME_FROM_LAST_OFFSET, unitMode=false, subscriptionDataSet=[SubscriptionData [classFilterMode=false, topic=real_bigdata_topic, subString=dsp_error, tagsSet=[dsp_error], codeSet=[1635624458], subVersion=1667886839748, expressionType=TAG], SubscriptionData [classFilterMode=false, topic=%RETRY%real_db_consumer_group-dsp_error, subString=*, tagsSet=[], codeSet=[], subVersion=1667886839778, expressionType=TAG]]] 192.168.1.61:56208
2022-11-08 13:54:00 INFO HeartbeatThread_2 - new producer connected, group: CLIENT_INNER_PRODUCER channel: ClientChannelInfo [channel=[id: 0xfeb744d6, L:/192.168.1.58:10911 - R:/192.168.1.61:56208], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886840523]
2022-11-08 13:54:00 WARN PullMessageThread_70 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error *
2022-11-08 13:54:00 INFO HeartbeatThread_4 - subscription changed, group: real_db_consumer_group-dsp_error OLD: SubscriptionData [classFilterMode=false, topic=%RETRY%real_db_consumer_group-dsp_error, subString=*, tagsSet=[], codeSet=[], subVersion=1667886839778, expressionType=TAG] NEW: SubscriptionData [classFilterMode=false, topic=%RETRY%real_db_consumer_group-dsp_error, subString=*, tagsSet=[], codeSet=[], subVersion=1667886840536, expressionType=TAG]
2022-11-08 13:54:00 WARN PullMessageThread_85 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_55 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_55 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_2 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_20 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_33 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_29 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_29 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_19 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_88 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_47 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_120 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_120 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 WARN PullMessageThread_50 - The broker's subscription is not latest, group: real_db_consumer_group-dsp_error dsp_error
2022-11-08 13:54:00 INFO HeartbeatThread_6 - subscription changed, group: real_db_consumer_group-dsp_error OLD: SubscriptionData [classFilterMode=false, topic=real_bigdata_topic, subString=dsp_error, tagsSet=[dsp_error], codeSet=[1635624458], subVersion=1667886839748, expressionType=TAG] NEW: SubscriptionData [classFilterMode=false, topic=real_bigdata_topic, subString=dsp_error, tagsSet=[dsp_error], codeSet=[1635624458], subVersion=1667886840681, expressionType=TAG]
2022-11-08 13:54:00 INFO NettyEventExecutor - NETTY EVENT: remove channel[ClientChannelInfo [channel=[id: 0xfeb744d6, L:/192.168.1.58:10911 ! R:/192.168.1.61:56208], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886840725]][192.168.1.61:56208] from ProducerManager groupChannelTable, producer group: CLIENT_INNER_PRODUCER
2022-11-08 13:54:00 WARN NettyEventExecutor - NETTY EVENT: remove not active channel[ClientChannelInfo [channel=[id: 0xfeb744d6, L:/192.168.1.58:10911 ! R:/192.168.1.61:56208], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886840725]] from ConsumerGroupInfo groupChannelTable, consumer group: real_db_consumer_group-dsp_error
2022-11-08 13:54:00 INFO NettyEventExecutor - unregister consumer ok, no any connection, and remove consumer group, real_db_consumer_group-dsp_error
2022-11-08 13:54:01 INFO HeartbeatThread_8 - new consumer connected, group: real_db_consumer_group-dsp_error CONSUME_PASSIVELY CLUSTERING channel: ClientChannelInfo [channel=[id: 0x05216940, L:/192.168.1.58:10911 - R:/192.168.1.61:56222], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886841062]
2022-11-08 13:54:01 INFO HeartbeatThread_8 - subscription changed, add new topic, group: real_db_consumer_group-dsp_error SubscriptionData [classFilterMode=false, topic=real_bigdata_topic, subString=dsp_error, tagsSet=[dsp_error], codeSet=[1635624458], subVersion=1667886840681, expressionType=TAG]
2022-11-08 13:54:01 INFO HeartbeatThread_8 - subscription changed, add new topic, group: real_db_consumer_group-dsp_error SubscriptionData [classFilterMode=false, topic=%RETRY%real_db_consumer_group-dsp_error, subString=*, tagsSet=[], codeSet=[], subVersion=1667886840536, expressionType=TAG]
2022-11-08 13:54:01 INFO HeartbeatThread_8 - registerConsumer info changed ConsumerData [groupName=real_db_consumer_group-dsp_error, consumeType=CONSUME_PASSIVELY, messageModel=CLUSTERING, consumeFromWhere=CONSUME_FROM_LAST_OFFSET, unitMode=false, subscriptionDataSet=[SubscriptionData [classFilterMode=false, topic=real_bigdata_topic, subString=dsp_error, tagsSet=[dsp_error], codeSet=[1635624458], subVersion=1667886840681, expressionType=TAG], SubscriptionData [classFilterMode=false, topic=%RETRY%real_db_consumer_group-dsp_error, subString=*, tagsSet=[], codeSet=[], subVersion=1667886840536, expressionType=TAG]]] 192.168.1.61:56222
2022-11-08 13:54:01 INFO HeartbeatThread_8 - new producer connected, group: CLIENT_INNER_PRODUCER channel: ClientChannelInfo [channel=[id: 0x05216940, L:/192.168.1.58:10911 - R:/192.168.1.61:56222], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886841062]
2022-11-08 13:54:01 INFO NettyEventExecutor - NETTY EVENT: remove channel[ClientChannelInfo [channel=[id: 0x05216940, L:/192.168.1.58:10911 ! R:/192.168.1.61:56222], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886841062]][192.168.1.61:56222] from ProducerManager groupChannelTable, producer group: CLIENT_INNER_PRODUCER
2022-11-08 13:54:01 WARN NettyEventExecutor - NETTY EVENT: remove not active channel[ClientChannelInfo [channel=[id: 0x05216940, L:/192.168.1.58:10911 ! R:/192.168.1.61:56222], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886841062]] from ConsumerGroupInfo groupChannelTable, consumer group: real_db_consumer_group-dsp_error
2022-11-08 13:54:01 INFO NettyEventExecutor - unregister consumer ok, no any connection, and remove consumer group, real_db_consumer_group-dsp_error
2022-11-08 13:54:01 WARN PullMessageThread_14 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:01 WARN PullMessageThread_97 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_64 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_122 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_84 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_11 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_110 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_57 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_57 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_116 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_116 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_68 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_48 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_48 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_43 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_52 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_52 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_55 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:02 WARN PullMessageThread_55 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_84 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_83 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_11 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_122 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_110 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_57 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_115 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_116 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_101 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_48 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_68 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_103 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_43 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_52 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_85 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_55 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error
2022-11-08 13:54:03 WARN PullMessageThread_33 - the consumer's group info not exist, group: real_db_consumer_group-dsp_error

I don't know what caused the problem,so i stop the consumer group and used ./bin/mqadmin resetOffsetByTime -n "192.168.1.58:9876;192.168.1.52:9876;192.168.1.150:9876" -g real_db_consumer_group-dsp_error -t real_bigdata_topic -s now the command, then i started the consumer group everything is ok.and after one night, The question comes up again. Is it there are too many consumer groups corresponding to one topic?

i have three broker master but only broker-a has delay image

  1. Please tell us about your environment: rocketMQ version : V4_9_4 java version "1.8.0_191" this topic is NORMAL topic this topic has 78 consumer groups and this topic has 16 queue on one broker (There are three broker)
wegod commented 1 year ago

I think you have the same issue I had before.

If you have several projects use same consumer group, check all your consumer project code whether there is a consumer don't call subscribe method.

All consumer in same consumer group must call subscribe method to bind the same consumer group subscription. If a consumer only call start method, then it will clean consumer group subscription.

This is because of https://rocketmq.apache.org/zh/docs/4.x/bestPractice/21subscribe

And I think this clean design is very strange which cost several hours to fix the deep bug.

chenchenfang commented 1 year ago

I think you have the same issue I had before.

If you have several projects use same consumer group, check all your consumer project code whether there is a consumer don't call subscribe method.

All consumer in same consumer group must call subscribe method to bind the same consumer group subscription. If a consumer only call start method, then it will clean consumer group subscription.

This is because of https://rocketmq.apache.org/zh/docs/4.x/bestPractice/21subscribe

And I think this clean design is very strange which cost several hours to fix the deep bug.

thinks,but my consumer group only has one consumer,i just has many consumer groups,and one consumer group has one consumer

wegod commented 1 year ago

I think you have the same issue I had before. If you have several projects use same consumer group, check all your consumer project code whether there is a consumer don't call subscribe method. All consumer in same consumer group must call subscribe method to bind the same consumer group subscription. If a consumer only call start method, then it will clean consumer group subscription. This is because of https://rocketmq.apache.org/zh/docs/4.x/bestPractice/21subscribe And I think this clean design is very strange which cost several hours to fix the deep bug.

thinks,but my consumer group only has one consumer,i just has many consumer groups,and one consumer group has one consumer

2022-11-08 13:54:01 INFO NettyEventExecutor - unregister consumer ok, no any connection, and remove consumer group, real_db_consumer_group-dsp_error

consumer group was deleted by this log, I check the source code of method doChannelCloseEvent in ConsumerManager.java and found when consumer group has no consumer, then when the last consumer's Channel close, the consumer group will be deleted.

But I can't find why your consumer Channel is closed, you can check by yourself or submit more relation log.

Say something else, in your use case, maybe you can set MessageModel to BROADCASTING and use one consumer group. It's the same all machine will consume all the message.

chenchenfang commented 1 year ago

I'm just starting the consumer group ,i do not know why it's not active channel,and then broker.log start WARN .......

wegod commented 1 year ago

2022-11-08 13:54:01 INFO HeartbeatThread_8 - new consumer connected, group: real_db_consumer_group-dsp_error CONSUME_PASSIVELY CLUSTERING channel: ClientChannelInfo [channel=[id: 0x05216940, L:/192.168.1.58:10911 - R:/192.168.1.61:56222], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886841062]

2022-11-08 13:54:01 INFO HeartbeatThread_8 - new consumer connected, group: real_db_consumer_group-dsp_error CONSUME_PASSIVELY CLUSTERING channel: ClientChannelInfo [channel=[id: 0x05216940, L:/192.168.1.58:10911 - R:/192.168.1.61:56222], clientId=${clientIP}@26917#5261547777682927, language=JAVA, version=401, lastUpdateTimestamp=1667886841062]

It's the consumer channel closed, you'd better to download the source code to find why, or to check other log or business code.

chenchenfang commented 1 year ago

OK, I'll have a try.

github-actions[bot] commented 11 months ago

This issue is stale because it has been open for 365 days with no activity. It will be closed in 3 days if no further activity occurs.

github-actions[bot] commented 11 months ago

This issue was closed because it has been inactive for 3 days since being marked as stale.