[Bug] Pulsar LedgerHandle contains incorrect ensemble leading to producer creation failure
- 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
3.0.9
### Minimal reproduce step
Not able to reproduce.
### What did you expect to see?
System client should be able to create reader on system topic and read events from the system topic to init topic policy caches.
### What did you see instead?
**Observations:**
We found that some of the topics were getting producer creation timeouts with logs:
`java.util.concurrent.CompletionException: org.apache.pulsar.broker.service.BrokerServiceException$ServiceUnitNotReadyException: Topic creation encountered an exception by initialize topic policies service. topic_name=persistent://persistent://tenant/ns-1/topic-partition-0 error_message=The subscription reader-1f00e888ff of the topic persistent://tenant/ns-1/__change_events gets the last message id was failed,13,46
java.util.concurrent.CompletionException: org.apache.pulsar.broker.service.BrokerServiceException$ServiceUnitNotReadyException: Topic creation encountered an exception by initialize topic policies service. topic_name=persistent://tenant/ns-1/topic-partition-0 error_message=The subscription reader-c9140278f8 of the topic persistent://tenant/ns-1/__change_events gets the last message id was failed`
On looking at logs of owning broker of the system topic tenant/ns-1/__change_events found the following log:
`[BookKeeperClientWorker-OrderedExecutor-1-0] ERROR org.apache.bookkeeper.client.PendingReadOp - Read of ledger entry failed: L805551 E0-E0, Sent to [prod-gke-as1-1-pulsar-bookie-4.prod-gke-as1-1-pulsar-bookie.viesti-prod.svc.cluster.local:3181, prod-gke-as1-1-pulsar-bookie-2.prod-gke-as1-1-pulsar-bookie.viesti-prod.svc.cluster.local:3181], Heard from [] : bitset = {}, Error = 'No such ledger exists on Bookies'. First unread entry is (-1, rc = null)`
From above we can see that the ensemble contains bookie-4 and bookie-2(this was confirmed from heapdump as well) however when getting the ensemble from ledgermetadata we were getting the following which is completely different with bookie-3 and bookie-0
`ensembles={0=[prod-gke-as1-1-pulsar-bookie-3.prod-gke-as1-1-pulsar-bookie.viesti-prod.svc.cluster.local:3181, prod-gke-as1-1-pulsar-bookie-0.prod-gke-as1-1-pulsar-bookie.viesti-prod.svc.cluster.local:3181]}
`
Looking at the bookies I saw that they all had ages ranging from 5-7 days even though no rollouts were done, so I am assuming due to some reason bookies restarted leading to ensemble changes which were somehow not updated in bookkeeper client of the broker
### Anything else?
Wondering if anyone has faced this issue specifically with __change_events topic
Could be similar to: https://github.com/apache/pulsar/issues/13693 however we saw this issue with __change_events topic only.
### Are you willing to submit a PR?
- [ ] I'm willing to submit a PR!
Contributor guide
Research direction
Start with the broker logs for the __change_events topic and compare the LedgerHandle ensemble with BookKeeper ledger metadata; the report also references a heap dump and issue #13693. Done means reproducing or explaining why the broker uses a different ensemble after bookie restarts, then identifying a supported fix or the missing diagnostic evidence.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- distributed-systems
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Quiet
- Clarity
- Needs clarification
- Newbie friendliness
- 32/100