text:
[Bug] Unable to create Connectors on Pulsar 2.9.1 (bare metal cluster)

Search before asking

[X] I searched in the issues and found nothing similar.

Version
OS: Debian 5.10.162-1 (2023-01-21) x86_64 GNU/Linux
Pulsar: 2.9.1
Pulsar Built-in File Source Connector: 2.9.1
Pulsar Built-in Debezium PostgreSQL Source Connector: 2.9.1
Java: openjdk 11.0.18 2023-01-17
Minimal reproduce step
Steps described below were performed using Ansible in order to perform identical configuration on machines of same type. This was done in order to reduce human errors.

Deploy a (single) cluster (of 6 machines) on bare-metal: 3 machines for brokers + bookies (both run on each machine), 3 machines for zookeepers following given instructions: https://pulsar.apache.org/docs/2.9.x/deploy-bare-metal/
Adjust firewall settings on each machine to allow incoming connections to ports used by Pulsar (including TCP 4181 on broker+bookie machines);
Initialize distributed log metadata;
Adjust following settings in broker.conf:

authenticationEnabled=true
authorizationEnabled=true
authenticationProviders=org.apache.pulsar.broker.authentication.AuthenticationProviderToken
brokerClientAuthenticationPlugin=org.apache.pulsar.client.impl.auth.AuthenticationToken
brokerClientAuthenticationParameters=token:generatedTokenGoesHere
superUserRoles=superUserRoleGoesHere
anonymousUserRole=anonymousRoleGoesHere
tokenSecretKey=file://path_to_secret_key

Adjust following settings in client.conf:

authPlugin=org.apache.pulsar.client.impl.auth.AuthenticationToken
authParams=token:generatedTokenGoesHere

Set namespace permissions for existing namespaces
Configure functions workers in following way:

Use Process runtime for function worker, as it is described here: https://pulsar.apache.org/docs/2.9.x/functions-runtime/#configure-process-runtime
Configure run-with-brokers, as it is described here: https://pulsar.apache.org/docs/2.9.x/functions-worker/#run-functions-worker-with-brokers (numFunctionPackageReplicas – 2; initializedDlogMetadata: false; workerId – set; workerHostname – set; wokerPort – 6750; wokerPortTls – 6751, download directory – /tmp/pulsar_functions; pulsarFunctionsNamespace – public/functions; pulsarFunctionsCluster – correct one; functionMetadataTopicName – metadata; clusterCoordinationTopicName – coordinate; useCompactedMetadataTopic – false; authenticateMetricsEndpoint – false; stateStorageServiceUrl: bk://one-of-the-zookeeper-machine-addres:4181; connectorsDirectory – ./connectors; functionsDirectory – ./functions)
Restart bookies and brokers
Ensure functions wokers work as expected by performing admin/v2/worker/cluster REST Admin API call;
Deploy connector (tried File Source, Debezium PostgreSQL source and custom CDC sink) and configuration of it to broker machines- (to <pulsar directory>/connectors and <pulsar directory>/connectors/configuration respectively);

After setup is done, navigate to <pulsar directory>/bin directory and perform:
./pulsar-admin sources create --archive /opt/pulsar/apache-pulsar-2.9.1/connectors/pulsar-io-file-2.9.1.nar --name file-test --destination-topic-name pulsar-file-test --source-config-file /opt/pulsar/apache-pulsar-2.9.1/connectors/configuration/file-connector.yml
In case of Built-in File Source connector, configuration of it is:
configs:
    inputDirectory: "/opt/pulsar"
    recurse: false
    keepFile: true
    fileFilter: "[^\\.].txt"

Broker machine has a.txt in /opt/pulsar directory (readable, permissions and ownership verified)
~$ cat /opt/pulsar/a.txt
test

To clarify:

bookkeeper.conf has zkServers=<list_of_actual_addresses_of_zookeper_instances>;
broker.conf has zookeeperServers=<list_of_actual_addresses_of_zookeper_instances>;
broker.conf has configurationStoreServers=<list_of_actual_addresses_of_zookeper_instances>;
broker.conf has globalZookeeperServers=<list_of_actual_addresses_of_zookeper_instances>;
functions_woker.yml has configurationStoreServers commented-out;

The cluster works fine, without any errors while StateStorageLifecycleComponent is not enabled in bookkeeper.conf on servers containing Bookkeeper. After functions worker setup is done, connectors do work in localrun mode (this proves that configuration of connector is valid, both for File Source and Debezium PostgreSQL Source). After StateStorageLifecycleComponent gets enabled, following piece reoccurs in logs (if initializedDlogMetadata: false – in logs of Broker, if initializedDlogMetadata: true – in  logs of Bookkeeper):
Jul 05 11:29:18 pulsar[797192]: 2023-07-05T11:29:18,297+0300 [io-write-scheduler-OrderedScheduler-1-0-SendThread(localhost:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181.
Jul 05 11:29:18 pulsar[797192]: 2023-07-05T11:29:18,297+0300 [io-write-scheduler-OrderedScheduler-1-0-SendThread(localhost:2181)] INFO  org.apache.zookeeper.ClientCnxn - SASL config status: Will not attempt to authenticate using SASL (unknown error)
Jul 05 11:29:18 pulsar[797192]: 2023-07-05T11:29:18,298+0300 [io-write-scheduler-OrderedScheduler-1-0-SendThread(localhost:2181)] WARN  org.apache.zookeeper.ClientCnxn - Session 0x0 for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting reconnect except it is a SessionExpiredException.
Jul 05 11:29:18 pulsar[797192]: java.net.ConnectException: Connection refused
Jul 05 11:29:18 pulsar[797192]:         at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[?:?]
Jul 05 11:29:18 pulsar[797192]:         at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:777) ~[?:?]
Jul 05 11:29:18 pulsar[797192]:         at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:344) ~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
Jul 05 11:29:18 pulsar[797192]:         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1290) [org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]

What is more, this fragment reoccurs without connector-related pulsar-admin calls.
What did you expect to see?
Connector running (succesfully created and started).
What did you see instead?
Error on allocating ledger under /pulsar/functions/public/default//78b1ef8d-ab3c-4deb-8b60-0579ff0ba395-.nar//allocation
Reason: HTTP 500 Internal Server Error
Anything else?
Also, after StateStorageLifecycleComponent gets enabled (and initializedDlogMetadata is set to false), following piece (stream paths change) reoccurs periodically in broker logs:
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,907+0300 [io-write-scheduler-OrderedScheduler-1-0] ERROR org.apache.distributedlog.bk.SimpleLedgerAllocator - Error creating ledger for allocating /stream/storage/streams_000000000000000004_000000000000000001_000000000000000000/<default>/allocation :
Jul 05 11:29:23 pulsar[797192]: org.apache.distributedlog.ZooKeeperClient$ZooKeeperConnectionException: Problem connecting to servers: localhost:2181
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.ZooKeeperClient.buildZooKeeper(ZooKeeperClient.java:320) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.ZooKeeperClient.get(ZooKeeperClient.java:239) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BookKeeperClient.commonInitialization(BookKeeperClient.java:115) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BookKeeperClient.initialize(BookKeeperClient.java:172) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BookKeeperClient.get(BookKeeperClient.java:199) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BookKeeperClient.createLedger(BookKeeperClient.java:211) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.bk.SimpleLedgerAllocator.allocateLedger(SimpleLedgerAllocator.java:370) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.bk.SimpleLedgerAllocator.allocate(SimpleLedgerAllocator.java:271) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.bk.LedgerAllocatorDelegator.allocate(LedgerAllocatorDelegator.java:67) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.impl.logsegment.BKLogSegmentAllocator.allocate(BKLogSegmentAllocator.java:55) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler.doStartLogSegment(BKLogWriteHandler.java:571) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:538) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:42) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:26) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:883) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2251) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler.asyncStartLogSegment(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.lambda$asyncStartNewLogSegment$1(BKAbstractLogWriter.java:379) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.asyncStartNewLogSegment(BKAbstractLogWriter.java:378) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.rollLogSegmentIfNecessary(BKAbstractLogWriter.java:517) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.doGetLogSegmentWriter(BKAsyncLogWriter.java:226) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:211) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:249) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.rollLogSegmentAndIssuePendingRequests(BKAsyncLogWriter.java:344) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.asyncWrite(BKAsyncLogWriter.java:302) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.write(BKAsyncLogWriter.java:420) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal.writeCommandBuf(AbstractStateStoreWithJournal.java:550) ~[org.apache.bookkeeper-statelib-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal.lambda$initializeJournalWriter$6(AbstractStateStoreWithJournal.java:248) ~[org.apache.bookkeeper-statelib-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]
Jul 05 11:29:23 pulsar[797192]:         at java.lang.Thread.run(Thread.java:829) [?:?]
Jul 05 11:29:23 pulsar[797192]: Caused by: org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss
Jul 05 11:29:23 pulsar[797192]:         at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase.waitForConnection(ZooKeeperWatcherBase.java:159) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.zookeeper.ZooKeeperClient$Builder.build(ZooKeeperClient.java:260) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.ZooKeeperClient.buildZooKeeper(ZooKeeperClient.java:318) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         ... 40 more
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,908+0300 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /stream/storage/streams_000000000000000004_000000000000000001_000000000000000000/<default>/allocation moved to phase ERROR : version = 0.
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,908+0300 [io-write-scheduler-OrderedScheduler-1-0-EventThread] INFO  org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x0
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,908+0300 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - Clearing resources hold by stream(1)/range(0) at storage container (4)
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,908+0300 [io-write-scheduler-OrderedScheduler-1-0] WARN  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerRegistryImpl - De-registered StorageContainer ('4') when failed to start
Jul 05 11:29:23 pulsar[797192]: java.util.concurrent.CompletionException: org.apache.distributedlog.bk.SimpleLedgerAllocator$AllocationException: Error on allocating ledger under /stream/storage/streams_000000000000000004_000000000000000001_000000000000000000/<default>/allocation
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:670) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.asyncWrite(BKAsyncLogWriter.java:309) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.write(BKAsyncLogWriter.java:420) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal.writeCommandBuf(AbstractStateStoreWithJournal.java:550) ~[org.apache.bookkeeper-statelib-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal.lambda$initializeJournalWriter$6(AbstractStateStoreWithJournal.java:248) ~[org.apache.bookkeeper-statelib-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]
Jul 05 11:29:23 pulsar[797192]:         at java.lang.Thread.run(Thread.java:829) [?:?]
Jul 05 11:29:23 pulsar[797192]: Caused by: org.apache.distributedlog.bk.SimpleLedgerAllocator$AllocationException: Error on allocating ledger under /stream/storage/streams_000000000000000004_000000000000000001_000000000000000000/<default>/allocation
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.bk.SimpleLedgerAllocator.tryObtain(SimpleLedgerAllocator.java:279) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.bk.LedgerAllocatorDelegator.tryObtain(LedgerAllocatorDelegator.java:73) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.impl.logsegment.BKLogSegmentAllocator.tryObtain(BKLogSegmentAllocator.java:61) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler.doStartLogSegment(BKLogWriteHandler.java:589) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:538) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:42) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:26) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:883) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2251) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler.asyncStartLogSegment(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.lambda$asyncStartNewLogSegment$1(BKAbstractLogWriter.java:379) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.asyncStartNewLogSegment(BKAbstractLogWriter.java:378) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.rollLogSegmentIfNecessary(BKAbstractLogWriter.java:517) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.doGetLogSegmentWriter(BKAsyncLogWriter.java:226) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:211) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:249) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.rollLogSegmentAndIssuePendingRequests(BKAsyncLogWriter.java:344) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.asyncWrite(BKAsyncLogWriter.java:302) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         ... 12 more
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,908+0300 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerRegistryImpl - Release resources hold by StorageContainer ('4') during de-register
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,908+0300 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl - Stopping storage container (4) ...
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,909+0300 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=localhost:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@27f4e436
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,909+0300 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,909+0300 [DLM-/stream/storage-OrderedScheduler-0-0] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=false
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,918+0300 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.stream.storage.impl.store.MVCCStoreFactoryImpl - scStores for 4 on store factory is null, return directly
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,918+0300 [io-write-scheduler-OrderedScheduler-1-0] INFO  org.apache.bookkeeper.stream.storage.impl.sc.StorageContainerImpl - Successfully stopped storage container (4).
Jul 05 11:29:23 pulsar[797192]: 2023-07-05T11:29:23,918+0300 [io-write-scheduler-OrderedScheduler-1-0] WARN  org.apache.bookkeeper.stream.storage.impl.sc.ZkStorageContainerManager - Failed to start storage container (4)
Jul 05 11:29:23 pulsar[797192]: java.util.concurrent.CompletionException: org.apache.distributedlog.bk.SimpleLedgerAllocator$AllocationException: Error on allocating ledger under /stream/storage/streams_000000000000000004_000000000000000001_000000000000000000/<default>/allocation
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:331) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:670) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:658) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2094) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.asyncWrite(BKAsyncLogWriter.java:309) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.write(BKAsyncLogWriter.java:420) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal.writeCommandBuf(AbstractStateStoreWithJournal.java:550) ~[org.apache.bookkeeper-statelib-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.statelib.impl.journal.AbstractStateStoreWithJournal.lambda$initializeJournalWriter$6(AbstractStateStoreWithJournal.java:248) ~[org.apache.bookkeeper-statelib-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
Jul 05 11:29:23 pulsar[797192]:         at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]
Jul 05 11:29:23 pulsar[797192]:         at java.lang.Thread.run(Thread.java:829) [?:?]
Jul 05 11:29:23 pulsar[797192]: Caused by: org.apache.distributedlog.bk.SimpleLedgerAllocator$AllocationException: Error on allocating ledger under /stream/storage/streams_000000000000000004_000000000000000001_000000000000000000/<default>/allocation
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.bk.SimpleLedgerAllocator.tryObtain(SimpleLedgerAllocator.java:279) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.bk.LedgerAllocatorDelegator.tryObtain(LedgerAllocatorDelegator.java:73) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.impl.logsegment.BKLogSegmentAllocator.tryObtain(BKLogSegmentAllocator.java:61) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler.doStartLogSegment(BKLogWriteHandler.java:589) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:538) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:42) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:26) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:883) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2251) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKLogWriteHandler.asyncStartLogSegment(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.lambda$asyncStartNewLogSegment$1(BKAbstractLogWriter.java:379) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.uniComposeStage(CompletableFuture.java:1106) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at java.util.concurrent.CompletableFuture.thenCompose(CompletableFuture.java:2235) ~[?:?]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.asyncStartNewLogSegment(BKAbstractLogWriter.java:378) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAbstractLogWriter.rollLogSegmentIfNecessary(BKAbstractLogWriter.java:517) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.doGetLogSegmentWriter(BKAsyncLogWriter.java:226) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:211) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.getLogSegmentWriter(BKAsyncLogWriter.java:249) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.rollLogSegmentAndIssuePendingRequests(BKAsyncLogWriter.java:344) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         at org.apache.distributedlog.BKAsyncLogWriter.asyncWrite(BKAsyncLogWriter.java:302) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 11:29:23 pulsar[797192]:         ... 12 more

If StateStorageLifecycleComponent gets enabled (and initializedDlogMetadata is set to false), following piece (stream paths change) occurs in logs when pulsar-admin sources create is called:
Jul 05 15:51:50 pulsar[96898]: 2023-07-05T15:51:50,642+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /pulsar/functions/public/default/file-test/67849712-9304-4be3-819c-991577feb171-pulsar-io-file-2.9.1.nar/<default>/allocation moved to phase ALLOCATING : version = 0.
Jul 05 15:51:50 pulsar[96898]: 2023-07-05T15:51:50,647+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] INFO  org.apache.zookeeper.ZooKeeper - Initiating client connection, connectString=localhost:2181 sessionTimeout=30000 watcher=org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase@5d5a5173
Jul 05 15:51:50 pulsar[96898]: 2023-07-05T15:51:50,647+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] INFO  org.apache.zookeeper.ClientCnxnSocket - jute.maxbuffer value is 10485760 Bytes
Jul 05 15:51:50 pulsar[96898]: 2023-07-05T15:51:50,648+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] INFO  org.apache.zookeeper.ClientCnxn - zookeeper.request.timeout value is 0. feature enabled=false
Jul 05 15:51:50 pulsar[96898]: 2023-07-05T15:51:50,658+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0-SendThread(localhost:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181.
Jul 05 15:51:50 pulsar[96898]: 2023-07-05T15:51:50,659+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0-SendThread(localhost:2181)] INFO  org.apache.zookeeper.ClientCnxn - SASL config status: Will not attempt to authenticate using SASL (unknown error)
Jul 05 15:51:50 audit[96898]: SYSCALL arch=c000003e syscall=41 success=yes exit=533 a0=2 a1=1 a2=0 a3=7f50a0807a01 items=0 ppid=1 pid=96898 auid=4294967295 uid=1008 gid=1008 euid=1008 suid=1008 fsuid=1008 egid=1008 sgid=1008 fsgid=1008 tty=(none) ses=4294967295 comm="DLM-/pulsar/fun" exe="/usr/lib/jvm/java-11-openjdk-amd64/bin/java" subj=unconfined key="mdatp"
Jul 05 15:51:50 audit[96898]: SYSCALL arch=c000003e syscall=42 success=no exit=-115 a0=215 a1=7f5042273490 a2=10 a3=b52 items=0 ppid=1 pid=96898 auid=4294967295 uid=1008 gid=1008 euid=1008 suid=1008 fsuid=1008 egid=1008 sgid=1008 fsgid=1008 tty=(none) ses=4294967295 comm="DLM-/pulsar/fun" exe="/usr/lib/jvm/java-11-openjdk-amd64/bin/java" subj=unconfined key="mdatp"
Jul 05 15:51:50 pulsar[96898]: 2023-07-05T15:51:50,661+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0-SendThread(localhost:2181)] WARN  org.apache.zookeeper.ClientCnxn - Session 0x0 for sever localhost/127.0.0.1:2181, Closing socket connection. Attempting reconnect except it is a SessionExpiredException.
Jul 05 15:51:50 pulsar[96898]: java.net.ConnectException: Connection refused
Jul 05 15:51:50 pulsar[96898]:         at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[?:?]
Jul 05 15:51:50 pulsar[96898]:         at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:777) ~[?:?]
Jul 05 15:51:50 pulsar[96898]:         at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:344) ~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
Jul 05 15:51:50 pulsar[96898]:         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1290) [org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
...
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,550+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0-SendThread(localhost:2181)] INFO  org.apache.zookeeper.ClientCnxn - Opening socket connection to server localhost/127.0.0.1:2181.
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,551+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0-SendThread(localhost:2181)] INFO  org.apache.zookeeper.ClientCnxn - SASL config status: Will not attempt to authenticate using SASL (unknown error)
Jul 05 15:52:21 audit[96898]: SYSCALL arch=c000003e syscall=41 success=yes exit=537 a0=2 a1=1 a2=0 a3=7f50a0807a01 items=0 ppid=1 pid=96898 auid=4294967295 uid=1008 gid=1008 euid=1008 suid=1008 fsuid=1008 egid=1008 sgid=1008 fsgid=1008 tty=(none) ses=4294967295 comm="DLM-/pulsar/fun" exe="/usr/lib/jvm/java-11-openjdk-amd64/bin/java" subj=unconfined key="mdatp"
Jul 05 15:52:21 audit[96898]: SYSCALL arch=c000003e syscall=42 success=no exit=-115 a0=219 a1=7f5042273490 a2=10 a3=bcc items=0 ppid=1 pid=96898 auid=4294967295 uid=1008 gid=1008 euid=1008 suid=1008 fsuid=1008 egid=1008 sgid=1008 fsgid=1008 tty=(none) ses=4294967295 comm="DLM-/pulsar/fun" exe="/usr/lib/jvm/java-11-openjdk-amd64/bin/java" subj=unconfined key="mdatp"
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,552+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0-SendThread(localhost:2181)] WARN  org.apache.zookeeper.ClientCnxn - An exception was thrown while closing send thread for session 0x0.
Jul 05 15:52:21 pulsar[96898]: java.net.ConnectException: Connection refused
Jul 05 15:52:21 pulsar[96898]:         at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:777) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:344) ~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1290) [org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,655+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] INFO  org.apache.zookeeper.ZooKeeper - Session: 0x0 closed
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,656+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0-EventThread] INFO  org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x0
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,657+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] ERROR org.apache.distributedlog.bk.SimpleLedgerAllocator - Error creating ledger for allocating /pulsar/functions/public/default/file-test/67849712-9304-4be3-819c-991577feb171-pulsar-io-file-2.9.1.nar/<default>/allocation :
Jul 05 15:52:21 pulsar[96898]: org.apache.distributedlog.ZooKeeperClient$ZooKeeperConnectionException: Problem connecting to servers: localhost:2181
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.ZooKeeperClient.buildZooKeeper(ZooKeeperClient.java:320) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.ZooKeeperClient.get(ZooKeeperClient.java:239) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BookKeeperClient.commonInitialization(BookKeeperClient.java:115) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BookKeeperClient.initialize(BookKeeperClient.java:172) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BookKeeperClient.get(BookKeeperClient.java:199) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BookKeeperClient.createLedger(BookKeeperClient.java:211) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.bk.SimpleLedgerAllocator.allocateLedger(SimpleLedgerAllocator.java:370) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.bk.SimpleLedgerAllocator.allocate(SimpleLedgerAllocator.java:271) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.bk.LedgerAllocatorDelegator.allocate(LedgerAllocatorDelegator.java:67) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.impl.logsegment.BKLogSegmentAllocator.allocate(BKLogSegmentAllocator.java:55) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler.doStartLogSegment(BKLogWriteHandler.java:571) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:538) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:42) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:26) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:883) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2251) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler.asyncStartLogSegment(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKAbstractLogWriter.lambda$asyncStartNewLogSegment$1(BKAbstractLogWriter.java:379) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.common.concurrent.FutureUtils$ListFutureProcessor.run(FutureUtils.java:229) [org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125) [com.google.guava-guava-30.1-jre.jar:?]
Jul 05 15:52:21 pulsar[96898]:         at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69) [com.google.guava-guava-30.1-jre.jar:?]
Jul 05 15:52:21 pulsar[96898]:         at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78) [com.google.guava-guava-30.1-jre.jar:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]
Jul 05 15:52:21 pulsar[96898]:         at java.lang.Thread.run(Thread.java:829) [?:?]
Jul 05 15:52:21 pulsar[96898]: Caused by: org.apache.zookeeper.KeeperException$ConnectionLossException: KeeperErrorCode = ConnectionLoss
Jul 05 15:52:21 pulsar[96898]:         at org.apache.zookeeper.KeeperException.create(KeeperException.java:102) ~[org.apache.zookeeper-zookeeper-3.6.3.jar:3.6.3]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.zookeeper.ZooKeeperWatcherBase.waitForConnection(ZooKeeperWatcherBase.java:159) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.zookeeper.ZooKeeperClient$Builder.build(ZooKeeperClient.java:260) ~[org.apache.bookkeeper-bookkeeper-server-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.ZooKeeperClient.buildZooKeeper(ZooKeeperClient.java:318) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         ... 34 more
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,660+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Ledger allocator /pulsar/functions/public/default/file-test/67849712-9304-4be3-819c-991577feb171-pulsar-io-file-2.9.1.nar/<default>/allocation moved to phase ERROR : version = 0.
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,688+0300 [DLM-/pulsar/functions-OrderedScheduler-0-0] INFO  org.apache.distributedlog.bk.SimpleLedgerAllocator - Abort ledger allocator without cleaning up on /pulsar/functions/public/default/file-test/67849712-9304-4be3-819c-991577feb171-pulsar-io-file-2.9.1.nar/<default>/allocation.
Jul 05 15:52:21 pulsar[96898]: 2023-07-05T15:52:21,691+0300 [pulsar-web-36-1] ERROR org.apache.pulsar.functions.worker.rest.api.SourcesImpl - Failed process Source public/default/file-test package:
Jul 05 15:52:21 pulsar[96898]: org.apache.distributedlog.bk.SimpleLedgerAllocator$AllocationException: Error on allocating ledger under /pulsar/functions/public/default/file-test/67849712-9304-4be3-819c-991577feb171-pulsar-io-file-2.9.1.nar/<default>/allocation
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.bk.SimpleLedgerAllocator.tryObtain(SimpleLedgerAllocator.java:279) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.bk.LedgerAllocatorDelegator.tryObtain(LedgerAllocatorDelegator.java:73) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.impl.logsegment.BKLogSegmentAllocator.tryObtain(BKLogSegmentAllocator.java:61) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler.doStartLogSegment(BKLogWriteHandler.java:589) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:538) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler$10.onSuccess(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:42) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:26) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:859) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.uniWhenCompleteStage(CompletableFuture.java:883) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.whenComplete(CompletableFuture.java:2251) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKLogWriteHandler.asyncStartLogSegment(BKLogWriteHandler.java:530) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.distributedlog.BKAbstractLogWriter.lambda$asyncStartNewLogSegment$1(BKAbstractLogWriter.java:379) ~[org.apache.distributedlog-distributedlog-core-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1072) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at org.apache.bookkeeper.common.concurrent.FutureUtils$ListFutureProcessor.run(FutureUtils.java:229) ~[org.apache.bookkeeper-bookkeeper-common-4.14.2.jar:4.14.2]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125) ~[com.google.guava-guava-30.1-jre.jar:?]
Jul 05 15:52:21 pulsar[96898]:         at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69) ~[com.google.guava-guava-30.1-jre.jar:?]
Jul 05 15:52:21 pulsar[96898]:         at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78) ~[com.google.guava-guava-30.1-jre.jar:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
Jul 05 15:52:21 pulsar[96898]:         at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.72.Final.jar:4.1.72.Final]
Jul 05 15:52:21 pulsar[96898]:         at java.lang.Thread.run(Thread.java:829) [?:?]
Jul 05 15:52:21 pulsar[96898]:         Suppressed: org.apache.distributedlog.exceptions.WriteException: Write rejected because stream public/default/file-test/67849712-9304-4be3-819c-991577feb171-pulsar-io-file-2.9.1.nar has encountered an error : writer has been closed due to error.
...

Are you willing to submit a PR?

[ ] I'm willing to submit a PR!

I have deployed a new cluster of 6 nodes (3 broker + bookkeeper machines and 3 zookeeper machines), running Pulsar 2.11.1. Using pretty much same configuration, I encounter same error: Error on allocating ledger under /pulsar/functions/ ...

Yesterday I have spent some time analizing 2.11.1 Pulsar source code, trying to figure out what may be the cause of zookeper connection to localhost (even though, nor broker, nor bookie, nor functions worker configuration does not contain any entries related to localhost). After digging the code that is mentioned in the stacktraces I've provided and stacktraces I get using Pulsar 2.11.1, I have a strong feeling that problem is located in uploadToBookKeeper(Namespace, InputStream, String) method call in WorkerUtils class. After this method gets called, BookKeeper client tries to access a bookkeeper via ZooKeeper, but somehow (not sure how exactly) ZooKeeperClient gets initialized with localhost value.

I have managed to register both source (both file and Debezium PostgreSQL Source) and (custom) sink connectors in 2.11.1 cluster. Stream storage service was disabled (as it is by default). I have set functionsWorkerEnablePackageManagement=true and enablePackagesManagement=true, restarted brokers and finally was able to run the connectors! I tried to do the same on 2.9.1, but result did not change at all – I still got ledger allocation errors.

I have finally managed to register both source (both file and Debezium PostgreSQL Source) and (custom) sink connectors in 2.9.1 bare-metal cluster. Once I added file:// schema prefix to path of the archive (I have provided absolute or relative file system paths of the archives until this discovery, same way as it is described in documentation), all the connectors that I was testing, got created (registered) successfully, operated properly after restart of broker node. It was not the case in 2.11.1 cluster with functionsWorkerEnablePackageManagement enabled – after restart of the broker, connector didn't start automatically and ended up having underlying internal error).

Once I added file:// schema prefix to path of the archive

Could you elaborate a bit what archive you configured? IIRC we use Path type for archive path and it should not take file://  input

It was not the case in 2.11.1

This seems a new issue. cc @jiangpengcheng @cbornet as you work on functions related logics recently. Do you have any thoughts on this kind of exceptions?

Seems not a bug but usability to be improved.
No specific action and duplicate with the open-ended discussion https://github.com/apache/pulsar/discussions/20796.
Let's move the discussion there and spawn any concrete issue to improve.

authors: rob-kvietkauskas-ign tisonkun


text:
[Bug] Pulsar cluster occasionally experiences consumption timeout

Search before asking

[X] I searched in the issues and found nothing similar.

Version
os: CentOS Linux release 7.9.2009 (Core)
pulsar: 2.10.5
java: 1.8.0.162
Minimal reproduce step
Occasionally appearing, unable to reproduce
What did you expect to see?
Consumption completed in a short period of time
What did you see instead?
Occasionally, if the consumption exceeds the limit, it will take at least ten minutes or longer to complete the consumption
Anything else?
Pulsar Bookie Configuration
bookiePort=3181
journalDirectory=data/bookkeeper/journal
minUsableSizeForIndexFileCreation=1073741824
advertisedAddress=192.168.0.93
allowLoopback=false
bookieDeathWatchInterval=1000
flushInterval=60000
useHostNameAsBookieID=false
gcWaitTime=900000
gcOverreplicatedLedgerWaitTime=86400000
numAddWorkerThreads=0
numReadWorkerThreads=8
numHighPriorityWorkerThreads=8
maxPendingReadRequestsPerThread=2500
maxPendingAddRequestsPerThread=10000
readWorkerThreadsThrottlingEnabled=true
enableBusyWait=false
auditorPeriodicBookieCheckInterval=86400
rereplicationEntryBatchSize=100
openLedgerRereplicationGracePeriod=30000
autoRecoveryDaemonEnabled=true
lostBookieRecoveryDelay=0
useV2WireProtocol=true
reppDnsResolverClass=org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping
serverTcpNoDelay=true
nettyMaxFrameSizeBytes=5253120
journalFormatVersionToWrite=5
journalMaxSizeMB=2048
journalMaxBackups=5
journalPreAllocSizeMB=16
journalWriteBufferSizeKB=64
journalRemoveFromPageCache=true
journalWriteData=true
journalSyncData=true
journalAdaptiveGroupWrites=true
journalMaxGroupWaitMSec=1
journalBufferedWritesThreshold=524288
numJournalCallbackThreads=8
journalAlignmentSize=4096
journalFlushWhenQueueEmpty=false
ledgerStorageClass=org.apache.bookkeeper.bookie.storage.ldb.DbLedgerStorage
ledgerDirectories=data/bookkeeper/ledgers
auditorPeriodicCheckInterval=604800
openFileLimit=0
fileInfoFormatVersionToWrite=0
pageLimit=0
zkLedgersRootPath=/ledgers
logSizeLimit=1073741824
entryLogFilePreallocationEnabled=true
flushEntrylogBytes=268435456
readBufferSizeBytes=4096
writeBufferSizeBytes=65536
compactionRate=1000
minorCompactionThreshold=0.2
minorCompactionInterval=3600
compactionMaxOutstandingRequests=100000
majorCompactionThreshold=0.5
majorCompactionInterval=86400
isThrottleByBytes=false
compactionRateByEntries=1000
compactionRateByBytes=1000000
statsProviderClass=org.apache.bookkeeper.stats.prometheus.PrometheusMetricsProvider
prometheusStatsHttpPort=8100
readOnlyModeEnabled=true
diskUsageThreshold=0.95
diskCheckInterval=10000
metadataServiceUri=
zkServers=192.168.0.118:2181,192.168.0.93:2181,192.168.0.225:2181
zkTimeout=30000
zkEnableSecurity=false
httpServerEnabled=false
httpServerPort=8000
httpServerClass=org.apache.bookkeeper.http.vertx.VertxHttpServer
dbStorage_writeCacheMaxSizeMb=
dbStorage_readAheadCacheMaxSizeMb=
dbStorage_readAheadCacheBatchSize=1000
dbStorage_rocksDB_blockCacheSize=
dbStorage_rocksDB_writeBufferSizeMB=64
dbStorage_rocksDB_sstSizeInMB=64
dbStorage_rocksDB_blockSize=65536
dbStorage_rocksDB_bloomFilterBitsPerKey=10
dbStorage_rocksDB_numLevels=-1
dbStorage_rocksDB_numFilesInLevel0=4
dbStorage_rocksDB_maxSizeInLevel1MB=256

Pulsar broker configuration
metadataStoreUrl=192.168.0.118:2181,192.168.0.93:2181,192.168.0.225:2181
configurationMetadataStoreUrl=192.168.0.118:2181,192.168.0.93:2181,192.168.0.225:2181
brokerServicePort=6650
brokerServicePortTls=
webServicePort=8080
webServicePortTls=
webServiceTlsProtocols=
webServiceTlsCiphers=
bindAddress=0.0.0.0
bindAddresses=
advertisedAddress=192.168.0.93
haProxyProtocolEnabled=false
numAcceptorThreads=
numIOThreads=
numOrderedExecutorThreads=8
numHttpServerThreads=
numExecutorThreadPoolSize=
numCacheExecutorThreadPoolSize=10
enableBusyWait=false
maxConcurrentHttpRequests=1024
isRunningStandalone=
clusterName=pulsar-cluster
maxTenants=0
failureDomainsEnabled=false
metadataStoreSessionTimeoutMillis=30000
metadataStoreOperationTimeoutSeconds=30
metadataStoreCacheExpirySeconds=300
brokerShutdownTimeoutMs=60000
skipBrokerShutdownOnOOM=false
backlogQuotaCheckEnabled=true
backlogQuotaCheckIntervalInSeconds=60
backlogQuotaDefaultLimitBytes=-1
backlogQuotaDefaultLimitSecond=-1
backlogQuotaDefaultRetentionPolicy=producer_request_hold
ttlDurationDefaultInSeconds=0
allowAutoTopicCreation=true
allowAutoTopicCreationType=non-partitioned
allowAutoSubscriptionCreation=true
defaultNumPartitions=1
brokerDeleteInactiveTopicsEnabled=true
brokerDeleteInactiveTopicsFrequencySeconds=60
brokerDeleteInactiveTopicsMode=delete_when_no_subscriptions
brokerDeleteInactivePartitionedTopicMetadataEnabled=false
brokerDeleteInactiveTopicsMaxInactiveDurationSeconds=
forceDeleteTenantAllowed=false
forceDeleteNamespaceAllowed=false
maxPendingPublishRequestsPerConnection=1000
messageExpiryCheckIntervalInMinutes=5
activeConsumerFailoverDelayTimeMillis=1000
subscriptionExpirationTimeMinutes=0
subscriptionRedeliveryTrackerEnabled=true
subscriptionExpiryCheckIntervalInMinutes=5
subscriptionTypesEnabled=Exclusive,Shared,Failover,Key_Shared
subscriptionKeySharedUseConsistentHashing=true
subscriptionKeySharedConsistentHashingReplicaPoints=100
brokerDeduplicationEnabled=false
brokerDeduplicationMaxNumberOfProducers=10000
brokerDeduplicationSnapshotFrequencyInSeconds=120
brokerDeduplicationSnapshotIntervalSeconds=120
brokerDeduplicationEntriesInterval=1000
brokerDeduplicationProducerInactivityTimeoutMinutes=360
defaultNumberOfNamespaceBundles=4
maxNamespacesPerTenant=0
maxTopicsPerNamespace=0
brokerMaxConnections=0
brokerMaxConnectionsPerIp=0
isAllowAutoUpdateSchemaEnabled=true
clientLibraryVersionCheckEnabled=false
statusFilePath=
preferLaterVersions=false
maxUnackedMessagesPerConsumer=50000
maxUnackedMessagesPerSubscription=200000
maxUnackedMessagesPerBroker=0
maxUnackedMessagesPerSubscriptionOnBrokerBlocked=0.16
unblockStuckSubscriptionEnabled=false
topicPublisherThrottlingTickTimeMillis=10
preciseTopicPublishRateLimiterEnable=false
brokerPublisherThrottlingTickTimeMillis=50
brokerPublisherThrottlingMaxMessageRate=0
brokerPublisherThrottlingMaxByteRate=0
maxPublishRatePerTopicInMessages=0
maxPublishRatePerTopicInBytes=0
subscribeThrottlingRatePerConsumer=0
subscribeRatePeriodPerConsumerInSecond=30
dispatchThrottlingRateInMsg=0
dispatchThrottlingRateInByte=0
dispatchThrottlingRatePerTopicInMsg=0
dispatchThrottlingRatePerTopicInByte=0
dispatchThrottlingOnBatchMessageEnabled=false
dispatchThrottlingRatePerSubscriptionInMsg=0
dispatchThrottlingRatePerSubscriptionInByte=0
dispatchThrottlingRatePerReplicatorInMsg=0
dispatchThrottlingRatePerReplicatorInByte=0
dispatchThrottlingRateRelativeToPublishRate=false
dispatchThrottlingOnNonBacklogConsumerEnabled=true
dispatcherMaxReadBatchSize=100
dispatcherMaxReadSizeBytes=5242880
dispatcherMinReadBatchSize=1
dispatcherMaxRoundRobinBatchSize=20
dispatcherReadFailureBackoffInitialTimeInMs=15000
dispatcherReadFailureBackoffMaxTimeInMs=60000
dispatcherReadFailureBackoffMandatoryStopTimeInMs=0
preciseDispatcherFlowControl=false
entryFilterNames=
entryFiltersDirectory=
maxConcurrentLookupRequest=50000
maxConcurrentTopicLoadRequest=5000
maxConcurrentNonPersistentMessagePerConnection=1000
numWorkerThreadsForNonPersistentTopic=
enablePersistentTopics=true
enableNonPersistentTopics=true
enableRunBookieTogether=false
enableRunBookieAutoRecoveryTogether=false
maxProducersPerTopic=0
maxSameAddressProducersPerTopic=0
encryptionRequireOnProducer=false
maxConsumersPerTopic=0
maxSameAddressConsumersPerTopic=0
maxSubscriptionsPerTopic=0
maxConsumersPerSubscription=0
maxMessageSize=5242880
brokerServiceCompactionMonitorIntervalInSeconds=60
brokerServiceCompactionThresholdInBytes=0
brokerServiceCompactionPhaseOneLoopTimeInSeconds=30
delayedDeliveryEnabled=true
delayedDeliveryTickTimeMillis=1000
isDelayedDeliveryDeliverAtTimeStrict=false
delayedDeliveryFixedDelayDetectionLookahead=50000
acknowledgmentAtBatchIndexLevelEnabled=false
enableReplicatedSubscriptions=true
replicatedSubscriptionsSnapshotFrequencyMillis=1000
replicatedSubscriptionsSnapshotTimeoutSeconds=30
replicatedSubscriptionsSnapshotMaxCachedPerSubscription=10
maxMessagePublishBufferSizeInMB=
retentionCheckIntervalInSeconds=120
maxMessageSizeCheckIntervalInSeconds=60
maxNumPartitionsPerPartitionedTopic=0
zookeeperSessionExpiredPolicy=reconnect
systemTopicEnabled=false
systemTopicSchemaCompatibilityStrategy=ALWAYS_COMPATIBLE
topicLevelPoliciesEnabled=false
topicFencingTimeoutSeconds=0
proxyRoles=
authenticateOriginalAuthData=false
tlsCertRefreshCheckDurationSec=300
tlsCertificateFilePath=
tlsKeyFilePath=
tlsTrustCertsFilePath=
tlsAllowInsecureConnection=false
tlsHostnameVerificationEnabled=false
tlsProtocols=
tlsCiphers=
tlsRequireTrustedClientCertOnConnect=false
tlsProvider=
webServiceTlsProvider=Conscrypt
tlsEnabledWithKeyStore=false
tlsKeyStoreType=JKS
tlsKeyStore=
tlsKeyStorePassword=
tlsTrustStoreType=JKS
tlsTrustStore=
tlsTrustStorePassword=
brokerClientTlsEnabledWithKeyStore=false
brokerClientSslProvider=
brokerClientTlsTrustStoreType=JKS
brokerClientTlsTrustStore=
brokerClientTlsTrustStorePassword=
brokerClientTlsCiphers=
brokerClientTlsProtocols=
metadataStoreBatchingEnabled=true
metadataStoreBatchingMaxDelayMillis=5
metadataStoreBatchingMaxOperations=1000
metadataStoreBatchingMaxSizeKb=128
authenticationEnabled=false
authenticationProviders=
authenticationRefreshCheckSeconds=60
authorizationEnabled=false
authorizationProvider=org.apache.pulsar.broker.authorization.PulsarAuthorizationProvider
authorizationAllowWildcardsMatching=false
superUserRoles=
brokerClientTlsEnabled=false
brokerClientAuthenticationPlugin=
brokerClientAuthenticationParameters=
brokerClientTrustCertsFilePath=
athenzDomainNames=
anonymousUserRole=
basicAuthConf=
tokenSecretKey=
tokenPublicKey=
tokenAuthClaim=
tokenAudienceClaim=
tokenAudience=
saslJaasClientAllowedIds=.*pulsar.*
saslJaasServerSectionName=PulsarBroker
saslJaasServerRoleTokenSignerSecretPath=
httpMaxRequestSize=-1
disableHttpDebugMethods=false
httpRequestsLimitEnabled=false
httpRequestsMaxPerSecond=100.0
bookkeeperMetadataServiceUri=
bookkeeperClientAuthenticationPlugin=
bookkeeperClientAuthenticationParametersName=
bookkeeperClientAuthenticationParameters=
bookkeeperClientTimeoutInSeconds=30
bookkeeperClientNumWorkerThreads=
bookkeeperClientSpeculativeReadTimeoutInMillis=0
bookkeeperNumberOfChannelsPerBookie=16
bookkeeperUseV2WireProtocol=true
bookkeeperClientHealthCheckEnabled=true
bookkeeperClientHealthCheckIntervalSeconds=60
bookkeeperClientHealthCheckErrorThresholdPerInterval=5
bookkeeperClientHealthCheckQuarantineTimeInSeconds=1800
bookkeeperClientQuarantineRatio=1.0
bookkeeperClientGetBookieInfoIntervalSeconds=86400
bookkeeperClientGetBookieInfoRetryIntervalSeconds=60
bookkeeperClientRackawarePolicyEnabled=true
bookkeeperClientRegionawarePolicyEnabled=false
bookkeeperClientMinNumRacksPerWriteQuorum=2
bookkeeperClientEnforceMinNumRacksPerWriteQuorum=false
bookkeeperClientReorderReadSequenceEnabled=false
bookkeeperClientIsolationGroups=
bookkeeperClientSecondaryIsolationGroups=
bookkeeperClientMinAvailableBookiesInIsolationGroups=
bookkeeperEnableStickyReads=true
bookkeeperTLSProviderFactoryClass=org.apache.bookkeeper.tls.TLSContextFactory
bookkeeperTLSClientAuthentication=false
bookkeeperTLSKeyFileType=PEM
bookkeeperTLSTrustCertTypes=PEM
bookkeeperTLSKeyStorePasswordPath=
bookkeeperTLSTrustStorePasswordPath=
bookkeeperTLSKeyFilePath=
bookkeeperTLSCertificateFilePath=
bookkeeperTLSTrustCertsFilePath=
bookkeeperTlsCertFilesRefreshDurationSeconds=300
bookkeeper_tlsHostnameVerificationEnabled=false
bookkeeperDiskWeightBasedPlacementEnabled=false
bookkeeperExplicitLacIntervalInMills=0
managedLedgerDefaultEnsembleSize=2
managedLedgerDefaultWriteQuorum=2
managedLedgerDefaultAckQuorum=2
managedLedgerCursorPositionFlushSeconds=60
managedLedgerStatsPeriodSeconds=60
managedLedgerDigestType=CRC32C
managedLedgerNumWorkerThreads=
managedLedgerNumSchedulerThreads=
managedLedgerCacheSizeMB=
managedLedgerCacheCopyEntries=false
managedLedgerCacheEvictionWatermark=0.9
managedLedgerCacheEvictionIntervalMs=10
managedLedgerCacheEvictionTimeThresholdMillis=1000
managedLedgerCursorBackloggedThreshold=1000
managedLedgerDefaultMarkDeleteRateLimit=1.0
managedLedgerMaxEntriesPerLedger=50000
managedLedgerMinLedgerRolloverTimeMinutes=10
managedLedgerMaxLedgerRolloverTimeMinutes=240
managedLedgerInactiveLedgerRolloverTimeSeconds=0
managedLedgerMaxSizePerLedgerMbytes=2048
managedLedgerOffloadDeletionLagMs=14400000
managedLedgerOffloadAutoTriggerSizeThresholdBytes=-1
managedLedgerCursorMaxEntriesPerLedger=50000
managedLedgerCursorRolloverTimeInSeconds=14400
managedLedgerMaxUnackedRangesToPersist=10000
managedLedgerMaxUnackedRangesToPersistInZooKeeper=1000
autoSkipNonRecoverableData=false
lazyCursorRecovery=false
managedLedgerMetadataOperationsTimeoutSeconds=60
managedLedgerReadEntryTimeoutSeconds=0
managedLedgerAddEntryTimeoutSeconds=0
managedLedgerPrometheusStatsLatencyRolloverSeconds=60
managedLedgerTraceTaskExecution=true
managedLedgerNewEntriesCheckDelayInMillis=10
loadBalancerEnabled=true
loadBalancerReportUpdateThresholdPercentage=10
loadBalancerReportUpdateMinIntervalMillis=5000
loadBalancerReportUpdateMaxIntervalMinutes=15
loadBalancerHostUsageCheckIntervalMinutes=1
loadBalancerSheddingEnabled=true
loadBalancerSheddingIntervalMinutes=1
loadBalancerSheddingGracePeriodMinutes=30
loadBalancerBrokerMaxTopics=50000
loadBalancerBrokerOverloadedThresholdPercentage=85
loadBalancerResourceQuotaUpdateIntervalMinutes=15
loadBalancerAutoBundleSplitEnabled=true
loadBalancerAutoUnloadSplitBundlesEnabled=true
loadBalancerNamespaceBundleMaxTopics=1000
loadBalancerNamespaceBundleMaxSessions=1000
loadBalancerNamespaceBundleMaxMsgRate=30000
loadBalancerNamespaceBundleMaxBandwidthMbytes=100
loadBalancerNamespaceMaximumBundles=128
loadBalancerOverrideBrokerNicSpeedGbps=1000
loadManagerClassName=org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl
supportedNamespaceBundleSplitAlgorithms=range_equally_divide,topic_count_equally_divide
defaultNamespaceBundleSplitAlgorithm=range_equally_divide
loadBalancerLoadSheddingStrategy=org.apache.pulsar.broker.loadbalance.impl.ThresholdShedder
loadBalancerBrokerThresholdShedderPercentage=10
loadBalancerMsgRateDifferenceShedderThreshold=50
loadBalancerMsgThroughputMultiplierDifferenceShedderThreshold=4
loadBalancerHistoryResourcePercentage=0.9
loadBalancerBandwithInResourceWeight=1.0
loadBalancerBandwithOutResourceWeight=1.0
loadBalancerCPUResourceWeight=1.0
loadBalancerMemoryResourceWeight=1.0
loadBalancerDirectMemoryResourceWeight=1.0
loadBalancerBundleUnloadMinThroughputThreshold=10
namespaceBundleUnloadingTimeoutMs=60000
replicationMetricsEnabled=true
replicationConnectionsPerBroker=16
replicationProducerQueueSize=1000
replicatorPrefix=pulsar.repl
replicationPolicyCheckDurationSeconds=600
defaultRetentionTimeInMinutes=0
defaultRetentionSizeInMB=0
keepAliveIntervalSeconds=30
bootstrapNamespaces=
webSocketServiceEnabled=false
webSocketNumIoThreads=
webSocketConnectionsPerBroker=
webSocketSessionIdleTimeoutMillis=300000
webSocketMaxTextFrameSize=1048576
exposeTopicLevelMetricsInPrometheus=true
exposeConsumerLevelMetricsInPrometheus=false
exposeProducerLevelMetricsInPrometheus=false
exposeManagedLedgerMetricsInPrometheus=true
exposeManagedCursorMetricsInPrometheus=false
metricsServletTimeoutMs=30000
exposeBundlesMetricsInPrometheus=false
functionsWorkerEnabled=false
exposePublisherStats=true
statsUpdateFrequencyInSecs=60
statsUpdateInitialDelayInSecs=60
exposePreciseBacklogInPrometheus=false
splitTopicAndPartitionLabelInPrometheus=false
aggregatePublisherStatsByProducerName=false
schemaRegistryStorageClassName=org.apache.pulsar.broker.service.schema.BookkeeperSchemaStorageFactory
isSchemaValidationEnforced=false
schemaCompatibilityStrategy=FULL
offloadersDirectory=./offloaders
managedLedgerOffloadDriver=
managedLedgerOffloadMaxThreads=2
managedLedgerOffloadPrefetchRounds=1
managedLedgerUnackedRangesOpenCacheSetEnabled=true
s3ManagedLedgerOffloadRegion=
s3ManagedLedgerOffloadBucket=
s3ManagedLedgerOffloadServiceEndpoint=
s3ManagedLedgerOffloadMaxBlockSizeInBytes=67108864
s3ManagedLedgerOffloadReadBufferSizeInBytes=1048576
gcsManagedLedgerOffloadRegion=
gcsManagedLedgerOffloadBucket=
gcsManagedLedgerOffloadMaxBlockSizeInBytes=67108864
gcsManagedLedgerOffloadReadBufferSizeInBytes=1048576
gcsManagedLedgerOffloadServiceAccountKeyFile=
managedLedgerOffloadBucket=
fileSystemProfilePath=../conf/filesystem_offload_core_site.xml
fileSystemURI=
transactionCoordinatorEnabled=true
transactionMetadataStoreProviderClassName=org.apache.pulsar.transaction.coordinator.impl.MLTransactionMetadataStoreProvider
transactionBufferSnapshotMaxTransactionCount=1000
transactionBufferSnapshotMinTimeInMillis=5000
transactionBufferClientMaxConcurrentRequests=1000
transactionPendingAckLogIndexMinLag=500
enablePackagesManagement=false
packagesManagementStorageProvider=org.apache.pulsar.packages.management.storage.bookkeeper.BookKeeperPackagesStorageProvider
packagesReplicas=1
packagesManagementLedgerRootPath=/ledgers
zookeeperServers=
globalZookeeperServers=
configurationStoreServers=
zooKeeperSessionTimeoutMillis=-1
zooKeeperOperationTimeoutSeconds=-1
zooKeeperCacheExpirySeconds=-1
replicationTlsEnabled=false
brokerServicePurgeInactiveFrequencyInSeconds=60
backlogQuotaDefaultLimitGB=-1
tlsEnabled=false
subscriptionKeySharedEnable=true
managedLedgerCacheEvictionFrequency=0

log
2024-01-04T02:00:46,565+0800 [pulsar-load-manager-1-1] INFO  org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Writing local data to metadata store because maximum change Infinity% exceeded threshold 10%; time since last report written is 805.0 seconds
2024-01-04T02:00:46,573+0800 [metadata-store-18-1] INFO  org.apache.pulsar.metadata.coordination.impl.ResourceLockImpl - Acquired resource lock on /loadbalance/brokers/192.168.0.93:8080
2024-01-04T02:00:53,886+0800 [pulsar-io-12-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 192.168.0.225:3181 [id: 0xfa258099, L:/192.168.0.93:59510 - R:192.168.0.225/192.168.0.225:3181]
2024-01-04T02:00:53,886+0800 [pulsar-io-12-8] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0xfa258099, L:/192.168.0.93:59510 - R:192.168.0.225/192.168.0.225:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
2024-01-04T02:00:53,886+0800 [pulsar-io-12-9] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 192.168.0.118:3181 [id: 0x1d13839d, L:/192.168.0.93:46096 - R:192.168.0.118/192.168.0.118:3181]
2024-01-04T02:00:53,886+0800 [pulsar-io-12-9] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x1d13839d, L:/192.168.0.93:46096 - R:192.168.0.118/192.168.0.118:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
2024-01-04T02:01:00,528+0800 [pulsar-io-12-10] INFO  org.apache.pulsar.broker.service.ServerCnx - New connection from /192.168.0.69:32992
2024-01-04T02:01:00,529+0800 [pulsar-io-12-10] INFO  org.apache.pulsar.broker.service.ServerCnx - Closed connection from /192.168.0.69:32992
2024-01-04T02:01:04,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 2 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:04,785+0800 [BookKeeperClientWorker-OrderedExecutor-6-0] WARN  org.apache.bookkeeper.client.PendingAddOp - Failed to write entry (1934, 9) to bookie (0, 192.168.0.225:3181): Bookie operation timeout
2024-01-04T02:01:04,785+0800 [BookKeeperClientWorker-OrderedExecutor-6-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - replaceBookie for bookie: 192.168.0.225:3181 in ensemble: [192.168.0.225:3181, 192.168.0.93:3181] is not adhering to placement policy and chose 192.168.0.118:3181. excludedBookies [192.168.0.225:3181] and quarantinedBookies []
2024-01-04T02:01:04,786+0800 [BookKeeperClientWorker-OrderedExecutor-6-0] WARN  org.apache.bookkeeper.client.PendingAddOp - Failed to write entry (1934, 10) to bookie (0, 192.168.0.225:3181): Bookie operation timeout
2024-01-04T02:01:04,790+0800 [BookKeeperClientWorker-OrderedExecutor-6-0] INFO  org.apache.bookkeeper.client.LedgerHandle - New Ensemble: [192.168.0.118:3181, 192.168.0.93:3181] for ledger: 1934
2024-01-04T02:01:04,791+0800 [pulsar-io-12-11] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 192.168.0.118:3181 [id: 0x6e05db2a, L:/192.168.0.93:46106 - R:192.168.0.118/192.168.0.118:3181]
2024-01-04T02:01:04,791+0800 [pulsar-io-12-11] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x6e05db2a, L:/192.168.0.93:46106 - R:192.168.0.118/192.168.0.118:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
2024-01-04T02:01:05,123+0800 [BookKeeperClientWorker-OrderedExecutor-6-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/default/persistent/notify-partition-0] Creating ledger, metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114], pulsar/managed-ledger=[112, 117, 98, 108, 105, 99, 47, 100, 101, 102, 97, 117, 108, 116, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 105, 114, 101, 115, 116, 45, 112, 97, 121, 45, 110, 111, 116, 105, 102, 121, 45, 112, 97, 114, 116, 105, 116, 105, 111, 110, 45, 48], pulsar/cursor=[71, 73, 68, 95, 73, 82, 69, 83, 84, 95, 80, 65, 89, 95, 78, 79, 84, 73, 70, 89], application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
2024-01-04T02:01:05,123+0800 [BookKeeperClientWorker-OrderedExecutor-6-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [192.168.0.225:3181, 192.168.0.93:3181] is not adhering to Placement Policy. quarantinedBookies: []
2024-01-04T02:01:05,134+0800 [metadata-store-18-1] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [192.168.0.225:3181, 192.168.0.93:3181] for ledger: 1949
2024-01-04T02:01:05,136+0800 [pulsar-io-12-12] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 192.168.0.225:3181 [id: 0xd1bde98a, L:/192.168.0.93:59524 - R:192.168.0.225/192.168.0.225:3181]
2024-01-04T02:01:05,136+0800 [pulsar-io-12-12] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0xd1bde98a, L:/192.168.0.93:59524 - R:192.168.0.225/192.168.0.225:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
2024-01-04T02:01:05,141+0800 [BookKeeperClientWorker-OrderedExecutor-5-0] INFO  org.apache.bookkeeper.mledger.impl.MetaStoreImpl - [public/default/persistent/notify-partition-0] [GID_IREST_PAY_NOTIFY] Updating cursor info ledgerId=1949 mark-delete=1946:101
2024-01-04T02:01:05,144+0800 [bookkeeper-ml-scheduler-OrderedScheduler-2-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/default/persistent/notify-partition-0] Updated cursor GID_IREST_PAY_NOTIFY with ledger id 1949 md-position=1946:101 rd-position=1946:102
2024-01-04T02:01:05,149+0800 [BookKeeperClientWorker-OrderedExecutor-6-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedCursorImpl - [public/default/persistent/notify-partition-0][GID_IREST_PAY_NOTIFY] Successfully closed & deleted ledger 1934 in cursor
2024-01-04T02:01:05,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:06,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:07,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:08,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:09,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:10,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:11,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:12,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:13,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:14,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:15,529+0800 [pulsar-io-12-13] INFO  org.apache.pulsar.broker.service.ServerCnx - New connection from /192.168.0.69:33082
2024-01-04T02:01:15,529+0800 [pulsar-io-12-13] INFO  org.apache.pulsar.broker.service.ServerCnx - Closed connection from /192.168.0.69:33082
2024-01-04T02:01:15,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:16,731+0800 [pulsar-web-44-5] INFO  org.eclipse.jetty.server.RequestLog - 192.168.0.118 - - [04/Jan/2024:02:01:16 +0800] "GET /admin/v2/broker-stats/topics HTTP/1.1" 200 14951 "-" "Pulsar-Java-v2.7.0" 0
2024-01-04T02:01:16,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:17,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:18,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:19,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:20,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:21,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:22,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:23,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:24,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:24,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0xfbfdce5d, L:/192.168.0.93:39530 - R:192.168.0.118/192.168.0.118:3181] for 192.168.0.118:3181
2024-01-04T02:01:24,785+0800 [BookKeeperClientWorker-OrderedExecutor-7-0] WARN  org.apache.bookkeeper.client.PendingAddOp - Failed to write entry (1935, 20) to bookie (1, 192.168.0.118:3181): Bookie operation timeout
2024-01-04T02:01:24,785+0800 [BookKeeperClientWorker-OrderedExecutor-7-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - replaceBookie for bookie: 192.168.0.118:3181 in ensemble: [192.168.0.93:3181, 192.168.0.118:3181] is not adhering to placement policy and chose 192.168.0.225:3181. excludedBookies [192.168.0.118:3181] and quarantinedBookies []
2024-01-04T02:01:24,790+0800 [BookKeeperClientWorker-OrderedExecutor-7-0] INFO  org.apache.bookkeeper.client.LedgerHandle - New Ensemble: [192.168.0.93:3181, 192.168.0.225:3181] for ledger: 1935
2024-01-04T02:01:24,791+0800 [pulsar-io-12-14] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Successfully connected to bookie: 192.168.0.225:3181 [id: 0x4bb3e46f, L:/192.168.0.93:59542 - R:192.168.0.225/192.168.0.225:3181]
2024-01-04T02:01:24,791+0800 [pulsar-io-12-14] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - connection [id: 0x4bb3e46f, L:/192.168.0.93:59542 - R:192.168.0.225/192.168.0.225:3181] authenticated as BookKeeperPrincipal{ANONYMOUS}
2024-01-04T02:01:24,797+0800 [BookKeeperClientWorker-OrderedExecutor-7-0] INFO  org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl - [public/default/persistent/miniprogram-partition-0] Creating ledger, metadata: {component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114], pulsar/managed-ledger=[112, 117, 98, 108, 105, 99, 47, 100, 101, 102, 97, 117, 108, 116, 47, 112, 101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 105, 114, 101, 115, 116, 45, 109, 101, 115, 115, 97, 103, 101, 45, 119, 101, 99, 104, 97, 116, 45, 109, 105, 110, 105, 112, 114, 111, 103, 114, 97, 109, 45, 112, 97, 114, 116, 105, 116, 105, 111, 110, 45, 48], pulsar/cursor=[73, 82, 69, 83, 84, 95, 77, 69, 83, 83, 65, 71, 69, 95, 77, 73, 78, 73, 95, 80, 82, 79, 71, 82, 65, 77, 95, 67, 79, 78, 83, 85, 77, 69, 82], application=[112, 117, 108, 115, 97, 114]} - metadata ops timeout : 60 seconds
2024-01-04T02:01:24,797+0800 [BookKeeperClientWorker-OrderedExecutor-7-0] WARN  org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble: [192.168.0.225:3181, 192.168.0.118:3181] is not adhering to Placement Policy. quarantinedBookies: []
2024-01-04T02:01:24,804+0800 [metadata-store-18-1] INFO  org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [192.168.0.225:3181, 192.168.0.118:3181] for ledger: 1950
2024-01-04T02:01:25,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8b8f80a8, L:/192.168.0.93:52952 - R:192.168.0.225/192.168.0.225:3181] for 192.168.0.225:3181
2024-01-04T02:01:25,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0xfbfdce5d, L:/192.168.0.93:39530 - R:192.168.0.118/192.168.0.118:3181] for 192.168.0.118:3181
2024-01-04T02:01:26,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 2 operations to channel [id: 0xfbfdce5d, L:/192.168.0.93:39530 - R:192.168.0.118/192.168.0.118:3181] for 192.168.0.118:3181
2024-01-04T02:01:28,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0xfbfdce5d, L:/192.168.0.93:39530 - R:192.168.0.118/192.168.0.118:3181] for 192.168.0.118:3181
2024-01-04T02:01:29,785+0800 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO  org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0xfbfdce5d, L:/192.168.0.93:39530 - R:192.168.0.118/192.168.0.118:3181] for 192.168.0.118:3181
2024-01-04T02:01:30,529+0800 [pulsar-io-12-15] INFO  org.apache.pulsar.broker.service.ServerCnx - New connection from /192.168.0.69:33172
2024-01-04T02:01:30,529+0800 [pulsar-io-12-15] INFO  org.apache.pulsar.broker.service.ServerCnx - Closed connection from /192.168.0.69:33172

Attempted to update to version 3.2.0, but failed to resolve the issue
Are you willing to submit a PR?

[ ] I'm willing to submit a PR!

@lhotari Could you please help me?

source: gharchive/issue

repo: apache/pulsar

license_type: permissive

license_source: github-api


text:
Fix ConsumerBuilderImpl#subscribeAsync blocks calling thread.

Fixes #14413
Motivation
When Retry topics are enabled, ConsumerBuilderImpl performs a backwards-compatibility check to look for DLQ or Retry topics that were created on previous version of Pulsar using a different naming scheme.
It does this by calling getPartitionedTopicMetadata and then using .get() to block while waiting for the results
if (client.getPartitionedTopicMetadata(oldRetryLetterTopic)
        .get(client.conf.getOperationTimeoutMs(), TimeUnit.MILLISECONDS).partitions > 0) {
    retryLetterTopic = oldRetryLetterTopic;
}
if (client.getPartitionedTopicMetadata(oldDeadLetterTopic)
        .get(client.conf.getOperationTimeoutMs(), TimeUnit.MILLISECONDS).partitions > 0) {
    deadLetterTopic = oldDeadLetterTopic;
}

This was implemented in https://github.com/apache/pulsar/pull/10129
A partial fix to add a Timeout was implemented in https://github.com/apache/pulsar/pull/11597
However this fix does still block the calling thread during the lookup.
This can be an issue for code that attempt to call subscribeAsync on a non-blocking Pool (such as when using Netty). The signature of subscribeAsync implies that it's non-blocking. (And it seems somewhat pointless to have subscribeAsync if it blocks anyway)
Note that this is an undocumented breaking change in behavior. Up until 2.9, it was safe to call this from a non-blocking pool.
In our case, we were running a custom SLF4J log exporter on the same thread pool, which resulted in a deadlock when the number of concurrent subscribeAsync calls exceeded the pool size. (This is probably an extreme example and a poor decision on our part, but perhaps a good example of why unexpected blocking can be dangerous)
Note that blocking call is still made even if the retry and DLQ names are explicitly specified in DeadLetterPolicy. In that scenario the check should not be needed. Aside from blocking the calling Thread, this also results in unneeded lookup requests.
Modifications

Make retry and DLQ metadata async.

Documentation

[x] no-need-doc

I wonder if it's possible that we can add some kind of client version check to avoid this compatibility check?

Perhaps a flag on DeadLetterPolicy that checks for legacy topics. Enabled by default for compatibility, but can be disabled to avoid the performance overhead?
DeadLetterPolicy.builder().checkForLegacyTopics(false)

I wonder if it's possible that we can add some kind of client version check to avoid this compatibility check?

Perhaps a flag on DeadLetterPolicy that checks for legacy topics. Enabled by default for compatibility, but can be disabled to avoid the performance overhead?
DeadLetterPolicy.builder().checkForLegacyTopics(false)

Yes, we can open a new issue for discussing.

@Jason918 @codelipenghui @gaoran10 @mattisonchao
Could you please help review again?

source: gharchive/pull-request

authors: Technoboy- jimmydivvy


text:
add metric for InMemoryDelayedDeliveryTracker's memory usage

Motivation
Provide namespace level and topic level metric for InMemoryDelayedDeliveryTracker's memory usage.
Documentation
Check the box below or label this PR directly.
Need to update docs?

[x] doc-required
(Your PR needs to update docs and you will update later)

[ ] doc-not-needed
(Please explain why)

[ ] doc
(Your PR contains doc changes)

[ ] doc-complete
(Docs have been already added)

Tests to be completed.

/pulsarbot run-failure-checks

/pulsarbot run-failure-checks

@codelipenghui  PTAL

/pulsarbot run-failure-checks

/pulsarbot run-failure-checks

@tjiuming Please check @Shoothzj 's comments

/pulsarbot run-failure-checks

/pulsarbot run-failure-checks

/pulsarbot run-failure-checks

/pulsarbot run-failure-checks

@codelipenghui All CI checks passed, PTAL

authors: codelipenghui tjiuming


text:
[fix][broker]fix bug: fail to expose managed ledger client stats to prometheus if bookkeeperClientExposeStatsToPrometheus is true

Motivation
It failed to expose bookkeeper client managed ledger stats to prometheus if setting bookkeeperClientExposeStatsToPrometheus=true in ServiceConfiguration. Because creating BkClient ignore the StatsLogger and use the NullStatsLogger.INSTANCE as default.
//class: org.apache.pulsar.broker.BookKeeperClientFactoryImpl
    @Override
    public BookKeeper create(ServiceConfiguration conf, ZooKeeper zkClient, EventLoopGroup eventLoopGroup,
                             Optional<Class<? extends EnsemblePlacementPolicy>> ensemblePlacementPolicyClass,
                             Map<String, Object> properties) throws IOException {
        return create(conf, zkClient, eventLoopGroup, ensemblePlacementPolicyClass, properties,
                NullStatsLogger.INSTANCE);
    }

Modifications
Add StatsLogger into BookKeeperClientFactory when creating BkClient.
The screenshot below is the result of my verification.

Verifying this change

[x]  Make sure that the change passes the CI checks.

This change is a trivial rework / code cleanup without any test coverage.
Does this pull request potentially affect one of the following parts:
If yes was chosen, please highlight the changes

Dependencies (does it add or upgrade a dependency): (no)
The public API: (no)
The schema: (no)
The default values of configurations: (no)
The wire protocol: (no)
The rest endpoints: (no)
The admin cli options: (no)
Anything that affects deployment: (no)

Documentation
Check the box below and label this PR (if you have committer privilege).
Need to update docs?

[x] doc-not-needed

/pulsarbot rerun-failure-checks

@HQebupt Please help add a test to make sure the issue will not comeback. Thanks.

It is hard to add a unit test due to there is two kinds of new BookKeeper client instance.

/pulsarbot rerun-failure-checks

/pulsarbot rerun-failure-checks

/pulsarbot rerun-failure-checks

Hi, @HQebupt
It looks like we have some conflict on branch-2.9. Could you please help to cherry-pick or push a new PR for it?

cherry-pick https://github.com/apache/pulsar/pull/16343 to branch-2.8 instead.

authors: BewareMyPower HQebupt mattisonchao


text:
[improve][broker] Optimize and clean up aggregation of topic stats

Motivation

getPublishers method gets called twice for every single publisher when aggregating topic stats in the add method of TopicStatsImpl:

https://github.com/apache/pulsar/blob/1a352f178590a210a9200dfee135089155c2f168/pulsar-common/src/main/java/org/apache/pulsar/common/policies/data/stats/TopicStatsImpl.java#L262-L263
This is a slight problem since getPublishers method is fairly costly and causes unnecessary garbage:
https://github.com/apache/pulsar/blob/1a352f178590a210a9200dfee135089155c2f168/pulsar-common/src/main/java/org/apache/pulsar/common/policies/data/stats/TopicStatsImpl.java#L152-L158

The code for aggregating subscription and replication stats is unnecessarily complex.

Modifications

extract a variable before the loop to eliminate the problem mentioned above.
refactor the code for aggregating subscription and replication stats

Documentation

[ ] doc
[ ] doc-required
[x] doc-not-needed
[ ] doc-complete

Can we also cache the sorted publisher list? It seems unnecessary to sort the same list repeatedly.

Codecov Report

Merging #21361 (49d31a8) into master (1a352f1) will increase coverage by 39.30%.
Report is 1 commits behind head on master.
The diff coverage is 80.00%.

@@              Coverage Diff              @@
##             master   #21361       +/-   ##
=============================================
+ Coverage     33.49%   72.79%   +39.30%
- Complexity    12257    32513    +20256
=============================================
  Files          1636     1876      +240
  Lines        127789   140066    +12277
  Branches      13963    15422     +1459
=============================================
+ Hits          42798   101961    +59163
+ Misses        79372    30026    -49346
- Partials       5619     8079     +2460

Flag
Coverage Δ

inttests
24.21% <0.00%> (+0.06%)
:arrow_up:

unittests
72.55% <80.00%> (+40.54%)
:arrow_up:

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

Files
Coverage Δ

...sar/common/policies/data/stats/TopicStatsImpl.java
94.70% <100.00%> (+41.90%)
:arrow_up:

...licies/data/stats/NonPersistentTopicStatsImpl.java
83.78% <62.50%> (+72.54%)
:arrow_up:

... and 1502 files with indirect coverage changes

Can we also cache the sorted publisher list? It seems unnecessary to sort the same list repeatedly.

One possibility is to eliminate the getPublishers method. It looks like it doesn't make much sense at the moment. That could be refactored in another PR.

authors: codecov-commenter heesung-sn lhotari


text:
[C++] Catch exception thrown by remote_endpoint

Motivation
Boost asio socket::remote_point may throw boost::system::system_error on failure. If the C++ client library was compiled with some low version boost, like 1.54, even if async_connect success, the server could still be unreachable and an exception would be thrown by socket_->remote_endpoint().
Modifications

Catch the exception for  socket_->remote_endpoint()
Add tests for when client connects to a unreachable service url
Fix header dependency because some boost *.hpp file doesn't include assert.h

Verifying this change

[ ] Make sure that the change passes the CI checks.

This change added tests and can be verified as follows:

Run testServerConnectError.

/pulsarbot run-failure-checks

/pulsarbot run-failure-checks

/pulsarbot run-failure-checks

cherry-picked to branch-2.6

authors: BewareMyPower codelipenghui jiazhai