You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2020/03/25 12:35:53 UTC
[GitHub] [pulsar] ncmans opened a new issue #6603: Brokers fail when
updating bookkeepr
ncmans opened a new issue #6603: Brokers fail when updating bookkeepr
URL: https://github.com/apache/pulsar/issues/6603
**Describe the bug**
Pulsar brokers start to fail with following error when bookkeepers are updating (ie in rolling manner, one at a time):
```
03:29:25.395 [BookKeeperClientScheduler-OrderedScheduler-0-0] ERROR org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy - Unexpected exception while handling joining bookie pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar.svc.cluster.local:3181
java.lang.NullPointerException: null
at org.apache.bookkeeper.net.NetUtils.resolveNetworkLocation(NetUtils.java:77) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.resolveNetworkLocation(TopologyAwareEnsemblePlacementPolicy.java:779) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.createBookieNode(TopologyAwareEnsemblePlacementPolicy.java:775) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.handleBookiesThatJoined(TopologyAwareEnsemblePlacementPolicy.java:707) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.handleBookiesThatJoined(RackawareEnsemblePlacementPolicyImpl.java:79) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicy.handleBookiesThatJoined(RackawareEnsemblePlacementPolicy.java:246) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.TopologyAwareEnsemblePlacementPolicy.onClusterChanged(TopologyAwareEnsemblePlacementPolicy.java:654) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicyImpl.onClusterChanged(RackawareEnsemblePlacementPolicyImpl.java:79) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.RackawareEnsemblePlacementPolicy.onClusterChanged(RackawareEnsemblePlacementPolicy.java:89) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.BookieWatcherImpl.processWritableBookiesChanged(BookieWatcherImpl.java:171) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.client.BookieWatcherImpl.lambda$initialBlockingBookieRead$1(BookieWatcherImpl.java:206) ~[org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.discover.ZKRegistrationClient$WatchTask.accept(ZKRegistrationClient.java:139) [org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at org.apache.bookkeeper.discover.ZKRegistrationClient$WatchTask.accept(ZKRegistrationClient.java:62) [org.apache.bookkeeper-bookkeeper-server-4.10.0.jar:4.10.0]
at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774) [?:1.8.0_232]
at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750) [?:1.8.0_232]
at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:456) [?:1.8.0_232]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_232]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_232]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_232]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_232]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
03:29:28.764 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0x8f82b194, L:/10.1.27.4:35010 - R:pulsar-bookkeeper-3.pulsar-bookkeeper.pulsar.svc.cluster.local/10.1.30.30:3181] for pulsar-bookkeeper-3.pulsar-bookkeeper.pulsar.svc.cluster.local:3181
03:29:28.764 [BookKeeperClientWorker-OrderedExecutor-0-0] INFO org.apache.bookkeeper.client.PendingReadOp - Error: Bookie operation timeout while reading L1707 E0 from bookie: pulsar-bookkeeper-3.pulsar-bookkeeper.pulsar.svc.cluster.local:3181
03:29:29.426 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.27.4:8080/healthcheck][reader-62bafd6e50] Failed to subscribe to topic on /10.1.27.4:6650
03:29:29.426 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.PulsarClientImpl - [persistent://pulsar/pulsar/10.1.27.4:8080/healthcheck] Failed to get create topic reader
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 696 lookup request timedout after ms 30000
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.uniRun(CompletableFuture.java:714) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture$UniRun.tryFire(CompletableFuture.java:701) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) ~[?:1.8.0_232]
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:1023) ~[org.apache.pulsar-pulsar-client-original-2.5.0.jar:2.5.0]
at org.apache.pulsar.client.impl.ClientCnx.lambda$channelActive$0(ClientCnx.java:187) ~[org.apache.pulsar-pulsar-client-original-2.5.0.jar:2.5.0]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:156) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:518) [io.netty-netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1050) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
Caused by: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 696 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:1022) ~[org.apache.pulsar-pulsar-client-original-2.5.0.jar:2.5.0]
... 10 more
03:29:29.427 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x449aeac5, L:/10.1.27.4:49298 - R:/10.1.27.4:6650] request 696 timed out after 30000 ms
03:29:29.427 [pulsar-client-io-41-1] ERROR org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.27.4:8080/healthcheck] [null] Failed to create producer: 697 lookup request timedout after ms 30000
03:29:29.430 [pulsar-client-io-41-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [24/Mar/2020:03:28:34 +0000] "GET /admin/v2/brokers/health HTTP/1.1" 500 2442 "-" "Pulsar-Java-v2.5.0" 55407
03:29:29.430 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x449aeac5, L:/10.1.27.4:49298 - R:/10.1.27.4:6650] request 697 timed out after 30000 ms
03:29:29.431 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.27.4:8080/healthcheck][reader-d9165e25c4] Failed to subscribe to topic on /10.1.27.4:6650
03:29:29.431 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.PulsarClientImpl - [persistent://pulsar/pulsar/10.1.27.4:8080/healthcheck] Failed to get create topic reader
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 702 lookup request timedout after ms 30000
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.uniRun(CompletableFuture.java:714) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture$UniRun.tryFire(CompletableFuture.java:701) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) ~[?:1.8.0_232]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) ~[?:1.8.0_232]
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:1023) ~[org.apache.pulsar-pulsar-client-original-2.5.0.jar:2.5.0]
at org.apache.pulsar.client.impl.ClientCnx.lambda$channelActive$0(ClientCnx.java:187) ~[org.apache.pulsar-pulsar-client-original-2.5.0.jar:2.5.0]
at io.netty.util.concurrent.PromiseTask.runTask(PromiseTask.java:98) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:156) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:510) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:518) [io.netty-netty-transport-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$6.run(SingleThreadEventExecutor.java:1050) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.43.Final.jar:4.1.43.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_232]
Caused by: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 702 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:1022) ~[org.apache.pulsar-pulsar-client-original-2.5.0.jar:2.5.0]
... 10 more
03:29:29.433 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x449aeac5, L:/10.1.27.4:49298 - R:/10.1.27.4:6650] request 702 timed out after 30000 ms
03:29:29.433 [pulsar-client-io-41-1] ERROR org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.27.4:8080/healthcheck] [null] Failed to create producer: 703 lookup request timedout after ms 30000
03:29:29.447 [pulsar-client-io-41-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [24/Mar/2020:03:28:34 +0000] "GET /admin/v2/brokers/health HTTP/1.1" 500 2442 "-" "Pulsar-Java-v2.5.0" 54952
03:29:29.448 [pulsar-client-io-41-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x449aeac5, L:/10.1.27.4:49298 - R:/10.1.27.4:6650] request 703 timed out after 30000 ms
```
The healthcheck mentioned is the following command:
```
$ /pulsar/bin/pulsar-admin brokers healthcheck
```
NOTE: this bug was [first reported](https://github.com/kafkaesque-io/pulsar-helm-chart/issues/23) to the relevant kubernetes chart maintainers with no resolutions as of this issue.
**To Reproduce**
Steps to reproduce the behavior:
1. Install the pulsar chart from https://github.com/kafkaesque-io/pulsar-helm-chart/tree/master/helm-chart-sources/pulsar
2. Make a change to the bookkeeper statefulset to trigger a rolling update: `kubectl edit sts pulsar-bookkeeper` and add an annotation to `spec.template.metadata.annotations`.
3. Watch the pods: `watch `kubectl get pod`
**Expected behavior**
Bookies should rolling update one by one with nothing else failing.
**Actual behavior**
Brokers start to fail and get restarted by the scheduler.
**Additional context**
Environment: Kubernetes cluster on GKE
```
$ kubectl version
Client Version: version.Info{Major:"1", Minor:"17", GitVersion:"v1.17.3", GitCommit:"06ad960bfd03b39c8310aaf92d1e7c12ce618213", GitTreeState:"archive", BuildDate:"2020-02-29T16:37:45Z", GoVersion:"go1.14", Compiler:"gc", Platform:"linux/amd64"}
Server Version: version.Info{Major:"1", Minor:"14+", GitVersion:"v1.14.10-gke.17", GitCommit:"bdceba0734835c6cb1acbd1c447caf17d8613b44", GitTreeState:"clean", BuildDate:"2020-01-17T23:10:13Z", GoVersion:"go1.12.12b4", Compiler:"gc", Platform:"linux/amd64"}
```
----------------------------------------------------------------
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:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [pulsar] sijie commented on issue #6603: Brokers fail when updating
bookkeepr
Posted by GitBox <gi...@apache.org>.
sijie commented on issue #6603: Brokers fail when updating bookkeepr
URL: https://github.com/apache/pulsar/issues/6603#issuecomment-604246559
the NullPointException is due to the hostname is unresolved. but that wasn't the root cause.
The error seems to come from lookup failures. It typically indicates the actual error is in a different broker. Have you checked the error log in the other brokers?
----------------------------------------------------------------
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:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [pulsar] ncmans commented on issue #6603: Brokers fail when
updating bookkeeper
Posted by GitBox <gi...@apache.org>.
ncmans commented on issue #6603: Brokers fail when updating bookkeeper
URL: https://github.com/apache/pulsar/issues/6603#issuecomment-605981898
From https://github.com/kafkaesque-io/pulsar-helm-chart/issues/23#issuecomment-605981138:
> The root cause was terminationGracePeriod = 0 which would result in bookie pods getting killed instantly upon rolling update. #30 fixes this issue.
As the issue is caused by mis-configuration of the helm chart, I'm closing it here.
----------------------------------------------------------------
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:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [pulsar] sijie commented on issue #6603: Brokers fail when updating
bookkeeper
Posted by GitBox <gi...@apache.org>.
sijie commented on issue #6603: Brokers fail when updating bookkeeper
URL: https://github.com/apache/pulsar/issues/6603#issuecomment-605749965
@ncmans the root cause is on third broker - `ledger=35 - operation=Failed to read entry - entry=0`. That means that your broker failed to read an entry when the bookkeeper cluster is being updated. I am guessing that the bookie stored `ledger 35` was being updated. I don't know how did you do a health check for your broker. I am guessing the health check in the helm chart wasn't implemented in the correct way, which causes K8S failed brokers when the bookie server is temporarily unavailable.
You can reference our chart https://github.com/streamnative/charts to see how we implement the readiness and liveness probes: https://github.com/streamnative/charts/blob/master/charts/pulsar/templates/broker-statefulset.yaml#L135
----------------------------------------------------------------
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:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [pulsar] ncmans commented on issue #6603: Brokers fail when
updating bookkeepr
Posted by GitBox <gi...@apache.org>.
ncmans commented on issue #6603: Brokers fail when updating bookkeepr
URL: https://github.com/apache/pulsar/issues/6603#issuecomment-604250126
Here's first broker's last lines in the logs:
```
06:07:55.845 [pulsar-client-io-40-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck][reader-4144f1b87f] Subscribing to topic on cnx [id: 0x1407a750, L:/10.1.26.5:56626 - R:10.1.26.5/10.1.26.5:6650]
06:07:55.845 [pulsar-io-22-1] INFO org.apache.pulsar.broker.service.ServerCnx - [/10.1.26.5:56626] Subscribing on topic persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck / reader-4144f1b87f
06:07:55.846 [pulsar-client-io-40-1] INFO org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck] [null] Creating producer on cnx [id: 0x1407a750, L:/10.1.26.5:56626 - R:10.1.26.5/10.1.26.5:6650]
06:07:55.846 [pulsar-io-22-1] INFO org.apache.pulsar.broker.service.ServerCnx - [/10.1.26.5:56626][persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck] Creating producer. producerId=83
06:08:11.651 [pulsar-ordered-OrderedExecutor-3-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000 sessionid:0x2004ec32b5e001b local:/10.1.26.5:52828 remoteserver:pulsar-zookeeper-1.pulsar-zookeeper/10.1.2.118:2181 lastZxid:4294968661 xid:613 sent:613 recv:645 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/loadbalance/brokers/10.1.23.38:8080
06:08:19.888 [pulsar-web-30-6] INFO org.eclipse.jetty.server.RequestLog - 10.1.13.3 - - [26/Mar/2020:06:08:19 +0000] "GET /metrics HTTP/1.1" 302 0 "-" "Prometheus/2.16.0" 1
06:08:19.898 [prometheus-stats-39-1] INFO org.eclipse.jetty.server.RequestLog - 10.1.13.3 - - [26/Mar/2020:06:08:19 +0000] "GET /metrics/ HTTP/1.1" 200 15451 "http://10.1.26.5:8080/metrics" "Prometheus/2.16.0" 10
06:08:25.083 [BookKeeperClientWorker-OrderedExecutor-3-0] INFO org.apache.bookkeeper.client.PendingReadOp - Error: Bookie operation timeout while reading L27 E0 from bookie: pulsar-bookkeeper-2.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:25.083 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0xdac01f4b, L:/10.1.26.5:35390 - R:pulsar-bookkeeper-2.pulsar-bookkeeper.pulsar-test.svc.cluster.local/10.1.23.37:3181] for pulsar-bookkeeper-2.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.247 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Removing a node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.247 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Removing a node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.272 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.272 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:48.937 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck][reader-6e29ce413c] Failed to subscribe to topic on 10.1.26.5/10.1.26.5:6650
06:08:48.937 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.PulsarClientImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck] Failed to get create topic reader
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 652 lookup request timedout after ms 30000
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.uniRun(CompletableFuture.java:700) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniRun.tryFire(CompletableFuture.java:687) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_212]
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:929) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at org.apache.pulsar.client.impl.ClientCnx.lambda$channelActive$0(ClientCnx.java:180) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_212]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:133) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:335) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]
Caused by: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 652 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:928) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
... 9 more
06:08:48.938 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x1407a750, L:/10.1.26.5:56626 - R:10.1.26.5/10.1.26.5:6650] request 652 timed out after 30000 ms
06:08:48.938 [pulsar-client-io-40-1] ERROR org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck] [null] Failed to create producer: 653 lookup request timedout after ms 30000
06:08:48.941 [pulsar-client-io-40-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/Mar/2020:06:07:54 +0000] "GET /admin/v2/brokers/health HTTP/1.1" 500 2371 "-" "Pulsar-Java-v2.4.0" 54451
06:08:48.944 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x1407a750, L:/10.1.26.5:56626 - R:10.1.26.5/10.1.26.5:6650] request 653 timed out after 30000 ms
06:08:48.944 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck][reader-4144f1b87f] Failed to subscribe to topic on 10.1.26.5/10.1.26.5:6650
06:08:48.944 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.PulsarClientImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck] Failed to get create topic reader
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 658 lookup request timedout after ms 30000
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.uniRun(CompletableFuture.java:700) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniRun.tryFire(CompletableFuture.java:687) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_212]
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:929) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at org.apache.pulsar.client.impl.ClientCnx.lambda$channelActive$0(ClientCnx.java:180) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_212]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:133) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:335) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]
Caused by: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 658 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:928) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
... 9 more
06:08:48.945 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x1407a750, L:/10.1.26.5:56626 - R:10.1.26.5/10.1.26.5:6650] request 658 timed out after 30000 ms
06:08:48.947 [pulsar-client-io-40-1] ERROR org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.26.5:8080/healthcheck] [null] Failed to create producer: 659 lookup request timedout after ms 30000
06:08:48.957 [pulsar-client-io-40-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/Mar/2020:06:07:55 +0000] "GET /admin/v2/brokers/health HTTP/1.1" 500 2371 "-" "Pulsar-Java-v2.4.0" 53127
06:08:48.957 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x1407a750, L:/10.1.26.5:56626 - R:10.1.26.5/10.1.26.5:6650] request 659 timed out after 30000 ms
```
Second broker:
```
06:07:51.195 [pulsar-client-io-40-1] INFO org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck][reader-a225a8cf7b] Subscribing to topic on cnx [id: 0xb6cd6406, L:/10.1.13.6:43964 - R:10.1.13.6/10.1.13.6:6650]
06:07:51.196 [pulsar-io-22-1] INFO org.apache.pulsar.broker.service.ServerCnx - [/10.1.13.6:43964] Subscribing on topic persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck / reader-a225a8cf7b
06:07:51.196 [pulsar-client-io-40-1] INFO org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck] [null] Creating producer on cnx [id: 0xb6cd6406, L:/10.1.13.6:43964 - R:10.1.13.6/10.1.13.6:6650]
06:07:51.197 [pulsar-io-22-1] INFO org.apache.pulsar.broker.service.ServerCnx - [/10.1.13.6:43964][persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck] Creating producer. producerId=65
06:08:01.876 [pulsar-web-30-1] INFO org.eclipse.jetty.server.RequestLog - 10.1.13.3 - - [26/Mar/2020:06:08:01 +0000] "GET /metrics HTTP/1.1" 302 0 "-" "Prometheus/2.16.0" 0
06:08:01.883 [prometheus-stats-39-1] INFO org.eclipse.jetty.server.RequestLog - 10.1.13.3 - - [26/Mar/2020:06:08:01 +0000] "GET /metrics/ HTTP/1.1" 200 15447 "http://10.1.13.6:8080/metrics" "Prometheus/2.16.0" 7
06:08:11.651 [pulsar-ordered-OrderedExecutor-7-0-EventThread] INFO org.apache.pulsar.zookeeper.ZooKeeperDataCache - [State:CONNECTED Timeout:30000 sessionid:0x2004ec32b5e001c local:/10.1.13.6:58112 remoteserver:pulsar-zookeeper-1.pulsar-zookeeper/10.1.2.118:2181 lastZxid:4294968661 xid:540 sent:540 recv:566 queuedpkts:0 pendingresp:0 queuedevents:0] Received ZooKeeper watch event: WatchedEvent state:SyncConnected type:NodeDataChanged path:/loadbalance/brokers/10.1.23.38:8080
06:08:20.870 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.proto.PerChannelBookieClient - Timed-out 1 operations to channel [id: 0xfe02c865, L:/10.1.13.6:54828 - R:pulsar-bookkeeper-2.pulsar-bookkeeper.pulsar-test.svc.cluster.local/10.1.23.37:3181] for pulsar-bookkeeper-2.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:20.871 [BookKeeperClientWorker-OrderedExecutor-2-0] INFO org.apache.bookkeeper.client.PendingReadOp - Error: Bookie operation timeout while reading L30 E0 from bookie: pulsar-bookkeeper-2.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.247 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Removing a node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.247 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Removing a node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.273 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:26.273 [BookKeeperClientScheduler-OrderedScheduler-0-0] INFO org.apache.bookkeeper.net.NetworkTopologyImpl - Adding a new node: /default-rack/pulsar-bookkeeper-0.pulsar-bookkeeper.pulsar-test.svc.cluster.local:3181
06:08:45.522 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck][reader-ef189d8ad1] Failed to subscribe to topic on 10.1.13.6/10.1.13.6:6650
06:08:45.522 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.PulsarClientImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck] Failed to get create topic reader
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 508 lookup request timedout after ms 30000
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.uniRun(CompletableFuture.java:700) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniRun.tryFire(CompletableFuture.java:687) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_212]
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:929) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at org.apache.pulsar.client.impl.ClientCnx.lambda$channelActive$0(ClientCnx.java:180) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_212]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:133) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:335) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]
Caused by: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 508 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:928) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
... 9 more
06:08:45.523 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xb6cd6406, L:/10.1.13.6:43964 - R:10.1.13.6/10.1.13.6:6650] request 508 timed out after 30000 ms
06:08:45.523 [pulsar-client-io-40-1] ERROR org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck] [null] Failed to create producer: 509 lookup request timedout after ms 30000
06:08:45.525 [pulsar-client-io-40-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/Mar/2020:06:07:50 +0000] "GET /admin/v2/brokers/health HTTP/1.1" 500 2371 "-" "Pulsar-Java-v2.4.0" 54798
06:08:45.525 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xb6cd6406, L:/10.1.13.6:43964 - R:10.1.13.6/10.1.13.6:6650] request 509 timed out after 30000 ms
06:08:45.525 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck][reader-a225a8cf7b] Failed to subscribe to topic on 10.1.13.6/10.1.13.6:6650
06:08:45.525 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.PulsarClientImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck] Failed to get create topic reader
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 514 lookup request timedout after ms 30000
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.uniRun(CompletableFuture.java:700) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniRun.tryFire(CompletableFuture.java:687) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_212]
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:929) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at org.apache.pulsar.client.impl.ClientCnx.lambda$channelActive$0(ClientCnx.java:180) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_212]
at io.netty.util.concurrent.ScheduledFutureTask.run(ScheduledFutureTask.java:133) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:404) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:335) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]
Caused by: org.apache.pulsar.client.api.PulsarClientException$TimeoutException: 514 lookup request timedout after ms 30000
at org.apache.pulsar.client.impl.ClientCnx.checkRequestTimeout(ClientCnx.java:928) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
... 9 more
06:08:45.526 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xb6cd6406, L:/10.1.13.6:43964 - R:10.1.13.6/10.1.13.6:6650] request 514 timed out after 30000 ms
06:08:45.526 [pulsar-client-io-40-1] ERROR org.apache.pulsar.client.impl.ProducerImpl - [persistent://pulsar/pulsar/10.1.13.6:8080/healthcheck] [null] Failed to create producer: 515 lookup request timedout after ms 30000
06:08:45.531 [pulsar-client-io-40-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/Mar/2020:06:07:51 +0000] "GET /admin/v2/brokers/health HTTP/1.1" 500 2371 "-" "Pulsar-Java-v2.4.0" 54372
06:08:45.531 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0xb6cd6406, L:/10.1.13.6:43964 - R:10.1.13.6/10.1.13.6:6650] request 515 timed out after 30000 ms
```
Third broker:
```
06:08:54.175 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ConsumerImpl - [persistent://pulsar/pulsar/10.1.23.38:8080/healthcheck][reader-01f359c463] Failed to subscribe to topic on 10.1.23.38/10.1.23.38:6650
06:08:54.174 [ForkJoinPool.commonPool-worker-0] WARN org.apache.pulsar.broker.service.ServerCnx - [/10.1.23.38:59200][persistent://pulsar/pulsar/10.1.23.38:8080/healthcheck][reader-089cdcfa30] Failed to create consumer: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
java.util.concurrent.CompletionException: java.io.IOException: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.uniCompose(CompletableFuture.java:943) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:926) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) ~[?:1.8.0_212]
at org.apache.pulsar.broker.service.schema.BookkeeperSchemaStorage$Functions.lambda$getLedgerEntry$0(BookkeeperSchemaStorage.java:595) ~[org.apache.pulsar-pulsar-broker-2.4.0.jar:2.4.0]
at org.apache.bookkeeper.client.LedgerHandle$6.onFailure(LedgerHandle.java:818) ~[org.apache.bookkeeper-bookkeeper-server-4.9.2.jar:4.9.2]
at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:38) ~[org.apache.bookkeeper-bookkeeper-common-4.9.2.jar:4.9.2]
at org.apache.bookkeeper.common.concurrent.FutureEventListener.accept(FutureEventListener.java:26) ~[org.apache.bookkeeper-bookkeeper-common-4.9.2.jar:4.9.2]
at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:442) ~[?:1.8.0_212]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_212]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_212]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at java.lang.Thread.run(Thread.java:748) ~[?:1.8.0_212]
Caused by: java.io.IOException: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
at org.apache.pulsar.broker.service.schema.BookkeeperSchemaStorage.bkException(BookkeeperSchemaStorage.java:656) ~[org.apache.pulsar-pulsar-broker-2.4.0.jar:2.4.0]
... 11 more
06:08:54.175 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.PulsarClientImpl - [persistent://pulsar/pulsar/10.1.23.38:8080/healthcheck] Failed to get create topic reader
java.util.concurrent.CompletionException: org.apache.pulsar.client.api.PulsarClientException: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.uniRun(CompletableFuture.java:700) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture$UniRun.tryFire(CompletableFuture.java:687) ~[?:1.8.0_212]
at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) [?:1.8.0_212]
at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977) [?:1.8.0_212]
at org.apache.pulsar.client.impl.ClientCnx.handleError(ClientCnx.java:597) [org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
at org.apache.pulsar.common.protocol.PulsarDecoder.channelRead(PulsarDecoder.java:154) [org.apache.pulsar-pulsar-common-2.4.0.jar:2.4.0]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:323) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:297) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1434) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:965) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:799) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:433) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:330) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:909) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-all-4.1.32.Final.jar:4.1.32.Final]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_212]
Caused by: org.apache.pulsar.client.api.PulsarClientException: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
at org.apache.pulsar.client.impl.ClientCnx.getPulsarClientException(ClientCnx.java:908) ~[org.apache.pulsar-pulsar-client-original-2.4.0.jar:2.4.0]
... 20 more
06:08:54.185 [pulsar-client-io-40-1] INFO org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/Mar/2020:06:08:50 +0000] "GET /admin/v2/brokers/health HTTP/1.1" 500 4137 "-" "Pulsar-Java-v2.4.0" 3464
06:08:54.186 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received error from server: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
06:08:54.186 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received unknown request id from server: 392
06:08:54.186 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received error from server: java.io.IOException: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
06:08:54.186 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received unknown request id from server: 393
06:08:54.186 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received error from server: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
06:08:54.186 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received unknown request id from server: 398
06:08:54.186 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received error from server: java.io.IOException: Bookie operation timeout - ledger=35 - operation=Failed to read entry - entry=0
06:08:54.187 [pulsar-client-io-40-1] WARN org.apache.pulsar.client.impl.ClientCnx - [id: 0x6eb60abb, L:/10.1.23.38:59200 - R:10.1.23.38/10.1.23.38:6650] Received unknown request id from server: 399
```
----------------------------------------------------------------
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:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [pulsar] ncmans closed issue #6603: Brokers fail when updating
bookkeeper
Posted by GitBox <gi...@apache.org>.
ncmans closed issue #6603: Brokers fail when updating bookkeeper
URL: https://github.com/apache/pulsar/issues/6603
----------------------------------------------------------------
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:
users@infra.apache.org
With regards,
Apache Git Services
[GitHub] [pulsar] ncmans edited a comment on issue #6603: Brokers fail when
updating bookkeeper
Posted by GitBox <gi...@apache.org>.
ncmans edited a comment on issue #6603: Brokers fail when updating bookkeeper
URL: https://github.com/apache/pulsar/issues/6603#issuecomment-605981898
From https://github.com/kafkaesque-io/pulsar-helm-chart/issues/23#issuecomment-605981138:
> The root cause was terminationGracePeriod = 0 which would result in bookie pods getting killed instantly upon rolling update. https://github.com/kafkaesque-io/pulsar-helm-chart/pull/30 fixes this issue.
As the issue is caused by mis-configuration of the helm chart, I'm closing it here.
----------------------------------------------------------------
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:
users@infra.apache.org
With regards,
Apache Git Services