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 2021/04/21 02:19:39 UTC
[GitHub] [pulsar] devinbost opened a new issue #10293: [Functions] Unable to create/update functions, Admin operations often fail, and performance is unusably slow
devinbost opened a new issue #10293:
URL: https://github.com/apache/pulsar/issues/10293
I created a build based on master (2.8.0-SNAPSHOT), and I'm getting a number of issues.
First of all, the ingestion rate is very slow, at least 100th of the typical rate.
Attempts to publish often timeout with `Unable to publish to topic` or `Unable to create Pulsar Producer: org.apache.pulsar.client.api.PulsarClientException$TimeoutException`
Here are more:
> java.util.concurrent.CompletionException: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> Caused by: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> java.util.concurrent.CompletionException: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> Caused by: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> 2021-04-21T01:59:43,535 [pulsar-io-28-56] WARN org.apache.pulsar.broker.service.ServerCnx - [/10.20.69.28:51426][persistent://feedsmyTenant1/myNamespace-partition-3][myTenant3/myNamespace/function1] Failed to create consumer: consumerId=4, Failed to load topic within timeout
> java.util.concurrent.CompletionException: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> Caused by: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> java.util.concurrent.CompletionException: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> Caused by: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> 2021-04-21T01:59:43,535 [pulsar-io-28-56] WARN org.apache.pulsar.broker.service.ServerCnx - [/10.20.69.28:51426][persistent://feedsmyTenant1/myNamespace-partition-3][myTenant3/myNamespace/function1] Failed to create consumer: consumerId=3, Failed to load topic within timeout
> java.util.concurrent.CompletionException: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> Caused by: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> 2021-04-21T01:59:43,545 [pulsar-io-28-60] WARN org.apache.pulsar.broker.service.ServerCnx - [/10.20.69.29:57784][persistent://myTenant2/events/all][myTenant2/events/all-pass-through] Failed to create consumer: consumerId=0, Failed to load topic within timeout
> java.util.concurrent.CompletionException: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> Caused by: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> 2021-04-21T01:59:43,551 [pulsar-io-28-62] WARN org.apache.pulsar.broker.service.ServerCnx - [/10.20.69.29:58218][persistent://myTenant2/requests/commands][myTenant2/requests/commands-router] Failed to create consumer: consumerId=0, Failed to load topic within timeout
> java.util.concurrent.CompletionException: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> Caused by: org.apache.pulsar.common.util.FutureUtil$LowOverheadTimeoutException: Failed to load topic within timeout
> java.util.concurrent.TimeoutException: Idle timeout expired: 30001/30000 ms
> java.util.concurrent.TimeoutException: Idle timeout expired: 30001/30000 ms
Also, when I try to update a function, I get this exception 100% of the time:
> 2021-04-21T01:43:37,293 [pulsar-web-46-14] ERROR org.apache.pulsar.functions.worker.rest.api.ComponentImpl - Update Failed
> org.apache.pulsar.client.admin.PulsarAdminException: java.util.concurrent.CompletionException: org.asynchttpclient.exception.RemotelyClosedException: Remotely closed
> at org.apache.pulsar.client.admin.internal.BaseResource.getApiException(BaseResource.java:229) ~[org.apache.pulsar-pulsar-client-admin-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
> at org.apache.pulsar.client.admin.internal.FunctionsImpl.lambda$updateOnWorkerLeaderAsync$13(FunctionsImpl.java:1078) ~[org.apache.pulsar-pulsar-client-admin-original-2.8.0-SNAPSHOT.jar:2.8.0-SNAPSHOT]
> at java.util.concurrent.CompletableFuture.uniExceptionally(CompletableFuture.java:884) ~[?:1.8.0_282]
> at java.util.concurrent.CompletableFuture$UniExceptionally.tryFire(CompletableFuture.java:866) ~[?:1.8.0_282]
> at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:488) ~[?:1.8.0_282]
> at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1990) ~[?:1.8.0_282]
> at org.asynchttpclient.netty.NettyResponseFuture.abort(NettyResponseFuture.java:273) ~[org.asynchttpclient-async-http-client-2.12.1.jar:?]
> at org.asynchttpclient.netty.request.NettyRequestSender.abort(NettyRequestSender.java:473) ~[org.asynchttpclient-async-http-client-2.12.1.jar:?]
> at org.asynchttpclient.netty.request.NettyRequestSender.handleUnexpectedClosedChannel(NettyRequestSender.java:484) ~[org.asynchttpclient-async-http-client-2.12.1.jar:?]
> at org.asynchttpclient.netty.handler.AsyncHttpClientHandler.channelInactive(AsyncHttpClientHandler.java:145) ~[org.asynchttpclient-async-http-client-2.12.1.jar:?]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.handler.stream.ChunkedWriteHandler.channelInactive(ChunkedWriteHandler.java:138) ~[io.netty-netty-handler-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.ChannelInboundHandlerAdapter.channelInactive(ChannelInboundHandlerAdapter.java:81) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.handler.codec.http.HttpContentDecoder.channelInactive(HttpContentDecoder.java:235) ~[io.netty-netty-codec-http-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelInactive(CombinedChannelDuplexHandler.java:418) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.handler.codec.ByteToMessageDecoder.channelInputClosed(ByteToMessageDecoder.java:389) ~[io.netty-netty-codec-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.handler.codec.ByteToMessageDecoder.channelInactive(ByteToMessageDecoder.java:354) ~[io.netty-netty-codec-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.handler.codec.http.HttpClientCodec$Decoder.channelInactive(HttpClientCodec.java:311) ~[io.netty-netty-codec-http-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.CombinedChannelDuplexHandler.channelInactive(CombinedChannelDuplexHandler.java:221) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.fireChannelInactive(AbstractChannelHandlerContext.java:241) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.DefaultChannelPipeline$HeadContext.channelInactive(DefaultChannelPipeline.java:1405) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:248) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.DefaultChannelPipeline.fireChannelInactive(DefaultChannelPipeline.java:901) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.AbstractChannel$AbstractUnsafe$8.run(AbstractChannel.java:831) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[io.netty-netty-common-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:472) ~[io.netty-netty-common-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:497) ~[io.netty-netty-transport-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) ~[io.netty-netty-common-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[io.netty-netty-common-4.1.63.Final.jar:4.1.63.Final]
> at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) [io.netty-netty-common-4.1.63.Final.jar:4.1.63.Final]
> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_282]
> Caused by: java.util.concurrent.CompletionException: org.asynchttpclient.exception.RemotelyClosedException: Remotely closed
> at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292) ~[?:1.8.0_282]
> at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308) ~[?:1.8.0_282]
> at java.util.concurrent.CompletableFuture.uniAccept(CompletableFuture.java:661) ~[?:1.8.0_282]
> at java.util.concurrent.CompletableFuture$UniAccept.tryFire(CompletableFuture.java:646) ~[?:1.8.0_282]
> ... 38 more
> Caused by: org.asynchttpclient.exception.RemotelyClosedException: Remotely closed
> at org.asynchttpclient.exception.RemotelyClosedException.INSTANCE(Unknown Source) ~[org.asynchttpclient-async-http-client-2.12.1.jar:?]
> 500 Internal Server Error HTTP/1.1
I suspect this is related to #10291
--
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
[GitHub] [pulsar] devinbost commented on issue #10293: [Functions] Unable to create/update functions and Admin operations often fail
Posted by GitBox <gi...@apache.org>.
devinbost commented on issue #10293:
URL: https://github.com/apache/pulsar/issues/10293#issuecomment-823736495
Note: The slow performance was resolved after switching from debug log level to info log level, but the Admin operations are still failing.
--
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
[GitHub] [pulsar] devinbost commented on issue #10293: [Functions] Unable to create/update functions, Admin operations often fail, and performance is unusably slow
Posted by GitBox <gi...@apache.org>.
devinbost commented on issue #10293:
URL: https://github.com/apache/pulsar/issues/10293#issuecomment-823727714
I'm also getting bookie timeouts, like:
`2021-04-21T02:25:14,625 [BookKeeperClientWorker-OrderedExecutor-24-0] WARN org.apache.bookkeeper.client.PendingAddOp - Failed to write entry (1211784, 9): Bookie operation timeout`
--
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
[GitHub] [pulsar] codelipenghui commented on issue #10293: [Functions] Unable to create/update functions and Admin operations often fail
Posted by GitBox <gi...@apache.org>.
codelipenghui commented on issue #10293:
URL: https://github.com/apache/pulsar/issues/10293#issuecomment-1058891261
The issue had no activity for 30 days, mark with Stale label.
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org
For queries about this service, please contact Infrastructure at:
users@infra.apache.org
[GitHub] [pulsar] devinbost edited a comment on issue #10293: [Functions] Unable to create/update functions, Admin operations often fail, and performance is unusably slow
Posted by GitBox <gi...@apache.org>.
devinbost edited a comment on issue #10293:
URL: https://github.com/apache/pulsar/issues/10293#issuecomment-823727714
I'm also getting bookie timeouts (in the broker logs), like:
`2021-04-21T02:25:14,625 [BookKeeperClientWorker-OrderedExecutor-24-0] WARN org.apache.bookkeeper.client.PendingAddOp - Failed to write entry (1211784, 9): Bookie operation timeout`
--
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