michaeljmarshall commented on issue #9450:
URL: https://github.com/apache/pulsar/issues/9450#issuecomment-777983886
These are the logs (and possibly a little extra) from the pulsar cluster
(out of surefire reports) for a failed `testResetCursorNotFail`. I haven't been
able to narrow in on the problem yet.
```
------- Starting test [TestClass name=class
org.apache.pulsar.broker.service.ReplicatorTest].testResetCursorNotFail([])-------
04:50:59.325 [TestNG-method=testResetCursorNotFail-1] INFO
org.apache.pulsar.broker.service.ReplicatorTest - --- Starting
ReplicatorTest::testResetCursorNotFail ---
04:50:59.325 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerFactoryImpl -
[pulsar/partitionedNs-false/persistent/dummyTopic] Successfully initialize
managed ledger
04:50:59.325 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.AbstractTopic - Disabling publish throttling
for persistent://pulsar/partitionedNs-false/dummyTopic
04:50:59.326 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN
org.apache.pulsar.broker.service.BrokerService - Topic level policies are not
enabled. Please refer to systemTopicEnabled and topicLevelPoliciesEnabled on
broker.conf
04:50:59.326 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://pulsar/partitionedNs-false/dummyTopic] There are no replicated
subscriptions on the topic
04:50:59.326 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://pulsar/partitionedNs-false/dummyTopic] Starting replicator to
remote: r1
04:51:00.427 [SyncThread-87-1] INFO
org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log
file because current active log channel has not initialized yet
04:51:00.433 [SyncThread-87-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk0test7266224708557895544/current/0.log for logId 0.
04:51:00.451 [pool-47-thread-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk0test7266224708557895544/current/1.log for logId 1.
04:51:00.456 [db-storage-cleanup-90-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes
for ledgers: [32, 34, 36, 38, 39, 40, 41, 12, 15, 17, 18, 19, 20, 24, 26, 27,
28, 30, 31]
04:51:00.460 [db-storage-cleanup-90-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes
for 38 entries from 19 ledgers in 0.004 seconds
04:51:00.825 [SyncThread-97-1] INFO
org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log
file because current active log channel has not initialized yet
04:51:00.825 [SyncThread-97-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk1test4008531672981107329/current/0.log for logId 0.
04:51:00.835 [pool-53-thread-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk1test4008531672981107329/current/1.log for logId 1.
04:51:00.848 [db-storage-cleanup-100-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes
for ledgers: [33, 35, 36, 37, 38, 39, 40, 41, 13, 14, 16, 17, 18, 19, 21, 22,
23, 24, 25, 27, 29]
04:51:00.853 [db-storage-cleanup-100-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes
for 42 entries from 21 ledgers in 0.004 seconds
04:51:01.218 [SyncThread-107-1] INFO
org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log
file because current active log channel has not initialized yet
04:51:01.221 [SyncThread-107-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk2test5422802886547866332/current/0.log for logId 0.
04:51:01.230 [pool-59-thread-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk2test5422802886547866332/current/1.log for logId 1.
04:51:01.239 [db-storage-cleanup-110-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes
for ledgers: [32, 33, 34, 35, 37, 12, 13, 14, 15, 16, 20, 21, 22, 23, 25, 26,
28, 29, 30, 31]
04:51:01.243 [db-storage-cleanup-110-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes
for 40 entries from 20 ledgers in 0.004 seconds
04:51:01.291 [pulsar-io-59-2] ERROR
org.apache.pulsar.broker.service.persistent.PersistentReplicator -
[PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1
-> r2] Error reading entries at null. Retrying to read in 3.746s. (We can only
have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a
single waiting callback
04:51:04.211 [pulsar-load-manager-113-1] INFO
org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Only 1
broker available: no load shedding will be performed
04:51:04.302 [pulsar-load-manager-113-1] INFO
org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Writing
local data to ZooKeeper because maximum change Infinity% exceeded threshold
10%; time since last report written is 54.955 seconds
04:51:04.310 [pulsar-ordered-OrderedExecutor-2-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x100002f6a530005 local:/127.0.0.1:50956
remoteserver:localhost/127.0.0.1:45671 lastZxid:885 xid:810 sent:810 recv:932
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/loadbalance/brokers/localhost:36981
04:51:04.601 [SyncThread-167-1] INFO
org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log
file because current active log channel has not initialized yet
04:51:04.602 [SyncThread-167-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk0test7520240603864159631/current/0.log for logId 0.
04:51:04.609 [pool-87-thread-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk0test7520240603864159631/current/1.log for logId 1.
04:51:04.620 [db-storage-cleanup-170-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes
for ledgers: [32, 3, 4, 5, 9, 12, 13, 14, 15, 16, 18, 22, 23, 24, 25, 26, 27,
29]
04:51:04.624 [db-storage-cleanup-170-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes
for 36 entries from 18 ledgers in 0.003 seconds
04:51:04.997 [SyncThread-177-1] INFO
org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log
file because current active log channel has not initialized yet
04:51:04.999 [SyncThread-177-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk1test4511514577938667183/current/0.log for logId 0.
04:51:05.010 [pool-93-thread-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk1test4511514577938667183/current/1.log for logId 1.
04:51:05.012 [db-storage-cleanup-180-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes
for ledgers: [3, 6, 7, 8, 9, 10, 11, 13, 14, 16, 17, 18, 19, 20, 22, 25, 26,
27, 28, 29, 30, 31]
04:51:05.017 [db-storage-cleanup-180-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes
for 44 entries from 22 ledgers in 0.004 seconds
04:51:05.038 [pulsar-io-59-3] ERROR
org.apache.pulsar.broker.service.persistent.PersistentReplicator -
[PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1
-> r2] Error reading entries at null. Retrying to read in 7.413s. (We can only
have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a
single waiting callback
04:51:05.370 [SyncThread-187-1] INFO
org.apache.bookkeeper.bookie.EntryLogManagerBase - Creating a new entry log
file because current active log channel has not initialized yet
04:51:05.370 [SyncThread-187-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk2test4463933633007020671/current/0.log for logId 0.
04:51:05.382 [pool-99-thread-1] INFO
org.apache.bookkeeper.bookie.EntryLoggerAllocator - Created new entry log file
/tmp/bk2test4463933633007020671/current/1.log for logId 1.
04:51:05.389 [db-storage-cleanup-190-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleting indexes
for ledgers: [32, 4, 5, 6, 7, 8, 10, 11, 12, 15, 17, 19, 20, 23, 24, 28, 30, 31]
04:51:05.394 [db-storage-cleanup-190-1] INFO
org.apache.bookkeeper.bookie.storage.ldb.EntryLocationIndex - Deleted indexes
for 36 entries from 18 ledgers in 0.004 seconds
04:51:08.223 [pulsar-load-manager-193-1] INFO
org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Only 1
broker available: no load shedding will be performed
04:51:08.300 [pulsar-load-manager-193-1] INFO
org.apache.pulsar.broker.loadbalance.impl.ModularLoadManagerImpl - Writing
local data to ZooKeeper because maximum change Infinity% exceeded threshold
10%; time since last report written is 54.958 seconds
04:51:08.306 [pulsar-ordered-OrderedExecutor-4-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x100002f7a8c0005 local:/127.0.0.1:48342
remoteserver:localhost/127.0.0.1:46567 lastZxid:820 xid:763 sent:763 recv:872
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/loadbalance/brokers/localhost:38401
04:51:12.451 [pulsar-io-59-4] ERROR
org.apache.pulsar.broker.service.persistent.PersistentReplicator -
[PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1
-> r2] Error reading entries at null. Retrying to read in 15.35s. (We can only
have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a
single waiting callback
04:51:27.781 [pulsar-io-59-1] ERROR
org.apache.pulsar.broker.service.persistent.PersistentReplicator -
[PersistentTopic{topic=persistent://pulsar/ns/clearBacklogTopic-1613105457814}][r1
-> r2] Error reading entries at null. Retrying to read in 31.735s. (We can
only have a single waiting callback)
org.apache.bookkeeper.mledger.ManagedLedgerException: We can only have a
single waiting callback
04:51:29.259 [pulsar-io-139-4] WARN
org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify
partitioned topic
non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false-null
04:51:29.260 [pulsar-io-139-4] INFO
org.apache.pulsar.broker.service.AbstractReplicator -
[non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false][r2
-> r3] Starting replicator
04:51:29.260 [pulsar-io-139-4] INFO
org.apache.pulsar.broker.service.nonpersistent.NonPersistentTopic -
[non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false]
Starting replicator to remote: r1
04:51:29.264 [pulsar-io-219-2] WARN
org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify
partitioned topic
non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false-null
04:51:29.264 [pulsar-io-219-2] INFO
org.apache.pulsar.broker.service.AbstractReplicator -
[non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false][r3
-> r1] Starting replicator
04:51:29.264 [pulsar-io-219-2] INFO
org.apache.pulsar.broker.service.BrokerService - Created topic
NonPersistentTopic{topic=non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false}
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN
org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify
partitioned topic persistent://pulsar/partitionedNs-false/dummyTopic-null
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.AbstractReplicator -
[persistent://pulsar/partitionedNs-false/dummyTopic][r2 -> r1] Starting
replicator
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.persistent.PersistentReplicator -
[persistent://pulsar/partitionedNs-false/dummyTopic][r2 -> r1] Starting open
cursor for replicator
04:51:29.272 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[pulsar/partitionedNs-false/persistent/dummyTopic] Cursor pulsar.repl.r1
recovered to position 155:-1
04:51:29.273 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[pulsar/partitionedNs-false/persistent/dummyTopic] Creating ledger, metadata:
{component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114],
pulsar/managed-ledger=[112, 117, 108, 115, 97, 114, 47, 112, 97, 114, 116, 105,
116, 105, 111, 110, 101, 100, 78, 115, 45, 102, 97, 108, 115, 101, 47, 112,
101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 100, 117, 109, 109, 121, 84,
111, 112, 105, 99], pulsar/cursor=[112, 117, 108, 115, 97, 114, 46, 114, 101,
112, 108, 46, 114, 49], application=[112, 117, 108, 115, 97, 114]} - metadata
ops timeout : 60 seconds
04:51:29.273 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN
org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[172.17.0.2:37467, 172.17.0.2:40707] is not adhering to Placement Policy.
quarantinedBookies: []
04:51:29.271 [pulsar-io-59-1] WARN
org.apache.pulsar.client.impl.BinaryProtoLookupService -
[persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false] failed
to get Partitioned metadata : 145 lookup request timedout after ms 30000
org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 145
lookup request timedout after ms 30000
at
org.apache.pulsar.client.impl.ClientCnx.lambda$addPendingLookupRequests$8(ClientCnx.java:617)
~[pulsar-client-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
[netty-transport-native-epoll-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:51:29.271 [pulsar-io-59-4] WARN
org.apache.pulsar.client.impl.BinaryProtoLookupService -
[persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false] failed
to get Partitioned metadata : 184 lookup request timedout after ms 30000
org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 184
lookup request timedout after ms 30000
at
org.apache.pulsar.client.impl.ClientCnx.lambda$addPendingLookupRequests$8(ClientCnx.java:617)
~[pulsar-client-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
[netty-transport-native-epoll-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:51:29.274 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://pulsar/partitionedNs-false/dummyTopic] Starting replicator to
remote: r3
04:51:29.290 [TestNG-method=setup-1-EventThread] INFO
org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [172.17.0.2:37467,
172.17.0.2:40707] for ledger: 156
04:51:29.292 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO
org.apache.bookkeeper.mledger.impl.MetaStoreImpl -
[pulsar/partitionedNs-false/persistent/dummyTopic] [pulsar.repl.r1] Updating
cursor info ledgerId=156 mark-delete=155:-1
04:51:29.279 [pulsar-io-219-2] WARN
org.apache.pulsar.client.impl.BinaryProtoLookupService -
[non-persistent://pulsar/partitionedNs-false/partTopic-1613105459006-false]
failed to get Partitioned metadata : 139 lookup request timedout after ms 30000
org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 139
lookup request timedout after ms 30000
at
org.apache.pulsar.client.impl.ClientCnx.lambda$addPendingLookupRequests$8(ClientCnx.java:617)
~[pulsar-client-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:170)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:384)
[netty-transport-native-epoll-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at
io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
[netty-common-4.1.51.Final.jar:4.1.51.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
04:51:29.306 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN
org.apache.pulsar.broker.service.AbstractReplicator - Failed to verify
partitioned topic persistent://pulsar/partitionedNs-false/dummyTopic-null
04:51:29.306 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.AbstractReplicator -
[persistent://pulsar/partitionedNs-false/dummyTopic][r3 -> r1] Starting
replicator
04:51:29.306 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.persistent.PersistentReplicator -
[persistent://pulsar/partitionedNs-false/dummyTopic][r3 -> r1] Starting open
cursor for replicator
~~~~~~~~~ SKIPPED -- [TestClass name=class
org.apache.pulsar.broker.service.ReplicatorTest].testResetCursorNotFail([])-------04:51:29.306
[bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.bookkeeper.mledger.impl.ManagedCursorImpl -
[pulsar/partitionedNs-false/persistent/dummyTopic] Cursor pulsar.repl.r1
recovered to position 142:-1
04:51:29.307 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.bookkeeper.mledger.impl.ManagedLedgerImpl -
[pulsar/partitionedNs-false/persistent/dummyTopic] Creating ledger, metadata:
{component=[109, 97, 110, 97, 103, 101, 100, 45, 108, 101, 100, 103, 101, 114],
pulsar/managed-ledger=[112, 117, 108, 115, 97, 114, 47, 112, 97, 114, 116, 105,
116, 105, 111, 110, 101, 100, 78, 115, 45, 102, 97, 108, 115, 101, 47, 112,
101, 114, 115, 105, 115, 116, 101, 110, 116, 47, 100, 117, 109, 109, 121, 84,
111, 112, 105, 99], pulsar/cursor=[112, 117, 108, 115, 97, 114, 46, 114, 101,
112, 108, 46, 114, 49], application=[112, 117, 108, 115, 97, 114]} - metadata
ops timeout : 60 seconds
04:51:29.307 [bookkeeper-ml-workers-OrderedExecutor-0-0] WARN
org.apache.bookkeeper.client.BookieWatcherImpl - New ensemble:
[172.17.0.2:34697, 172.17.0.2:34779] is not adhering to Placement Policy.
quarantinedBookies: []
04:51:29.308 [bookkeeper-ml-workers-OrderedExecutor-0-0] INFO
org.apache.pulsar.broker.service.persistent.PersistentTopic -
[persistent://pulsar/partitionedNs-false/dummyTopic] Starting replicator to
remote: r2
04:51:29.317 [pulsar-ordered-OrderedExecutor-7-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0003 local:/127.0.0.1:39986
remoteserver:localhost/127.0.0.1:35957 lastZxid:109 xid:318 sent:325 recv:366
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/ns
04:51:29.318 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0001 local:/127.0.0.1:39964
remoteserver:localhost/127.0.0.1:35957 lastZxid:109 xid:384 sent:393 recv:435
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/ns
04:51:29.319 [pulsar-ordered-OrderedExecutor-6-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0005 local:/127.0.0.1:40008
remoteserver:localhost/127.0.0.1:35957 lastZxid:109 xid:283 sent:291 recv:312
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/ns
04:51:29.318 [pulsar-web-77-8] INFO
org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully
updated the on namespace /admin/policies/pulsar/ns
04:51:29.319 [pulsar-web-77-8] INFO
org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully
removed backlog namespace=pulsar/ns, quota=destination_storage
04:51:29.320 [TestNG-method=setup-1-EventThread] INFO
org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [172.17.0.2:34697,
172.17.0.2:34779] for ledger: 143
04:51:29.321 [pulsar-web-77-8] INFO org.eclipse.jetty.server.RequestLog -
127.0.0.1 - - [12/Feb/2021:04:51:29 +0000] "DELETE
/admin/v2/namespaces/pulsar/ns/backlogQuota?backlogQuotaType=destination_storage
HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
04:51:29.332 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0001 local:/127.0.0.1:39964
remoteserver:localhost/127.0.0.1:35957 lastZxid:110 xid:385 sent:394 recv:437
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/ns1
04:51:29.333 [pulsar-ordered-OrderedExecutor-7-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0003 local:/127.0.0.1:39986
remoteserver:localhost/127.0.0.1:35957 lastZxid:110 xid:319 sent:326 recv:368
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/ns1
04:51:29.333 [pulsar-web-77-7] INFO
org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully
updated the on namespace /admin/policies/pulsar/ns1
04:51:29.333 [pulsar-web-77-7] INFO
org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully
removed backlog namespace=pulsar/ns1, quota=destination_storage
04:51:29.334 [pulsar-web-77-7] INFO org.eclipse.jetty.server.RequestLog -
127.0.0.1 - - [12/Feb/2021:04:51:29 +0000] "DELETE
/admin/v2/namespaces/pulsar/ns1/backlogQuota?backlogQuotaType=destination_storage
HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
04:51:29.341 [pulsar-ordered-OrderedExecutor-7-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0003 local:/127.0.0.1:39986
remoteserver:localhost/127.0.0.1:35957 lastZxid:111 xid:320 sent:327 recv:370
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/global/ns
04:51:29.341 [pulsar-ordered-OrderedExecutor-1-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0001 local:/127.0.0.1:39964
remoteserver:localhost/127.0.0.1:35957 lastZxid:111 xid:386 sent:395 recv:439
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/global/ns
04:51:29.341 [pulsar-ordered-OrderedExecutor-6-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:20000
sessionid:0x100002f0aaf0005 local:/127.0.0.1:40008
remoteserver:localhost/127.0.0.1:35957 lastZxid:110 xid:284 sent:292 recv:314
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged
path:/admin/policies/pulsar/global/ns
04:51:29.341 [pulsar-web-77-5] INFO
org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully
updated the on namespace /admin/policies/pulsar/global/ns
04:51:29.342 [pulsar-web-77-5] INFO
org.apache.pulsar.broker.admin.impl.NamespacesBase - [null] Successfully
removed backlog namespace=pulsar/global/ns, quota=destination_storage
04:51:29.344 [pulsar-web-77-5] INFO org.eclipse.jetty.server.RequestLog -
127.0.0.1 - - [12/Feb/2021:04:51:29 +0000] "DELETE
/admin/namespaces/pulsar/global/ns/backlogQuota?backlogQuotaType=destination_storage
HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0-SNAPSHOT" 8
```
----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
For queries about this service, please contact Infrastructure at:
[email protected]
