Skip to content
This repository has been archived by the owner on Jan 24, 2024. It is now read-only.

[BUG] KoP failed to start for PulsarAdminException #619

Closed
xiaotongwang1 opened this issue Jul 22, 2021 · 4 comments
Closed

[BUG] KoP failed to start for PulsarAdminException #619

xiaotongwang1 opened this issue Jul 22, 2021 · 4 comments
Labels
type/bug

Comments

@xiaotongwang1
Copy link

xiaotongwang1 commented Jul 22, 2021 •
edited by BewareMyPower
Loading 

2021-07-20 19:21:07.887 [main] INFO  org.apache.pulsar.broker.PulsarService - Starting load management service ...
2021-07-20 19:21:07.946 [main] INFO  org.apache.pulsar.broker.PulsarService - Starting load balancer
2021-07-20 19:21:07.948 [main] INFO  i.s.pulsar.handlers.kop.KafkaProtocolHandler - Starting KafkaProtocolHandler, kop version is: '2.7.0.1'
2021-07-20 19:21:07.948 [main] INFO  i.s.pulsar.handlers.kop.KafkaProtocolHandler - Git Revision 810b09a
2021-07-20 19:21:07.948 [main] INFO  i.s.pulsar.handlers.kop.KafkaProtocolHandler - Built by  <> on fv-az60-573 at 2020-12-23T03:40:50+0000
2021-07-20 19:21:08.092 [main] INFO  org.apache.pulsar.broker.PulsarService - created admin with url http://10.3.113.157:8080 
2021-07-20 19:21:08.776 [main] INFO  i.s.pulsar.handlers.kop.utils.MetadataUtils - Cluster PPSADXService_dcssync_pulsar found: ClusterData{serviceUrl=http://10.6.95.18:8080,10.6.95.19:8080,10.6.95.20:8080,10.6.95.21:8080,10.3.113.157:8080,10.3.114.11:8080,10.3.114.12:8080,10.3.114.13:8080,10.3.114.14:8080, serviceUrlTls=https://10.6.95.18:8443,10.6.95.19:8443,10.6.95.20:8443,10.6.95.21:8443,10.3.113.157:8443,10.3.114.11:8443,10.3.114.12:8443,10.3.114.13:8443,10.3.114.14:8443, brokerServiceUrl=pulsar://10.6.95.18:6650,10.6.95.19:6650,10.6.95.20:6650,10.6.95.21:6650,10.3.113.157:6650,10.3.114.11:6650,10.3.114.12:6650,10.3.114.13:6650,10.3.114.14:6650, brokerServiceUrlTls=null, proxyServiceUrl=null, proxyProtocol=null, peerClusterNames=null}
2021-07-20 19:21:08.884 [pulsar-web-47-24] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x071c71c7_0x0e38e38e
2021-07-20 19:21:08.893 [pulsar-web-47-27] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x0e38e38e_0x15555555
2021-07-20 19:21:08.894 [pulsar-web-47-26] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x15555555_0x18e38e38
2021-07-20 19:21:08.894 [pulsar-web-47-31] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x18e38e38_0x1aaaaaaa
2021-07-20 19:21:08.937 [pulsar-web-47-24] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x6e38e38c_0x71c71c70
2021-07-20 19:21:08.966 [pulsar-web-47-45] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x78e38e37_0x7ffffffe
2021-07-20 19:21:08.975 [pulsar-web-47-58] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x8e38e38c_0x91c71c6f
2021-07-20 19:21:09.017 [pulsar-web-47-45] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x95555553_0x98e38e36
2021-07-20 19:21:09.022 [pulsar-web-47-60] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0x75555553_0x78e38e37
2021-07-20 19:21:09.029 [pulsar-web-47-27] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0xbaaaaaa7_0xbc71c719
2021-07-20 19:21:09.035 [pulsar-web-47-21] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0xee38e38a_0xf1c71c6e
2021-07-20 19:21:09.036 [pulsar-web-47-36] INFO  o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Namespace bundle is not owned by any broker PPSADXService/PPSADXMicroService/0xf5555552_0xf8e38e36
2021-07-20 19:21:09.438 [AsyncHttpClient-54-1] ERROR o.a.pulsar.broker.admin.v2.NonPersistentTopics - [100444451] Failed to get list of topics under namespace PPSADXService/PPSADXMicroService
java.util.concurrent.ExecutionException: org.apache.pulsar.client.admin.PulsarAdminException: java.util.concurrent.CompletionException: org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector$RetryException: Could not complete the operation. Number of retries has been exhausted. Failed reason: Connection refused: /10.3.114.11:8080
	at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
	at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1908)
	at org.apache.pulsar.broker.admin.v2.NonPersistentTopics.lambda$getList$1(NonPersistentTopics.java:279)
	at java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:836)
	at java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:811)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
	at org.apache.pulsar.client.admin.internal.TopicsImpl$5.failed(TopicsImpl.java:234)
	at org.glassfish.jersey.client.JerseyInvocation$1.failed(JerseyInvocation.java:839)
	at org.glassfish.jersey.client.ClientRuntime.processFailure(ClientRuntime.java:247)
	at org.glassfish.jersey.client.ClientRuntime.processFailure(ClientRuntime.java:242)
	at org.glassfish.jersey.client.ClientRuntime.access$100(ClientRuntime.java:62)
	at org.glassfish.jersey.client.ClientRuntime$2.lambda$failure$1(ClientRuntime.java:178)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:288)
	at org.glassfish.jersey.client.ClientRuntime$2.failure(ClientRuntime.java:178)
	at org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector.lambda$apply$1(AsyncHttpConnector.java:204)
	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
	at org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector.lambda$retryOperation$3(AsyncHttpConnector.java:246)
	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990)
	at org.asynchttpclient.netty.NettyResponseFuture.abort(NettyResponseFuture.java:273)
	at org.asynchttpclient.netty.channel.NettyConnectListener.onFailure(NettyConnectListener.java:181)
	at org.asynchttpclient.netty.channel.NettyChannelConnector$1.onFailure(NettyChannelConnector.java:108)
	at org.asynchttpclient.netty.SimpleChannelFutureListener.operationComplete(SimpleChannelFutureListener.java:28)
	at org.asynchttpclient.netty.SimpleChannelFutureListener.operationComplete(SimpleChannelFutureListener.java:20)
	at io.netty.util.concurrent.DefaultPromise.notifyListener0(DefaultPromise.java:577)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners0(DefaultPromise.java:570)
	at io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:549)
	at io.netty.util.concurrent.DefaultPromise.notifyListeners(DefaultPromise.java:490)
	at io.netty.util.concurrent.DefaultPromise.setValue0(DefaultPromise.java:615)
	at io.netty.util.concurrent.DefaultPromise.setFailure0(DefaultPromise.java:608)
	at io.netty.util.concurrent.DefaultPromise.tryFailure(DefaultPromise.java:117)
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.fulfillConnectPromise(AbstractNioChannel.java:321)
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:337)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:702)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.pulsar.client.admin.PulsarAdminException: java.util.concurrent.CompletionException: org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector$RetryException: Could not complete the operation. Number of retries has been exhausted. Failed reason: Connection refused: /10.3.114.11:8080
	at org.apache.pulsar.client.admin.internal.BaseResource.getApiException(BaseResource.java:233)
	... 45 common frames omitted
Caused by: java.util.concurrent.CompletionException: org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector$RetryException: Could not complete the operation. Number of retries has been exhausted. Failed reason: Connection refused: /10.3.114.11:8080
	at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
	at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
	at java.util.concurrent.CompletableFuture.orApply(CompletableFuture.java:1385)
	at java.util.concurrent.CompletableFuture$OrApply.tryFire(CompletableFuture.java:1364)
	... 29 common frames omitted
Caused by: org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector$RetryException: Could not complete the operation. Number of retries has been exhausted. Failed reason: Connection refused: /10.3.114.11:8080
	at org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector.lambda$retryOperation$3(AsyncHttpConnector.java:248)
	... 26 common frames omitted
Caused by: java.net.ConnectException: Connection refused: /10.3.114.11:8080
	at org.asynchttpclient.netty.channel.NettyConnectListener.onFailure(NettyConnectListener.java:179)
	... 20 common frames omitted
Caused by: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /10.3.114.11:8080
Caused by: java.net.ConnectException: Connection refused
	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:714)
	at io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:330)
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:334)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:702)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
2021-07-20 19:21:09.450 [main] ERROR i.s.pulsar.handlers.kop.utils.MetadataUtils - Failed to successfully initialize Kafka Metadata PPSADXService/PPSADXMicroService
org.apache.pulsar.client.admin.PulsarAdminException$ServerSideErrorException: HTTP 500 Internal Server Error
	at org.apache.pulsar.client.admin.internal.BaseResource.getApiException(BaseResource.java:209)
	at org.apache.pulsar.client.admin.internal.TopicsImpl$2.failed(TopicsImpl.java:147)
	at org.glassfish.jersey.client.JerseyInvocation$1.failed(JerseyInvocation.java:839)
	at org.glassfish.jersey.client.JerseyInvocation$1.completed(JerseyInvocation.java:820)
	at org.glassfish.jersey.client.ClientRuntime.processResponse(ClientRuntime.java:229)
	at org.glassfish.jersey.client.ClientRuntime.access$200(ClientRuntime.java:62)
	at org.glassfish.jersey.client.ClientRuntime$2.lambda$response$0(ClientRuntime.java:173)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:288)
	at org.glassfish.jersey.client.ClientRuntime$2.response(ClientRuntime.java:173)
	at org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector.lambda$apply$1(AsyncHttpConnector.java:212)
	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975)
	at org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector.lambda$retryOperation$3(AsyncHttpConnector.java:253)
	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975)
	at org.asynchttpclient.netty.NettyResponseFuture.loadContent(NettyResponseFuture.java:222)
	at org.asynchttpclient.netty.NettyResponseFuture.done(NettyResponseFuture.java:257)
	at org.asynchttpclient.netty.handler.AsyncHttpClientHandler.finishUpdate(AsyncHttpClientHandler.java:241)
	at org.asynchttpclient.netty.handler.HttpHandler.handleChunk(HttpHandler.java:114)
	at org.asynchttpclient.netty.handler.HttpHandler.handleRead(HttpHandler.java:143)
	at org.asynchttpclient.netty.handler.AsyncHttpClientHandler.channelRead(AsyncHttpClientHandler.java:78)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
Caused by: javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.glassfish.jersey.client.JerseyInvocation.convertToException(JerseyInvocation.java:914)
	at org.glassfish.jersey.client.JerseyInvocation.access$500(JerseyInvocation.java:77)
	... 54 common frames omitted
2021-07-20 19:21:09.451 [main] INFO  i.s.pulsar.handlers.kop.utils.MetadataUtils - Current state of kafka metadata, cluster: PPSADXService_dcssync_pulsar exists: true, tenant: PPSADXService exists: true, namespace: PPSADXService/PPSADXMicroService exists: true, topic: PPSADXService/PPSADXMicroService/__consumer_offsets exists: false
2021-07-20 19:21:09.451 [main] ERROR i.s.pulsar.handlers.kop.KafkaProtocolHandler - initGroupCoordinator failed with
org.apache.pulsar.client.admin.PulsarAdminException$ServerSideErrorException: HTTP 500 Internal Server Error
	at org.apache.pulsar.client.admin.internal.BaseResource.getApiException(BaseResource.java:209)
	at org.apache.pulsar.client.admin.internal.TopicsImpl$2.failed(TopicsImpl.java:147)
	at org.glassfish.jersey.client.JerseyInvocation$1.failed(JerseyInvocation.java:839)
	at org.glassfish.jersey.client.JerseyInvocation$1.completed(JerseyInvocation.java:820)
	at org.glassfish.jersey.client.ClientRuntime.processResponse(ClientRuntime.java:229)
	at org.glassfish.jersey.client.ClientRuntime.access$200(ClientRuntime.java:62)
	at org.glassfish.jersey.client.ClientRuntime$2.lambda$response$0(ClientRuntime.java:173)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:288)
	at org.glassfish.jersey.client.ClientRuntime$2.response(ClientRuntime.java:173)
	at org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector.lambda$apply$1(AsyncHttpConnector.java:212)
	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975)
	at org.apache.pulsar.client.admin.internal.http.AsyncHttpConnector.lambda$retryOperation$3(AsyncHttpConnector.java:253)
	at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:774)
	at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:750)
	at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488)
	at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1975)
	at org.asynchttpclient.netty.NettyResponseFuture.loadContent(NettyResponseFuture.java:222)
	at org.asynchttpclient.netty.NettyResponseFuture.done(NettyResponseFuture.java:257)
	at org.asynchttpclient.netty.handler.AsyncHttpClientHandler.finishUpdate(AsyncHttpClientHandler.java:241)
	at org.asynchttpclient.netty.handler.HttpHandler.handleChunk(HttpHandler.java:114)
	at org.asynchttpclient.netty.handler.HttpHandler.handleRead(HttpHandler.java:143)
	at org.asynchttpclient.netty.handler.AsyncHttpClientHandler.channelRead(AsyncHttpClientHandler.java:78)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:436)
	at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:324)
	at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:296)
	at io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:251)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
	at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:163)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:714)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:576)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.lang.Thread.run(Thread.java:748)
Caused by: javax.ws.rs.InternalServerErrorException: HTTP 500 Internal Server Error
	at org.glassfish.jersey.client.JerseyInvocation.convertToException(JerseyInvocation.java:914)
	at org.glassfish.jersey.client.JerseyInvocation.access$500(JerseyInvocation.java:77)
	... 54 common frames omitted
2021-07-20 19:21:09.452 [main] ERROR org.apache.pulsar.broker.PulsarService - null
java.lang.IllegalStateException: null
	at com.google.common.base.Preconditions.checkState(Preconditions.java:492)
	at io.streamnative.pulsar.handlers.kop.KafkaProtocolHandler.newChannelInitializers(KafkaProtocolHandler.java:272)
	at org.apache.pulsar.broker.protocol.ProtocolHandlerWithClassLoader.newChannelInitializers(ProtocolHandlerWithClassLoader.java:71)
	at org.apache.pulsar.broker.protocol.ProtocolHandlers.newChannelInitializers(ProtocolHandlers.java:123)
	at org.apache.pulsar.broker.PulsarService.start(PulsarService.java:594)
	at org.apache.pulsar.PulsarBrokerStarter$BrokerStarter.start(PulsarBrokerStarter.java:277)
	at org.apache.pulsar.PulsarBrokerStarter.main(PulsarBrokerStarter.java:346)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.huawei.dmq2.security.dmq.broker.DMQBrokerMain.main(DMQBrokerMain.java:44)
2021-07-20 19:21:09.452 [main] ERROR org.apache.pulsar.PulsarBrokerStarter - Failed to start pulsar service.
org.apache.pulsar.broker.PulsarServerException: java.lang.IllegalStateException
	at org.apache.pulsar.broker.PulsarService.start(PulsarService.java:615)
	at org.apache.pulsar.PulsarBrokerStarter$BrokerStarter.start(PulsarBrokerStarter.java:277)
	at org.apache.pulsar.PulsarBrokerStarter.main(PulsarBrokerStarter.java:346)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.huawei.dmq2.security.dmq.broker.DMQBrokerMain.main(DMQBrokerMain.java:44)
Caused by: java.lang.IllegalStateException: null
	at com.google.common.base.Preconditions.checkState(Preconditions.java:492)
	at io.streamnative.pulsar.handlers.kop.KafkaProtocolHandler.newChannelInitializers(KafkaProtocolHandler.java:272)
	at org.apache.pulsar.broker.protocol.ProtocolHandlerWithClassLoader.newChannelInitializers(ProtocolHandlerWithClassLoader.java:71)
	at org.apache.pulsar.broker.protocol.ProtocolHandlers.newChannelInitializers(ProtocolHandlers.java:123)
	at org.apache.pulsar.broker.PulsarService.start(PulsarService.java:594)
	... 7 common frames omitted
@xiaotongwang1
Copy link
Author

KOP：2.7.0.1

@xiaotongwang1
Copy link
Author

xiaotongwang1 commented Jul 22, 2021 •
edited by BewareMyPower
Loading

出问题的时候，每个broker节点都报类似的错误，__consumer_offsets 操作30秒超时，后面把所有的broker停掉之后，只启动一台，启动前，注释掉broker.conf里面的kop配置，然后再启动，broker恢复正常。
然后再把kop配置上，这个时候才恢复正常。

另外，重启过程中话发下 /tmp/pulsar-nar 下面，少了部分类，删掉后，重启恢复

When a problem happened, each broker node reported a similar error. The __consumer_offsets operation timed out for 30 seconds. After stopping all the brokers, only start one broker. Before starting, comment out the kop configuration in broker.conf, and then the broker started successfully.
Then configure the kop again, and it will return to normal at this time.

In addition, during the restarting process, send a message under /tmp/pulsar-nar. Some classes are missing. After deleting, restart and restore

@BewareMyPower BewareMyPower changed the title [BUG] KOP启动校验失败，导致Pulsar无法启动 [BUG] KoP failed to start for PulsarAdminException Jul 22, 2021
@BewareMyPower
Copy link
Collaborator

This bug is caused by

kop/kafka-impl/src/main/java/io/streamnative/pulsar/handlers/kop/utils/MetadataUtils.java

Line 155 in 96f454a

topics.getList(kafkaMetadataNamespace).stream()

Topics#getList will list both persistent and non-persistent topics. Listing persistent topics only needs to read z-node /managed-ledger/<namespace>/<domain> while listing non-persistent topics will first find each namespace bundle's owner broker.

However, the implementation of broker side is to create an admin client and send HTTP request to itself. There's somehow a deadlock for this implementation.

Here're a correct output for getTopics with 4 bundles:

15:27:50.703 [pulsar-web-40-9] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/七月/2021:15:27:50 +0800] "GET /admin/v2/persistent/public/__kafka HTTP/1.1" 200 3091 "-" "Pulsar-Java-v2.8.0" 43
15:27:50.729 [ForkJoinPool.commonPool-worker-5] INFO  org.apache.pulsar.broker.admin.v2.NonPersistentTopics - [null] Namespace bundle is not owned by any broker public/__kafka/0x00000000_0x40000000
15:27:50.729 [ForkJoinPool.commonPool-worker-10] INFO  org.apache.pulsar.broker.admin.v2.NonPersistentTopics - [null] Namespace bundle is not owned by any broker public/__kafka/0xc0000000_0xffffffff
15:27:50.729 [ForkJoinPool.commonPool-worker-3] INFO  org.apache.pulsar.broker.admin.v2.NonPersistentTopics - [null] Namespace bundle is not owned by any broker public/__kafka/0x40000000_0x80000000
15:27:50.729 [ForkJoinPool.commonPool-worker-12] INFO  org.apache.pulsar.broker.admin.v2.NonPersistentTopics - [null] Namespace bundle is not owned by any broker public/__kafka/0x80000000_0xc0000000
15:27:50.731 [ForkJoinPool.commonPool-worker-3] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/七月/2021:15:27:50 +0800] "GET /admin/v2/non-persistent/public/__kafka/0x40000000_0x80000000 HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0" 9
15:27:50.731 [ForkJoinPool.commonPool-worker-5] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/七月/2021:15:27:50 +0800] "GET /admin/v2/non-persistent/public/__kafka/0x00000000_0x40000000 HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0" 10
15:27:50.731 [ForkJoinPool.commonPool-worker-10] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/七月/2021:15:27:50 +0800] "GET /admin/v2/non-persistent/public/__kafka/0xc0000000_0xffffffff HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0" 7
15:27:50.731 [ForkJoinPool.commonPool-worker-12] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/七月/2021:15:27:50 +0800] "GET /admin/v2/non-persistent/public/__kafka/0x80000000_0xc0000000 HTTP/1.1" 204 0 "-" "Pulsar-Java-v2.8.0" 9
15:27:50.736 [AsyncHttpClient-48-1] INFO  org.eclipse.jetty.server.RequestLog - 127.0.0.1 - - [26/七月/2021:15:27:50 +0800] "GET /admin/v2/non-persistent/public/__kafka HTTP/1.1" 200 2 "-" "Pulsar-Java-v2.8.0" 79

The Namespace bundle is not owned by any broker log is okay but no jetty logs can be seen in your logs.

The simplest fix is to remove the getList call, which has already been removed in master in #522. I'll fix it in branch-2.7.2 soon, while it might introduce some redundant WARN logs from createMissedPartitions.

@BewareMyPower BewareMyPower mentioned this issue Jul 26, 2021
Merged
BewareMyPower added a commit that referenced this issue Jul 26, 2021
@BewareMyPower
[branch-2.7.2] Fix unused getList call to create missed partitions (#626
5da3a66 
)

Fixes #619

See #619 (comment) for details.
@BewareMyPower
Copy link
Collaborator

It's fixed by #626

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
type/bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@xiaotongwang1 @BewareMyPower