lwclover opened a new pull request #3120:
URL: https://github.com/apache/rocketmq/pull/3120
## What do I find?
In production practice，There is a situation that is starting many diffent
consumers and using web controls consumers restarting and stoping at the same
time in one running process.
then I noticed a problem one day after stoping and starting consumers
using web，There was a consumer who reconsume messages a few days ago.
## What is the purpose of the change?
fix issue below:
producing a ghost consumer at frequently start and stop consumers in the
same process，who can not consume message，but can pull messages and submit the
same consume offset.
## Clues below
find offset reset in **host1** rocketmq_client.log:
```
2021-06-08 14:19:23,023 INFO RocketmqClient - [persistAll] Group:
topic-xxx-consumer ClientId: host1@29158 updateConsumeOffsetToBroker
MessageQueue [topic=topic-xxx brokerName=broker-a, queueId=5] 2678704
2021-06-08 14:19:23,023 INFO RocketmqClient - the consumer
[topic-xxx-consumer] shutdown OK
2021-06-08 14:19:24,024 INFO RocketmqClient - the consumer
[topic-xxx-consumer] start beginning. messageModel=CLUSTERING, isUnitMode=false
2021-06-08 14:19:24,024 INFO RocketmqClient - the consumer
[topic-xxx-consumer] start OK.
2021-06-08 14:19:24,024 INFO RocketmqClient - doRebalance,
topic-xxx-consumer, add a new pull request PullRequest
[consumerGroup=topic-xxx-consumer, messageQueue=MessageQueue [topic=topic-xxx
brokerName=broker-a, queueId=5], nextOffset=2611518]
```
find ghost consumer submit consume offset from **host2**:
```
2021-06-04 00:00:00 WARN PullMessageThread_55 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613665
2021-06-04 00:00:00 WARN PullMessageThread_87 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613666
2021-06-04 00:00:00 WARN PullMessageThread_107 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613667
2021-06-04 00:00:01 WARN PullMessageThread_71 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613668
2021-06-04 00:00:01 WARN PullMessageThread_17 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613669
2021-06-04 00:00:01 WARN PullMessageThread_13 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613670
2021-06-04 00:00:02 WARN PullMessageThread_93 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613671
2021-06-04 00:00:02 WARN PullMessageThread_121 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2613672
..........................................................................................................................................................................................................................
2021-06-07 18:49:45 WARN PullMessageThread_18 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2670228
2021-06-07 18:49:46 WARN PullMessageThread_79 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2670229
2021-06-07 18:49:47 WARN PullMessageThread_61 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2670230
2021-06-07 18:49:50 WARN PullMessageThread_43 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2670231
2021-06-07 18:49:51 WARN PullMessageThread_14 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2670232
2021-06-07 18:49:52 WARN PullMessageThread_67 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2670233
2021-06-07 18:49:56 WARN PullMessageThread_67 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2670234
..........................................................................................................................................................................................................................
2021-06-08 14:20:00 WARN PullMessageThread_123 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2636343
2021-06-08 14:20:00 WARN PullMessageThread_29 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2636385
2021-06-08 14:20:00 WARN PullMessageThread_90 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2636621
2021-06-08 14:20:03 WARN PullMessageThread_60 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2637975
2021-06-08 14:20:03 WARN PullMessageThread_114 - [NOTIFYME]update consumer
offset less than store. clientHost=host2:35394,
key=topic-xxx@topic-xxx-consumer, queueId=5, requestOffset=2611518,
storeOffset=2638184
```
finally **host2** triggers flow control:
```
2021-06-03 23:47:18,018 WARN RocketmqClient - the queue's messages, span too
long, so do flow control, minOffset=2611615, maxOffset=2613616, maxSpan=2001,
pullRequest=PullRequest [consumerGroup=topic-xxx-consumer,
messageQueue=MessageQueue [topic=topic-xxx, brokerName=broker-a, queueId=15],
nextOffset=2613617], flowControlTimes=1
2021-06-04 00:16:42,042 WARN RocketmqClient - the queue's messages, span too
long, so do flow control, minOffset=2611518, maxOffset=2613736, maxSpan=2218,
pullRequest=PullRequest [consumerGroup=topic-xxx-consumer,
messageQueue=MessageQueue [topic=topic-xxx, brokerName=broker-a, queueId=5],
nextOffset=2613737], flowControlTimes=7001
2021-06-05 11:11:12,012 WARN RocketmqClient - the queue's messages, span too
long, so do flow control, minOffset=2611518, maxOffset=2632183, maxSpan=20665,
pullRequest=PullRequest [consumerGroup=topic-xxx-consumer,
messageQueue=MessageQueue [topic=topic-xxx, brokerName=broker-a, queueId=5],
nextOffset=2632184], flowControlTimes=534001
..........................................................................................................................................................................................................................................
2021-06-08 19:33:51,051 WARN RocketmqClient - the queue's messages, span too
long, so do flow control, minOffset=2611518, maxOffset=2678767, maxSpan=67249,
pullRequest=PullRequest [consumerGroup=topic-xxx-consumer,
messageQueue=MessageQueue [topic=topic-xxx, brokerName=broker-a, queueId=5],
nextOffset=2678768], flowControlTimes=1131001
```
**We can find host1 consuming broker-a queueId=5, but at the same time host2
is submit the same offset 2611518.
producing a ghost consumer at frequently start and stop consumers in the
same process，who can not consume message，but can pull messages and submit the
same consume offset.**
## root cause
**The root cause is that class MQClientInstance`s registerConsumer and
unregisterConsumer is not atomic operation.**
--
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]
