[Bug] Another issue result in broker lost bookie rack information in pulsar new version
- Dominant language
- Java
- Stars
- 15.3k
- Forks
- 3.8k
- Avg merge
- 1d 14h
- Merged PRs (30d)
- 160
Description
### Search before asking
- [X] I searched in the [issues](https://github.com/apache/pulsar/issues) and found nothing similar.
### Read release policy
- [X] I understand that unsupported versions don't get bug fixes. I will attempt to reproduce the issue on a supported version of Pulsar client and Pulsar broker.
### Version
pulsar-3.0.6
### Minimal reproduce step
restart broker many times
### What did you expect to see?
when broker restart, can load rack information correctly
### What did you see instead?
This is a supplement of https://github.com/apache/pulsar/issues/23282. After fix the previous issue, we found another issue would cause broker lost rack information. When broker restart many times, some broker may generate the following log, illustrate that it has lost rack information.
```
11:52:24.768 [ForkJoinPool.commonPool-worker-1] INFO org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Initialize rackaware ensemble placement policy @ null @ Unknown : org.apache.pulsar.bookie.rackawareness.BookieRackAffinityMapping.
11:52:24.768 [ForkJoinPool.commonPool-worker-1] INFO org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl - Not weighted
11:52:24.768 [ForkJoinPool.commonPool-worker-1] INFO org.apache.bookkeeper.client.BookKeeper - Weighted ledger placement is not enabled
11:52:24.775 [metadata-store-33-1] INFO org.apache.pulsar.metadata.bookkeeper.PulsarRegistrationClient - Update BookieInfoCache (writable bookie) ip1:port1 -> BookieServiceInfo{properties={}, endpoints=[EndpointInfo{id=bookie, port=port1, host=ip1, protocol=bookie-rpc, auth=[], extensions=[]}]}
11:52:24.775 [metadata-store-33-1] INFO org.apache.pulsar.metadata.bookkeeper.PulsarRegistrationClient - Update BookieInfoCache (writable bookie) ip1:port1 -> BookieServiceInfo{properties={}, endpoints=[EndpointInfo{id=bookie, port=port1, host=ip1, protocol=bookie-rpc, auth=[], extensions=[]}]}
11:52:24.796 [pulsar-registration-client-58-1] WARN org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy - Failed to resolve network location for ip1, using default rack for it : /default-region/default-rack.
11:52:24.796 [pulsar-registration-client-58-1] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-region/default-rack/ip1:port1
11:52:24.797 [pulsar-registration-client-58-1] WARN org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy - Failed to resolve network location for ip1, using default rack for it : /default-region/default-rack.
11:52:24.797 [pulsar-registration-client-58-1] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-region/default-rack/ip1:port2
```
Actually, the root reason is the same as https://github.com/apache/pulsar/issues/23282, two listeners in registrationClient must be executed in a sync way.
But the code implementation is async, when we restart broker, we do listener registering in PulsarRegistrationClient#watchWritableBookies. Notice that this is an async method. First listener is register in BookieRackAffinityMapping#watchAvailableBookies, using async way. Second listener is register in BookieWatcherImpl#initialBlockingBookieRead, using sync way.
That is the reason. In PulsarRegistrationClient#watchWritableBookies, two listeners is add into writableBookiesWatchers in a sync way. But when execute `getWritableBookies().thenAcceptAsync(registrationListener::onBookiesChanged, executor)`, it is async.
It is easy to confirm this issue, just add some log in each part of PulsarRegistrationClient#watchWritableBookies. Since there are two listeners, We can see getWritableBookies() would be executed twice, in a async way.
https://github.com/apache/pulsar/blob/9012422bcbaac7b38820ce545cd5a3b4f8b586d0/pulsar-metadata/src/main/java/org/apache/pulsar/metadata/bookkeeper/PulsarRegistrationClient.java#L180-L187
### Anything else?
By the way, previous version do not have this issue. Because previous version use ZKRegistrationClient as implementation of RegistrationClient, but not PulsarRegistrationClient. After PIP-45, pulsar change the implementation into PulsarRegistrationClient. Then would cause the issue.
Because ZKRegistrationClient#watchWritableBookies can ensure two listeners executed in a sync way. while PulsarRegistrationClient#watchWritableBookies can not.
### Are you willing to submit a PR?
- [X] I'm willing to submit a PR!
Contributor guide
Research direction
Start in pulsar-metadata/src/main/java/org/apache/pulsar/metadata/bookkeeper/PulsarRegistrationClient.java at watchWritableBookies, then compare the listener behavior with BookieRackAffinityMapping#watchAvailableBookies, BookieWatcherImpl#initialBlockingBookieRead, and the prior ZKRegistrationClient implementation. Reproduce repeated broker restarts and verify both listeners execute in order so bookie rack information is retained instead of falling back to the default rack.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- distributed-systems
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 45/100