[Broker] Fix and improve topic ownership assignment by lhotari · Pull Request #13069 · apache/pulsar

lhotari · 2021-12-01T13:49:03Z

Motivation

This PR depends on #13066 .

When a lookup is made to a topic that isn't currently loaded, the decision will be made in a distributed fashion on the follower brokers since the information about the leader broker is missing (because LeaderElectionService.getCurrentLeader() always returned Optional.empty()). This leads to races when assigning the topic ownership to a broker, since the decision isn't made centrally on the leader broker.

This PR adds a test to verify the behavior and also uses a cached way to get available brokers.

Modifications

builds upon changes from [Broker] Fix LeaderElectionService.getCurrentLeader and add support for empheralOwner in MockZooKeeper #13066
add failing test case MultiBrokerLeaderElectionTest.shouldProvideConsistentAnswerToTopicLookup
adds more logging to topic ownership assignment decision made in NamespaceService.searchForCandidateBroker
optimizes performance of the topic ownership assignment by using LoadManager.getAvailableBrokers instead of reading the list every time from Zookeeper

Additional context

PR to backport this fix to branch-2.8 is #13117 . Pulsar 2.8.1 contains another topic ownership bug which is fixed by #12650 .

michaeljmarshall

LGTM

eolivelli

LGTM

lhotari · 2021-12-03T08:25:34Z

I fixed the test in https://github.com/lhotari/pulsar/commits/lh-fix-topic-ownership-assignment-branch-2.8 . I can now consistently reproduce the issue. It results in error 500 :

10:22:44.069 [metadata-store-150-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-220-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-80-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-45-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-325-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-185-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-255-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-290-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.069 [metadata-store-115-1] INFO  org.apache.pulsar.common.naming.NamespaceBundleFactory - Policy updated for namespace public/default, refreshing the bundle cache.
10:22:44.070 [metadata-store-255-1] WARN  org.apache.pulsar.broker.lookup.TopicLookupBase - Failed to lookup broker for topic persistent://public/default/lookuptest0e133752-6e62-415f-994b-ef5d9ad57730-0: org.apache.pulsar.metadata.api.MetadataStoreException$BadVersionException: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
java.util.concurrent.CompletionException: org.apache.pulsar.metadata.api.MetadataStoreException$BadVersionException: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632) ~[?:?]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) ~[?:?]
	at org.apache.pulsar.metadata.impl.ZKMetadataStore.lambda$storePut$15(ZKMetadataStore.java:226) ~[pulsar-metadata-2.8.2.jar:2.8.2]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.68.Final.jar:4.1.68.Final]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: org.apache.pulsar.metadata.api.MetadataStoreException$BadVersionException: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
	at org.apache.pulsar.metadata.impl.ZKMetadataStore.getException(ZKMetadataStore.java:308) ~[pulsar-metadata-2.8.2.jar:2.8.2]
	... 5 more
Caused by: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:122) ~[zookeeper-3.6.3.jar:3.6.3]
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.6.3.jar:3.6.3]
	at org.apache.pulsar.metadata.impl.ZKMetadataStore.getException(ZKMetadataStore.java:304) ~[pulsar-metadata-2.8.2.jar:2.8.2]
	... 5 more
10:22:44.070 [metadata-store-185-1] WARN  org.apache.pulsar.broker.lookup.TopicLookupBase - Failed to lookup broker for topic persistent://public/default/lookuptest0e133752-6e62-415f-994b-ef5d9ad57730-0: org.apache.pulsar.metadata.api.MetadataStoreException$BadVersionException: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
java.util.concurrent.CompletionException: org.apache.pulsar.metadata.api.MetadataStoreException$BadVersionException: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:346) ~[?:?]
	at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:632) ~[?:?]
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:2088) ~[?:?]
	at org.apache.pulsar.metadata.impl.ZKMetadataStore.lambda$storePut$15(ZKMetadataStore.java:226) ~[pulsar-metadata-2.8.2.jar:2.8.2]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [netty-common-4.1.68.Final.jar:4.1.68.Final]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: org.apache.pulsar.metadata.api.MetadataStoreException$BadVersionException: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
	at org.apache.pulsar.metadata.impl.ZKMetadataStore.getException(ZKMetadataStore.java:308) ~[pulsar-metadata-2.8.2.jar:2.8.2]
	... 5 more
Caused by: org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /admin/local-policies/public/default
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:122) ~[zookeeper-3.6.3.jar:3.6.3]
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.6.3.jar:3.6.3]
	at org.apache.pulsar.metadata.impl.ZKMetadataStore.getException(ZKMetadataStore.java:304) ~[pulsar-metadata-2.8.2.jar:2.8.2]
	... 5 more

lhotari · 2021-12-03T08:35:43Z

Problem happens here:

pulsar/pulsar-broker/src/main/java/org/apache/pulsar/common/naming/NamespaceBundleFactory.java

Lines 104 to 110 in 0b9d51b

    
           // If no local policies defined for namespace, copy from global config 
        
           copyToLocalPolicies(namespace) 
        
                   .thenAccept(b -> future.complete(b)) 
        
                   .exceptionally(ex -> { 
        
                       future.completeExceptionally(ex); 
        
                       return null; 
        
                   });

lhotari · 2021-12-03T08:37:41Z

Exception gets handled here:

pulsar/pulsar-broker/src/main/java/org/apache/pulsar/broker/namespace/NamespaceService.java

Lines 205 to 208 in e1fbccd

    
           }).exceptionally(ex -> { 
        
               lookupFailures.inc(); 
        
               return null; 
        
           });

and here:

pulsar/pulsar-broker/src/main/java/org/apache/pulsar/broker/lookup/TopicLookupBase.java

Lines 126 to 130 in 5dc5de8

    
           }).exceptionally(exception -> { 
        
               log.warn("Failed to lookup broker for topic {}: {}", topicName, exception.getMessage(), exception); 
        
               completeLookupResponseExceptionally(asyncResponse, exception); 
        
               return null; 
        
           });

lhotari · 2021-12-03T09:19:15Z

I have a fix for branch-2.8 in lhotari@1a350804 . I'll make similar changes to this PR since they aren't 2.8 specific.

(cherry picked from commit 4d6dc41)

lhotari · 2021-12-03T09:40:54Z

@codelipenghui @eolivelli Please review the recent changes.

eolivelli

+1

lhotari · 2021-12-03T10:35:13Z

PR to backport this fix to branch-2.8 is #13117

…ache#13117)

…ache#13117) (cherry picked from commit 537dee1)

* Add warning log message when leader broker isn't available * Add more logging about load manager decisions * Use cached information for available brokers * Reproduce lookup race issue * Use java.util.concurrent.Phaser to increase the chances of a race * Address review feedback * Increase concurrency of test case to reproduce race conditions * Use real Zookeeper server in MultiBrokerLeaderElectionTest * Add retry with backoff to loading namespace bundles * Add more topics to test * Address review comment * Fix checkstyle * Improve logging * Address review comments (cherry picked from commit 537dee1)

* Add warning log message when leader broker isn't available * Add more logging about load manager decisions * Use cached information for available brokers * Reproduce lookup race issue * Use java.util.concurrent.Phaser to increase the chances of a race * Address review feedback * Increase concurrency of test case to reproduce race conditions * Use real Zookeeper server in MultiBrokerLeaderElectionTest * Add retry with backoff to loading namespace bundles * Add more topics to test * Address review comment * Fix checkstyle * Improve logging * Address review comments

…!64) Squash merge branch 'optimize-ownership-assign' into '2.8.1' --story=872733891 负载均衡优化(apache#13069)(apache#13117 ) TAPD: --story=872733891

lhotari added type/bug The PR fixed a bug or issue reported a bug area/broker doc-not-needed Your PR changes do not impact docs labels Dec 1, 2021

lhotari added this to the 2.10.0 milestone Dec 1, 2021

lhotari requested review from addisonj, codelipenghui, eolivelli, merlimat and rdhabalia December 1, 2021 13:49

lhotari self-assigned this Dec 1, 2021

lhotari mentioned this pull request Dec 1, 2021

[Broker] Fix LeaderElectionService.getCurrentLeader and add support for empheralOwner in MockZooKeeper #13066

Merged

eolivelli reviewed Dec 1, 2021

View reviewed changes

Comment thread pulsar-broker/src/main/java/org/apache/pulsar/broker/namespace/NamespaceService.java

lhotari force-pushed the lh-fix-topic-ownership-assignment branch from 534eec7 to 7c785d0 Compare December 1, 2021 17:41

lhotari added 5 commits December 2, 2021 20:56

Add warning log message when leader broker isn't available

719430a

Add more logging about load manager decisions

d13f554

Use cached information for available brokers

31e7cc2

Reproduce lookup race issue

aa77c99

Use java.util.concurrent.Phaser to increase the chances of a race

e483775

lhotari force-pushed the lh-fix-topic-ownership-assignment branch from 7c785d0 to e483775 Compare December 2, 2021 19:00

lhotari marked this pull request as ready for review December 2, 2021 19:02

lhotari mentioned this pull request Dec 2, 2021

MaxRedirectException occurs when attempting to delete a subscription that was recently created and then had its topic destroyed #12552

Closed

lhotari requested a review from eolivelli December 2, 2021 19:08

michaeljmarshall approved these changes Dec 2, 2021

View reviewed changes

Comment thread pulsar-broker/src/main/java/org/apache/pulsar/broker/namespace/NamespaceService.java Outdated

eolivelli reviewed Dec 2, 2021

View reviewed changes

Comment thread pulsar-broker/src/main/java/org/apache/pulsar/broker/namespace/NamespaceService.java Outdated

Comment thread pulsar-broker/src/main/java/org/apache/pulsar/broker/namespace/NamespaceService.java Outdated

Address review feedback

772ee18

eolivelli approved these changes Dec 3, 2021

View reviewed changes

eolivelli added release/2.8.2 release/2.9.1 labels Dec 3, 2021

Increase concurrency of test case to reproduce race conditions

f74d278

lhotari added a commit to lhotari/pulsar that referenced this pull request Dec 3, 2021

[Broker] Fix and improve topic ownership assignment (apache#13069)

e1fbccd

lhotari added 3 commits December 3, 2021 11:33

Use real Zookeeper server in MultiBrokerLeaderElectionTest

9a6421b

Add retry with backoff to loading namespace bundles

346581c

Add more topics to test

1b8d144

(cherry picked from commit 4d6dc41)

lhotari marked this pull request as ready for review December 3, 2021 09:40

lhotari added 3 commits December 3, 2021 11:58

Address review comment

584f6aa

Fix checkstyle

0232817

Improve logging

2ba179f

eolivelli reviewed Dec 3, 2021

View reviewed changes

eolivelli approved these changes Dec 3, 2021

View reviewed changes

Address review comments

5c25397

lhotari added a commit to lhotari/pulsar that referenced this pull request Dec 3, 2021

[Broker] Fix and improve topic ownership assignment (apache#13069)

64d6829

lhotari mentioned this pull request Dec 3, 2021

[branch-2.8] [Broker] Fix and improve topic ownership assignment (#13069) #13117

Merged

lhotari added a commit to lhotari/pulsar that referenced this pull request Dec 3, 2021

[Broker] Fix and improve topic ownership assignment (apache#13069)(ap…

5eee5f9

…ache#13117)

lhotari added a commit to lhotari/pulsar that referenced this pull request Dec 3, 2021

[Broker] Fix and improve topic ownership assignment (apache#13069)

0b4adb9

lhotari added a commit to lhotari/pulsar that referenced this pull request Dec 3, 2021

[Broker] Fix and improve topic ownership assignment (apache#13069)(ap…

965df3b

…ache#13117)

lhotari merged commit 537dee1 into apache:master Dec 3, 2021

lhotari added a commit to lhotari/pulsar that referenced this pull request Dec 3, 2021

[Broker] Fix and improve topic ownership assignment (apache#13069)(ap…

bb5bab5

…ache#13117) (cherry picked from commit 537dee1)

lhotari added a commit that referenced this pull request Dec 3, 2021

[Broker] Fix and improve topic ownership assignment (#13069) (#13117)

3f3098c

lhotari added cherry-picked/branch-2.8 Archived: 2.8 is end of life cherry-picked/branch-2.9 Archived: 2.9 is end of life labels Dec 3, 2021

dave2wave mentioned this pull request Dec 7, 2021

[BUG] KOP Topic Partitions are assigned to the same Brokers and are not Balanced. Latency is Large. streamnative/kop#956

Open

Uh oh!

Conversation

lhotari commented Dec 1, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Motivation

Modifications

Additional context

Uh oh!

Uh oh!

michaeljmarshall left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Uh oh!

Uh oh!

eolivelli left a comment

Choose a reason for hiding this comment

Uh oh!

lhotari commented Dec 3, 2021

Uh oh!

lhotari commented Dec 3, 2021

Uh oh!

lhotari commented Dec 3, 2021 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

lhotari commented Dec 3, 2021

Uh oh!

lhotari commented Dec 3, 2021

Uh oh!

Uh oh!

Uh oh!

Uh oh!

eolivelli left a comment

Choose a reason for hiding this comment

Uh oh!

lhotari commented Dec 3, 2021

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

lhotari commented Dec 1, 2021 •

edited

Loading

lhotari commented Dec 3, 2021 •

edited

Loading