lhotari commented on pull request #11370:
URL: https://github.com/apache/pulsar/pull/11370#issuecomment-884867458
I tested the changes locally. The flakiness isn't fixed. The third re-run
made the test fail
```
[ERROR] Tests run: 3, Failures: 1, Errors: 0, Skipped: 2, Time elapsed: 8.86
s <<< FAILURE! - in org.apache.pulsar.broker.service.RackAwareTest
[ERROR] testPlacement(org.apache.pulsar.broker.service.RackAwareTest) Time
elapsed: 2.152 s <<< FAILURE!
java.lang.AssertionError: first bookie in rack 0 not included in ensemble
expected [true] but found [false]
at org.testng.Assert.fail(Assert.java:99)
at org.testng.Assert.failNotEquals(Assert.java:1037)
at org.testng.Assert.assertTrue(Assert.java:45)
at
org.apache.pulsar.broker.service.RackAwareTest.testPlacement(RackAwareTest.java:135)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at
org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:132)
at
org.testng.internal.InvokeMethodRunnable.runOne(InvokeMethodRunnable.java:45)
at
org.testng.internal.InvokeMethodRunnable.call(InvokeMethodRunnable.java:73)
at
org.testng.internal.InvokeMethodRunnable.call(InvokeMethodRunnable.java:11)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
```
Test logs
```
------- Starting test [TestClass name=class
org.apache.pulsar.broker.service.RackAwareTest].testPlacement([])-------
12:15:16.915 [metadata-store-68-1] INFO org.eclipse.jetty.server.RequestLog
- 127.0.0.1 - - [22/Jul/2021:12:15:16 +0000] "PUT /admin/v2/tenants/prop
HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.9.0-SNAPSHOT" 48
12:15:16.917 [TestNG-method=testPlacement-1] INFO
org.apache.pulsar.broker.service.RackAwareTest - setting rack for bookie at
10.0.0.1:46037 -- BookieInfoImpl(rack=rack-1, hostname=bookie-1)
12:15:16.934 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x1000d17ab760009 local:/127.0.0.1:58518
remoteserver:localhost/127.0.0.1:43735 lastZxid:60 xid:21 sent:21 recv:25
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged path:/bookies
12:15:16.936 [metadata-store-66-1] INFO
org.apache.pulsar.broker.admin.v2.Bookies - Updated rack mapping info for
10.0.0.1:46037
12:15:16.936 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:16.937 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Bookie rack info
updated to {default={10.0.0.1:46037=BookieInfoImpl(rack=rack-1,
hostname=bookie-1)}}. Notifying rackaware policy.
12:15:16.937 [metadata-store-66-1] INFO org.eclipse.jetty.server.RequestLog
- 127.0.0.1 - - [22/Jul/2021:12:15:16 +0000] "POST
/admin/v2/bookies/racks-info/10.0.0.1:46037?group=default HTTP/1.1" 204 0 "-"
"Pulsar-Java-v2.9.0-SNAPSHOT" 17
12:15:16.939 [TestNG-method=testPlacement-1] INFO
org.apache.pulsar.broker.service.RackAwareTest - setting rack for bookie at
10.0.0.2:40721 -- BookieInfoImpl(rack=rack-2, hostname=bookie-2)
12:15:16.945 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.bookkeeper.net.NetworkTopologyImpl - Removing a node:
/default-rack/10.0.0.1:46037
12:15:16.945 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node:
/rack-1/10.0.0.1:46037
12:15:16.949 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x1000d17ab760009 local:/127.0.0.1:58518
remoteserver:localhost/127.0.0.1:43735 lastZxid:69 xid:22 sent:22 recv:27
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged path:/bookies
12:15:16.950 [metadata-store-66-1] INFO
org.apache.pulsar.broker.admin.v2.Bookies - Updated rack mapping info for
10.0.0.2:40721
12:15:16.950 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:16.950 [metadata-store-66-1] INFO org.eclipse.jetty.server.RequestLog
- 127.0.0.1 - - [22/Jul/2021:12:15:16 +0000] "POST
/admin/v2/bookies/racks-info/10.0.0.2:40721?group=default HTTP/1.1" 204 0 "-"
"Pulsar-Java-v2.9.0-SNAPSHOT" 9
12:15:16.951 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Bookie rack info
updated to {default={10.0.0.1:46037=BookieInfoImpl(rack=rack-1,
hostname=bookie-1), 10.0.0.2:40721=BookieInfoImpl(rack=rack-2,
hostname=bookie-2)}}. Notifying rackaware policy.
12:15:16.951 [TestNG-method=testPlacement-1] INFO
org.apache.pulsar.broker.service.RackAwareTest - setting rack for bookie at
10.0.0.3:35455 -- BookieInfoImpl(rack=rack-2, hostname=bookie-3)
12:15:16.959 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x1000d17ab760009 local:/127.0.0.1:58518
remoteserver:localhost/127.0.0.1:43735 lastZxid:70 xid:23 sent:23 recv:29
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged path:/bookies
12:15:16.960 [metadata-store-66-1] INFO
org.apache.pulsar.broker.admin.v2.Bookies - Updated rack mapping info for
10.0.0.3:35455
12:15:16.960 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:16.961 [metadata-store-66-1] INFO org.eclipse.jetty.server.RequestLog
- 127.0.0.1 - - [22/Jul/2021:12:15:16 +0000] "POST
/admin/v2/bookies/racks-info/10.0.0.3:35455?group=default HTTP/1.1" 204 0 "-"
"Pulsar-Java-v2.9.0-SNAPSHOT" 7
12:15:16.961 [TestNG-method=testPlacement-1] INFO
org.apache.pulsar.broker.service.RackAwareTest - setting rack for bookie at
10.0.0.4:39995 -- BookieInfoImpl(rack=rack-2, hostname=bookie-4)
12:15:16.965 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.bookkeeper.net.NetworkTopologyImpl - Removing a node:
/rack-1/10.0.0.1:46037
12:15:16.965 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node:
/rack-1/10.0.0.1:46037
12:15:16.995 [ForkJoinPool.commonPool-worker-1] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Bookie rack info
updated to {default={10.0.0.1:46037=BookieInfoImpl(rack=rack-1,
hostname=bookie-1), 10.0.0.2:40721=BookieInfoImpl(rack=rack-2,
hostname=bookie-2), 10.0.0.3:35455=BookieInfoImpl(rack=rack-2,
hostname=bookie-3)}}. Notifying rackaware policy.
12:15:17.007 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x1000d17ab760009 local:/127.0.0.1:58518
remoteserver:localhost/127.0.0.1:43735 lastZxid:71 xid:24 sent:24 recv:31
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged path:/bookies
12:15:17.007 [metadata-store-66-1] INFO
org.apache.pulsar.broker.admin.v2.Bookies - Updated rack mapping info for
10.0.0.4:39995
12:15:17.008 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:17.008 [metadata-store-66-1] INFO org.eclipse.jetty.server.RequestLog
- 127.0.0.1 - - [22/Jul/2021:12:15:17 +0000] "POST
/admin/v2/bookies/racks-info/10.0.0.4:39995?group=default HTTP/1.1" 204 0 "-"
"Pulsar-Java-v2.9.0-SNAPSHOT" 8
12:15:17.009 [TestNG-method=testPlacement-1] INFO
org.apache.pulsar.broker.service.RackAwareTest - setting rack for bookie at
10.0.0.5:43509 -- BookieInfoImpl(rack=rack-2, hostname=bookie-5)
12:15:17.017 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x1000d17ab760009 local:/127.0.0.1:58518
remoteserver:localhost/127.0.0.1:43735 lastZxid:72 xid:25 sent:25 recv:33
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged path:/bookies
12:15:17.017 [metadata-store-66-1] INFO
org.apache.pulsar.broker.admin.v2.Bookies - Updated rack mapping info for
10.0.0.5:43509
12:15:17.017 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.bookkeeper.net.NetworkTopologyImpl - Removing a node:
/default-rack/10.0.0.2:40721
12:15:17.018 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node:
/rack-2/10.0.0.2:40721
12:15:17.018 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Bookie rack info
updated to {default={10.0.0.1:46037=BookieInfoImpl(rack=rack-1,
hostname=bookie-1), 10.0.0.2:40721=BookieInfoImpl(rack=rack-2,
hostname=bookie-2), 10.0.0.3:35455=BookieInfoImpl(rack=rack-2,
hostname=bookie-3), 10.0.0.4:39995=BookieInfoImpl(rack=rack-2,
hostname=bookie-4)}}. Notifying rackaware policy.
12:15:17.018 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:17.018 [metadata-store-66-1] INFO org.eclipse.jetty.server.RequestLog
- 127.0.0.1 - - [22/Jul/2021:12:15:17 +0000] "POST
/admin/v2/bookies/racks-info/10.0.0.5:43509?group=default HTTP/1.1" 204 0 "-"
"Pulsar-Java-v2.9.0-SNAPSHOT" 7
12:15:17.019 [TestNG-method=testPlacement-1] INFO
org.apache.pulsar.broker.service.RackAwareTest - setting rack for bookie at
10.0.0.6:39203 -- BookieInfoImpl(rack=rack-2, hostname=bookie-6)
12:15:17.026 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000
sessionid:0x1000d17ab760009 local:/127.0.0.1:58518
remoteserver:localhost/127.0.0.1:43735 lastZxid:73 xid:26 sent:26 recv:35
queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event:
WatchedEvent state:SyncConnected type:NodeDataChanged path:/bookies
12:15:17.026 [metadata-store-66-1] INFO
org.apache.pulsar.broker.admin.v2.Bookies - Updated rack mapping info for
10.0.0.6:39203
12:15:17.027 [metadata-store-66-1] INFO org.eclipse.jetty.server.RequestLog
- 127.0.0.1 - - [22/Jul/2021:12:15:17 +0000] "POST
/admin/v2/bookies/racks-info/10.0.0.6:39203?group=default HTTP/1.1" 204 0 "-"
"Pulsar-Java-v2.9.0-SNAPSHOT" 6
12:15:17.028 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:18.019 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:18.019 [ForkJoinPool.commonPool-worker-1] WARN
org.apache.pulsar.zookeeper.ZooKeeperDataCache - Reloading ZooKeeperDataCache
failed at path: /bookies
java.util.concurrent.CompletionException: java.lang.RuntimeException:
java.util.concurrent.TimeoutException
at
java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
~[?:?]
at
java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)
~[?:?]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:718)
~[?:?]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
~[?:?]
at
java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
~[?:?]
at
org.apache.pulsar.zookeeper.ZooKeeperCache.lambda$getDataAsync$17(ZooKeeperCache.java:386)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:714)
~[?:?]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
~[?:?]
at
java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
~[?:?]
at
org.apache.pulsar.zookeeper.ZooKeeperCache.lambda$getDataAsync$11(ZooKeeperCache.java:366)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1426)
[?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at
java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
[?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
[?:?]
at
java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
[?:?]
Caused by: java.lang.RuntimeException: java.util.concurrent.TimeoutException
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.getRack(ZkBookieRackAffinityMapping.java:195)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.resolve(ZkBookieRackAffinityMapping.java:179)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy$DNSResolverDecorator.resolve(TopologyAwareEnsemblePlacementPolicy.java:561)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.net.NetUtils.resolveNetworkLocation(NetUtils.java:88)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.resolveNetworkLocation(TopologyAwareEnsemblePlacementPolicy.java:794)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.createBookieNode(TopologyAwareEnsemblePlacementPolicy.java:784)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.onBookieRackChange(TopologyAwareEnsemblePlacementPolicy.java:747)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.onBookieRackChange(RackawareEnsemblePlacementPolicyImpl.java:80)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:242)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:53)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZooKeeperDataCache.lambda$reloadCache$3(ZooKeeperDataCache.java:138)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:714)
~[?:?]
... 13 more
Caused by: java.util.concurrent.TimeoutException
at
java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1886)
~[?:?]
at
java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021) ~[?:?]
at
org.apache.pulsar.zookeeper.ZooKeeperDataCache.get(ZooKeeperDataCache.java:97)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.getRack(ZkBookieRackAffinityMapping.java:187)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.resolve(ZkBookieRackAffinityMapping.java:179)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy$DNSResolverDecorator.resolve(TopologyAwareEnsemblePlacementPolicy.java:561)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.net.NetUtils.resolveNetworkLocation(NetUtils.java:88)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.resolveNetworkLocation(TopologyAwareEnsemblePlacementPolicy.java:794)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.createBookieNode(TopologyAwareEnsemblePlacementPolicy.java:784)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.onBookieRackChange(TopologyAwareEnsemblePlacementPolicy.java:747)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.onBookieRackChange(RackawareEnsemblePlacementPolicyImpl.java:80)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:242)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:53)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZooKeeperDataCache.lambda$reloadCache$3(ZooKeeperDataCache.java:138)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:714)
~[?:?]
... 13 more
12:15:18.024 [ForkJoinPool.commonPool-worker-1] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Bookie rack info
updated to {default={10.0.0.1:46037=BookieInfoImpl(rack=rack-1,
hostname=bookie-1), 10.0.0.2:40721=BookieInfoImpl(rack=rack-2,
hostname=bookie-2), 10.0.0.3:35455=BookieInfoImpl(rack=rack-2,
hostname=bookie-3), 10.0.0.4:39995=BookieInfoImpl(rack=rack-2,
hostname=bookie-4), 10.0.0.5:43509=BookieInfoImpl(rack=rack-2,
hostname=bookie-5)}}. Notifying rackaware policy.
12:15:19.019 [ForkJoinPool.commonPool-worker-3] WARN
org.apache.pulsar.zookeeper.ZooKeeperDataCache - Reloading ZooKeeperDataCache
failed at path: /bookies
java.util.concurrent.CompletionException: java.lang.RuntimeException:
java.util.concurrent.TimeoutException
at
java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
~[?:?]
at
java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)
~[?:?]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:718)
~[?:?]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
~[?:?]
at
java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
~[?:?]
at
org.apache.pulsar.zookeeper.ZooKeeperCache.lambda$getDataAsync$17(ZooKeeperCache.java:386)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:714)
~[?:?]
at
java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
~[?:?]
at
java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2073)
~[?:?]
at
org.apache.pulsar.zookeeper.ZooKeeperCache.lambda$getDataAsync$11(ZooKeeperCache.java:366)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1426)
[?:?]
at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290) [?:?]
at
java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1020)
[?:?]
at java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1656) [?:?]
at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1594)
[?:?]
at
java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:183)
[?:?]
Caused by: java.lang.RuntimeException: java.util.concurrent.TimeoutException
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.getRack(ZkBookieRackAffinityMapping.java:195)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.resolve(ZkBookieRackAffinityMapping.java:179)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy$DNSResolverDecorator.resolve(TopologyAwareEnsemblePlacementPolicy.java:561)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.net.NetUtils.resolveNetworkLocation(NetUtils.java:88)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.resolveNetworkLocation(TopologyAwareEnsemblePlacementPolicy.java:794)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.createBookieNode(TopologyAwareEnsemblePlacementPolicy.java:784)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.onBookieRackChange(TopologyAwareEnsemblePlacementPolicy.java:747)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.onBookieRackChange(RackawareEnsemblePlacementPolicyImpl.java:80)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:242)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:53)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZooKeeperDataCache.lambda$reloadCache$3(ZooKeeperDataCache.java:138)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:714)
~[?:?]
... 13 more
Caused by: java.util.concurrent.TimeoutException
at
java.util.concurrent.CompletableFuture.timedGet(CompletableFuture.java:1886)
~[?:?]
at
java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2021) ~[?:?]
at
org.apache.pulsar.zookeeper.ZooKeeperDataCache.get(ZooKeeperDataCache.java:97)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.getRack(ZkBookieRackAffinityMapping.java:187)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.resolve(ZkBookieRackAffinityMapping.java:179)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy$DNSResolverDecorator.resolve(TopologyAwareEnsemblePlacementPolicy.java:561)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.net.NetUtils.resolveNetworkLocation(NetUtils.java:88)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.resolveNetworkLocation(TopologyAwareEnsemblePlacementPolicy.java:794)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.createBookieNode(TopologyAwareEnsemblePlacementPolicy.java:784)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.onBookieRackChange(TopologyAwareEnsemblePlacementPolicy.java:747)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.onBookieRackChange(RackawareEnsemblePlacementPolicyImpl.java:80)
~[bookkeeper-server-4.14.1.jar:4.14.1]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:242)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping.onUpdate(ZkBookieRackAffinityMapping.java:53)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
org.apache.pulsar.zookeeper.ZooKeeperDataCache.lambda$reloadCache$3(ZooKeeperDataCache.java:138)
~[pulsar-zookeeper-utils-2.9.0-SNAPSHOT.jar:2.9.0-SNAPSHOT]
at
java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:714)
~[?:?]
... 13 more
12:15:19.020 [ForkJoinPool.commonPool-worker-3] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Bookie rack info
updated to {default={10.0.0.1:46037=BookieInfoImpl(rack=rack-1,
hostname=bookie-1), 10.0.0.2:40721=BookieInfoImpl(rack=rack-2,
hostname=bookie-2), 10.0.0.3:35455=BookieInfoImpl(rack=rack-2,
hostname=bookie-3), 10.0.0.4:39995=BookieInfoImpl(rack=rack-2,
hostname=bookie-4), 10.0.0.5:43509=BookieInfoImpl(rack=rack-2,
hostname=bookie-5), 10.0.0.6:39203=BookieInfoImpl(rack=rack-2,
hostname=bookie-6)}}. Notifying rackaware policy.
12:15:19.022 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO
org.apache.pulsar.zookeeper.ZkBookieRackAffinityMapping - Reloading the bookie
rack affinity mapping cache.
12:15:19.061 [main-EventThread] INFO
org.apache.bookkeeper.client.LedgerCreateOp - Ensemble: [10.0.0.2:40721,
10.0.0.5:43509] for ledger: 0
12:15:19.061 [TestNG-method=testPlacement-1] INFO
org.apache.pulsar.broker.service.RackAwareTest - Ledger: 0 -- Ensemble:
[10.0.0.2:40721, 10.0.0.5:43509]
!!!!!!!!! FAILURE-- [TestClass name=class
org.apache.pulsar.broker.service.RackAwareTest].testPlacement([])-------
```
--
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.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
