[fix] [broker] Close dispatchers stuck due to mismatch between dispatcher.consumerList and dispatcher.consumerSet by poorbarcode · Pull Request #22270 · apache/pulsar

poorbarcode · 2024-03-14T17:50:35Z

Motivation

2024-03-13T07:47:36,071+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://{tenat}/{ns}/{topic name}] Global topic inactive for 86400 seconds, closed repl producers
2024-03-13T07:47:36,073+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.Consumer - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=5, consumerName=082c9, address=/127.0.0.6:34293}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.Consumer - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=10, consumerName=f0c65, address=/127.0.0.6:32911}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers - Removed consumer Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=5, consumerName=7f82f, address=/127.0.0.6:39763} with pending 0 acks
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers - [persistent://{tenat}/{ns}/{topic name} / {subscription}] Trying to remove a non-connected consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=10, consumerName=f0c65, address=/127.0.0.6:32911}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.Consumer - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=5, consumerName=7f82f, address=/127.0.0.6:39763}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers - Removed consumer Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=18, consumerName=1aebe, address=/127.0.0.6:33045} with pending 0 acks
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.Consumer - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=18, consumerName=b44be, address=/127.0.0.6:44907}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers - [persistent://{tenat}/{ns}/{topic name} / {subscription}] Trying to remove a non-connected consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=5, consumerName=082c9, address=/127.0.0.6:34293}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.Consumer - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=10, consumerName=a2fc6, address=/127.0.0.6:54177}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers - [persistent://{tenat}/{ns}/{topic name} / {subscription}] Trying to remove a non-connected consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=18, consumerName=b44be, address=/127.0.0.6:44907}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.Consumer - Disconnecting consumer: Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=18, consumerName=1aebe, address=/127.0.0.6:33045}
2024-03-13T07:47:36,074+0000 [pulsar-inactivity-monitor-25-1] INFO  org.apache.pulsar.broker.service.persistent.PersistentDispatcherMultipleConsumers - Removed consumer Consumer{subscription=PersistentSubscription{topic=persistent://{tenat}/{ns}/{topic name}, name={subscription}}, consumerId=10, consumerName=a2fc6, address=/127.0.0.6:54177} with pending 0 acks
2024-03-13T07:47:36,186+0000 [pulsar-io-4-22] WARN  org.apache.pulsar.broker.service.persistent.PersistentTopic - [persistent://{tenat}/{ns}/{topic name}] Attempting to subscribe to a fenced topic

The logs were printed on our cluster(2.11.2)

The consumer {clientCnx 127.0.0.6:44907, consumerId: 18} has been removed twice when calling dispatcher.disconnectAllConsumers.^[1]
Pulsar printed Trying to remove a non-connected consumer when removing the consumer {clientCnx 127.0.0.6:44907, consumerId: 18} at the second time, which means this consumer is duplicated in dispatcher.consumerList.^[2]
Once the log "Trying to remove a non-connected consumer" is printed, the closeFuture of dispatcher will never be completed, leading to the process of topic.delete being stuck.
The topic stays in a fenced state.

[1]: dispatcher.disconnectAllConsumers

public synchronized CompletableFuture<Void> disconnectAllConsumers() {
  consumerList.forEach(consumer -> consumer.disconnect(isResetCursor, assignedBrokerLookupData));
}

[2]: dispatcher.removeConsumer

public synchronized void removeConsumer(Consumer consumer) throws BrokerServiceException {
    // decrement unack-message count for removed consumer
    addUnAckedMessages(-consumer.getUnackedMessages());
    if (consumerSet.removeAll(consumer) == 1) {
        consumerList.remove(consumer);
        log.info("Removed consumer {} with pending {} acks", consumer, consumer.getPendingAcks().size());
        if (consumerList.isEmpty()) {
            if (closeFuture != null) {
                closeFuture.complete(null); // Once the log "Trying to remove a non-connected consumer" was printed, it means the closeFuture will never be completed.
            }
        } 
    } else {
        log.info("[{}] Trying to remove a non-connected consumer: {}", name, consumer);
    }
}

Modifications

I haven't found the logic of repeating consumer in dispatcher.consumerList yet(it may caused by a consumer that has been added twice, and dispatcher.consumerSet merged two adding), I just fixed the follow-up issue.

Documentation

doc
doc-required
doc-not-needed
doc-complete

Matching PR in forked repository

PR in forked repository: x

…consumerList and dispatcher.consumerSet

hanmz

LGTM

.../java/org/apache/pulsar/broker/service/persistent/PersistentDispatcherMultipleConsumers.java

lhotari

LGTM

codecov-commenter · 2024-03-19T04:59:18Z

Codecov Report

❌ Patch coverage is 92.30769% with 1 line in your changes missing coverage. Please review.
✅ Project coverage is 73.68%. Comparing base (bbc6224) to head (4882977).
⚠️ Report is 1247 commits behind head on master.

Files with missing lines	Patch %	Lines
...sistent/PersistentDispatcherMultipleConsumers.java	92.30%	0 Missing and 1 partial ⚠️

Additional details and impacted files

@@             Coverage Diff              @@
##             master   #22270      +/-   ##
============================================
+ Coverage     73.57%   73.68%   +0.10%     
- Complexity    32624    32802     +178     
============================================
  Files          1877     1887      +10     
  Lines        139502   139488      -14     
  Branches      15299    15293       -6     
============================================
+ Hits         102638   102778     +140     
+ Misses        28908    28750     -158     
- Partials       7956     7960       +4

Flag	Coverage Δ
inttests	`26.58% <46.15%> (+2.00%)`	⬆️
systests	`24.54% <46.15%> (+0.22%)`	⬆️
unittests	`72.95% <92.30%> (+0.11%)`	⬆️

Flags with carried forward coverage won't be shown. Click here to find out more.

Files with missing lines	Coverage Δ
...sistent/PersistentDispatcherMultipleConsumers.java	`74.52% <92.30%> (+0.20%)`	⬆️

... and 103 files with indirect coverage changes

🚀 New features to boost your workflow:

❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

codelipenghui

It looks like we don't need this PR if we follow this comment to fix the issue. I have tested on my laptop.

poorbarcode · 2024-03-21T14:14:32Z

It looks like we don't need this PR if we follow this #22283 (review) to fix the issue. I have tested on my laptop.

Changed the implementation: Just add a defensive code to avoid the topic not being unloaded anymore: remove the consumers which are not mismatched between consumerSet and consumerList, and print an error log

poorbarcode · 2024-03-22T06:27:27Z

/pulsarbot rerun-failure-checks

…cher.consumerList and dispatcher.consumerSet (#22270) (cherry picked from commit cba1600)

…cher.consumerList and dispatcher.consumerSet (apache#22270) (cherry picked from commit cba1600) (cherry picked from commit 94edfe4)

…cher.consumerList and dispatcher.consumerSet (apache#22270) (cherry picked from commit cba1600)

…cher.consumerList and dispatcher.consumerSet (apache#22270)

[fix] [broker] Delete topic stuck due to mismatch between dispatcher.…

550c42c

…consumerList and dispatcher.consumerSet

poorbarcode added type/bug The PR fixed a bug or issue reported a bug release/3.0.4 release/3.2.2 release/2.11.5 labels Mar 14, 2024

poorbarcode added this to the 3.3.0 milestone Mar 14, 2024

poorbarcode self-assigned this Mar 14, 2024

github-actions bot added the doc-not-needed Your PR changes do not impact docs label Mar 14, 2024

poorbarcode changed the title ~~[fix] [broker] Delete topic stuck due to mismatch between dispatcher.consumerList and dispatcher.consumerSet~~ [fix] [broker] Close dispatchers stuck due to mismatch between dispatcher.consumerList and dispatcher.consumerSet Mar 15, 2024

poorbarcode mentioned this pull request Mar 16, 2024

[fix] [broker] fix mismatch between dispatcher.consumerList and dispatcher.consumerSet #22283

Merged

4 tasks

poorbarcode added 2 commits March 16, 2024 10:05

add a test

c59501b

add a test

2f67d1b

hanmz approved these changes Mar 18, 2024

View reviewed changes

lhotari reviewed Mar 18, 2024

View reviewed changes

.../java/org/apache/pulsar/broker/service/persistent/PersistentDispatcherMultipleConsumers.java Show resolved Hide resolved

poorbarcode requested a review from lhotari March 18, 2024 15:47

lhotari approved these changes Mar 18, 2024

View reviewed changes

add another test

b709898

poorbarcode mentioned this pull request Mar 19, 2024

[fix][broker] Fix one potential to add duplicated consumer #20583

Closed

5 tasks

codelipenghui requested changes Mar 21, 2024

View reviewed changes

address comment

4882977

poorbarcode requested a review from codelipenghui March 21, 2024 14:14

codelipenghui approved these changes Mar 22, 2024

View reviewed changes

poorbarcode added the ready-to-test label Mar 22, 2024

poorbarcode merged commit cba1600 into apache:master Mar 23, 2024

poorbarcode added a commit that referenced this pull request Mar 26, 2024

[fix] [broker] Close dispatchers stuck due to mismatch between dispat…

c8ee206

…cher.consumerList and dispatcher.consumerSet (#22270) (cherry picked from commit cba1600)

poorbarcode added the cherry-picked/branch-2.11 label Mar 26, 2024

poorbarcode added a commit that referenced this pull request Mar 26, 2024

[fix] [broker] Close dispatchers stuck due to mismatch between dispat…

94edfe4

…cher.consumerList and dispatcher.consumerSet (#22270) (cherry picked from commit cba1600)

poorbarcode added the cherry-picked/branch-3.0 label Mar 26, 2024

poorbarcode added a commit that referenced this pull request Mar 26, 2024

[fix] [broker] Close dispatchers stuck due to mismatch between dispat…

ab88cee

…cher.consumerList and dispatcher.consumerSet (#22270) (cherry picked from commit cba1600)

poorbarcode added the release/3.2.3 label Mar 26, 2024

poorbarcode added a commit that referenced this pull request Mar 26, 2024

[fix] [broker] Close dispatchers stuck due to mismatch between dispat…

310102f

…cher.consumerList and dispatcher.consumerSet (#22270) (cherry picked from commit cba1600)

poorbarcode added cherry-picked/branch-3.2 cherry-picked/branch-2.10 release/2.10.7 and removed release/3.2.2 labels Mar 26, 2024

lhotari added release/3.2.2 and removed release/3.2.3 labels Mar 27, 2024

nodece pushed a commit to ascentstream/pulsar that referenced this pull request May 13, 2024

[fix] [broker] Close dispatchers stuck due to mismatch between dispat…

2595ff2

…cher.consumerList and dispatcher.consumerSet (apache#22270) (cherry picked from commit cba1600)

hanmz pushed a commit to hanmz/pulsar that referenced this pull request Feb 12, 2025

[fix] [broker] Close dispatchers stuck due to mismatch between dispat…

dd4b2d7

…cher.consumerList and dispatcher.consumerSet (apache#22270)

TakaHiR07 mentioned this pull request Dec 17, 2025

[fix][broker] fix delayedMessagesCount error in InMemoryDelayedDeliveryTracker #25076

Open

5 tasks

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[fix] [broker] Close dispatchers stuck due to mismatch between dispatcher.consumerList and dispatcher.consumerSet#22270

[fix] [broker] Close dispatchers stuck due to mismatch between dispatcher.consumerList and dispatcher.consumerSet#22270
poorbarcode merged 5 commits intoapache:masterfrom
poorbarcode:fix/dispatcher_close_stuck

poorbarcode commented Mar 14, 2024

Uh oh!

hanmz left a comment

Uh oh!

Uh oh!

lhotari left a comment

Uh oh!

codecov-commenter commented Mar 19, 2024 •

edited

Loading

Uh oh!

codelipenghui left a comment

Uh oh!

poorbarcode commented Mar 21, 2024

Uh oh!

poorbarcode commented Mar 22, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

Conversation

poorbarcode commented Mar 14, 2024

Motivation

Modifications

Documentation

Matching PR in forked repository

Uh oh!

hanmz left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

lhotari left a comment

Choose a reason for hiding this comment

Uh oh!

codecov-commenter commented Mar 19, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Codecov Report

Uh oh!

codelipenghui left a comment

Choose a reason for hiding this comment

Uh oh!

poorbarcode commented Mar 21, 2024

Uh oh!

poorbarcode commented Mar 22, 2024

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

codecov-commenter commented Mar 19, 2024 •

edited

Loading