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: [email protected] With regards, Apache Git Services
