[Bug] Pulsar LedgerHandle contains incorrect ensemble leading to producer creation failure

[manmeetkc]

Search before asking

• I searched in the issues and found nothing similar.

Read release policy

• 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: #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!

[programmerahul]

This issue is solved by
apache/bookkeeper#4613
#25199
#23977

the ledgerHandle data get outdated because after decommissioning of bookies, those updates aren't received and processed correctly in broker. 25199 the method used for this action doesn't register for updates from zk. Even after receiving the updates 23977 the ledger regex is incorrect so correct handler is not called.