Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Rest-client-mutiny issue, exhausting thread pool #29301

Closed
Chexpir opened this issue Nov 16, 2022 · 13 comments
Closed

Rest-client-mutiny issue, exhausting thread pool #29301

Chexpir opened this issue Nov 16, 2022 · 13 comments
Labels
area/rest-client area/resteasy-classic kind/bug Something isn't working triage/wontfix This will not be worked on

Comments

@Chexpir
Copy link
Contributor

Chexpir commented Nov 16, 2022 •
edited
Loading

Describe the bug

When using rest-client-mutiny, returning a Uni, it starts failing after configured pool size is exhausted, default appeared to be 50.
quarkus.rest-client.config-key.connection-pool-size=5

connect-timeout,read-timeout,connection-ttl variables don't affect the result.
Sometimes, it manages to do "yet another round" of requests, so if pool-size is N, it appear to get 2*N working.

My workaround for now is set scope=RequestScoped, this issue is reproducible with Singleton, Dependent and ApplicationScoped scopes.

Expected behavior

I was expecting to manage infinite sequencial requests with the pool.

Actual behavior

It does not manage infinite requests, they are silently hanging.

When stopped the service, this is the error we get on each of the hanging threads

{
  "class": "java.util.concurrent.ThreadPoolExecutor$AbortPolicy",
  "method": "rejectedExecution",
  "line": 2065
},
{
  "class": "java.util.concurrent.ThreadPoolExecutor",
  "method": "reject",
  "line": 833
},
{
  "class": "java.util.concurrent.ScheduledThreadPoolExecutor",
  "method": "delayedExecute",
  "line": 340
},
{
  "class": "java.util.concurrent.ScheduledThreadPoolExecutor",
  "method": "schedule",
  "line": 562
},
{
  "class": "io.quarkus.mutiny.runtime.MutinyInfrastructure$2",
  "method": "schedule",
  "line": 54
},
{
  "class": "io.smallrye.mutiny.operators.uni.UniDelayOnItem$UniDelayOnItemProcessor",
  "method": "onItem",
  "line": 54
},
{
  "class": "io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription",
  "method": "forward",
  "line": 38
},
{
  "class": "io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem$KnownItemSubscription",
  "method": "access$100",
  "line": 26
},
{
  "class": "io.smallrye.mutiny.operators.uni.builders.UniCreateFromKnownItem",
  "method": "subscribe",
  "line": 23
},
{
  "class": "io.smallrye.mutiny.operators.AbstractUni",
  "method": "subscribe",
  "line": 36
},
{
  "class": "io.smallrye.mutiny.operators.uni.UniDelayOnItem",
  "method": "subscribe",
  "line": 28
},
{
  "class": "io.smallrye.mutiny.operators.AbstractUni",
  "method": "subscribe",
  "line": 36
},
{
  "class": "io.smallrye.mutiny.converters.uni.UniToMultiPublisher$UniToMultiSubscription",
  "method": "request",
  "line": 74
},
{
  "class": "io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapInner",
  "method": "onSubscribe",
  "line": 601
},
{
  "class": "io.smallrye.mutiny.converters.uni.UniToMultiPublisher",
  "method": "subscribe",
  "line": 26
},
{
  "class": "io.smallrye.mutiny.groups.MultiCreate$1",
  "method": "subscribe",
  "line": 163
},
{
  "class": "io.smallrye.mutiny.operators.multi.MultiFlatMapOp$FlatMapMainSubscriber",
  "method": "onItem",
  "line": 193
},
{
  "class": "io.smallrye.mutiny.subscription.MultiSubscriber",
  "method": "onNext",
  "line": 61
},
{
  "class": "io.smallrye.mutiny.operators.multi.processors.UnicastProcessor",
  "method": "drainWithDownstream",
  "line": 103
},
{
  "class": "io.smallrye.mutiny.operators.multi.processors.UnicastProcessor",
  "method": "drain",
  "line": 134
},
{
  "class": "io.smallrye.mutiny.operators.multi.processors.UnicastProcessor",
  "method": "onNext",
  "line": 200
},
{
  "class": "io.smallrye.mutiny.operators.multi.processors.SerializedProcessor",
  "method": "onNext",
  "line": 105
},
{
  "class": "io.smallrye.mutiny.subscription.SerializedSubscriber",
  "method": "onItem",
  "line": 75
},
{
  "class": "io.smallrye.mutiny.subscription.MultiSubscriber",
  "method": "onNext",
  "line": 61
},
{
  "class": "io.smallrye.mutiny.operators.multi.MultiRetryWhenOp$RetryWhenOperator",
  "method": "onFailure",
  "line": 129
},
{
  "class": "io.smallrye.mutiny.subscription.MultiSubscriber",
  "method": "onError",
  "line": 73
},
{
  "class": "io.smallrye.mutiny.converters.uni.UniToMultiPublisher$UniToMultiSubscription",
  "method": "onFailure",
  "line": 103
},
{
  "class": "io.smallrye.mutiny.operators.uni.UniOperatorProcessor",
  "method": "onFailure",
  "line": 54
},
{
  "class": "io.smallrye.mutiny.operators.uni.UniOperatorProcessor",
  "method": "onFailure",
  "line": 54
},
{
  "class": "io.smallrye.mutiny.operators.uni.UniOperatorProcessor",
  "method": "onFailure",
  "line": 54
},
{
  "class": "io.smallrye.mutiny.operators.uni.UniOnItemConsume$UniOnItemComsumeProcessor",
  "method": "onFailure",
  "line": 65
},
{
  "class": "io.smallrye.mutiny.operators.uni.UniOperatorProcessor",
  "method": "onFailure",
  "line": 54
},
{
  "class": "io.smallrye.mutiny.operators.uni.builders.UniCreateFromCompletionStage$CompletionStageUniSubscription",
  "method": "forwardResult",
  "line": 58
},
{
  "class": "java.util.concurrent.CompletableFuture",
  "method": "uniWhenComplete",
  "line": 863
},
{
  "class": "java.util.concurrent.CompletableFuture$UniWhenComplete",
  "method": "tryFire",
  "line": 841
},
{
  "class": "java.util.concurrent.CompletableFuture",
  "method": "postComplete",
  "line": 510
},
{
  "class": "java.util.concurrent.CompletableFuture$AsyncSupply",
  "method": "run",
  "line": 1773
},
{
  "class": "org.jboss.resteasy.microprofile.client.impl.MpClientInvocation$Decorator",
  "method": "lambda$decorate$0",
  "line": 93
},
{
  "class": "io.smallrye.context.impl.wrappers.SlowContextualRunnable",
  "method": "run",
  "line": 19
},
{
  "class": "io.quarkus..core.runtime.VertxCoreRecorder$14",
  "method": "runWith",
  "line": 555
},
{
  "class": "org.jboss.threads.EnhancedQueueExecutor$Task",
  "method": "run",
  "line": 2449
},
{
  "class": "org.jboss.threads.EnhancedQueueExecutor$ThreadBody",
  "method": "run",
  "line": 1478
},
{
  "class": "org.jboss.threads.DelegatingRunnable",
  "method": "run",
  "line": 29
},
{
  "class": "org.jboss.threads.ThreadLocalResettingRunnable",
  "method": "run",
  "line": 29
},
{
  "class": "io.netty.util.concurrent.FastThreadLocalRunnable",
  "method": "run",
  "line": 30
},
{
  "class": "java.lang.Thread",
  "method": "run",
  "line": 833
},
{
  "class": "com.oracle.svm.core.thread.PlatformThreads",
  "method": "threadStartRoutine",
  "line": 704
},
{
  "class": "com.oracle.svm.core.posix.thread.PosixPlatformThreads",
  "method": "pthreadStartRoutine",
  "line": 202
}```

### How to Reproduce?

Library is deprecated, if you think there is any chance you fix it, I will create a reproducer.
I am not expecting a fix, just reporting it and maybe letting me know if I am doing something wrong...

My code is returning Uni<Void>:

 @RestClient
private final SomeClient client; 
 .....
Uni<Void> .... {
....
   client.sendResult(getAuthorizationHeader(), parameter,  entity)
                    .replaceWithVoid()
                    .invoke(logWebhookSent(entity));

}


### Output of `uname -a` or `ver`

_No response_

### Output of `java -version`

17.0.1

### GraalVM version (if different from Java)

22.2

### Quarkus version or git rev

2.14.0.Final

### Build tool (ie. output of `mvnw --version` or `gradlew --version`)

gradle 7.5.1

### Additional information

We started using mutiny instead of reactive because we needed this PR merged to use it https://github.com/quarkusio/quarkus/issues/27901
@Chexpir Chexpir added the kind/bug Something isn't working label Nov 16, 2022
@quarkus-bot
Copy link

quarkus-bot bot commented Nov 16, 2022

/cc @Sgitario, @cescoffier, @geoand, @jponge

@cescoffier
Copy link
Member

That's the expected behavior. We limit the number of outgoing connections to the same endpoints. The5 magical numbers come from browsers. I recommend increasing it but also understanding that the target system may not have infinite concurrency.

Using RequestScope creates a new pool every time; it's inefficient in terms of resource usage.

@cescoffier
Copy link
Member

BTW, you can increase the number of connections and combine them with @Bulkead.

@Chexpir
Copy link
Contributor Author

Chexpir commented Nov 16, 2022

@cescoffier thank you very much Clement for dedicating time to this.

Just to be clear, connections are not concurrent, so I was expecting to reuse the connections, or TTL configuration to drop those connections.
I know RequestScoped is not efficient, hence here I am writing (also it's a short-term solution, I'll be back on rest client reactive as soon as I can configure SSL for RestClientBuilder).

@cescoffier
Copy link
Member

If the requests are sequential, it should not be a problem. Once the connection is closed or is not used anymore it should be recycled. Do you have reproducer?

@Chexpir
Copy link
Contributor Author

Chexpir commented Nov 16, 2022

@cescoffier I will create one as soon as I have a short-term fix for my project and put it here.

@cescoffier cescoffier added the triage/needs-reproducer We are waiting for a reproducer. label Nov 16, 2022
@Chexpir
Copy link
Contributor Author

Chexpir commented Nov 17, 2022 •
edited
Loading

@cescoffier Here's a reproducer, I was expecting once I kept it simpler to dissapear, but still there.
https://github.com/Chexpir/files/blob/main/quarkus-reproducer-29301.zip

I have reduced the pool-size to 5, to be easily reproducible.
I am calling GET http://localhost:8080/hello 7 times, and only the first 5 result in a webhook request being sent.

2022-11-17 09:17:35,049 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:36,220 INFO  [io.qua.rep.Adapter] (executor-thread-0) [{}] Successfully sent
2022-11-17 09:17:41,116 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:41,716 INFO  [io.qua.rep.Adapter] (executor-thread-0) [{}] Successfully sent
2022-11-17 09:17:42,570 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:43,163 INFO  [io.qua.rep.Adapter] (executor-thread-0) [{}] Successfully sent
2022-11-17 09:17:44,286 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:45,077 INFO  [io.qua.rep.Adapter] (executor-thread-0) [{}] Successfully sent
2022-11-17 09:17:46,174 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:46,897 INFO  [io.qua.rep.Adapter] (executor-thread-0) [{}] Successfully sent
2022-11-17 09:17:47,870 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:50,398 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:51,553 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook
2022-11-17 09:17:52,891 INFO  [io.qua.rep.Adapter] (vert.x-eventloop-thread-0) Here preparing webhook

@Chexpir
Copy link
Contributor Author

Chexpir commented Nov 25, 2022

@cescoffier Reminder I attached a reproducer, so we remove the tag ;-)

Note: I tried to put it with a proper automated tests failing, but it was taking more time for some reason than the whole reproducer.

@geoand geoand removed the triage/needs-reproducer We are waiting for a reproducer. label Nov 25, 2022
@cescoffier
Copy link
Member

@Chexpir Thanks for the reproducer and it's interesting.

Basically, the connections are not recycled because you don't read the body of the response. As your REST Client method returns a Uni<Response>, we seem to expect that you want to read the body.

I would recommend switching to RESTEasy Reactive and the Reactive Rest Client. The usage of Mutiny in this context is not doing what you think and, as indicated in the log, is deprecated.

I'm a bit stopped in my tests as the service you use is now rejecting my requests.... (Too many requests)

@Chexpir
Copy link
Contributor Author

Chexpir commented Nov 28, 2022 •
edited
Loading

Interesting! so moving to Uni should probably stop the issue?
We moved from Reactive to mutiny due to #27901 (we need to support insecure and secure connections) but it will be soon be merged and we'll be back to Reactive.

@cescoffier
Copy link
Member

If you use the reactive REST client, the issue does not happen. So, it's a bug in the classic REST client. Unfortunately, I won't be able to help on this one.

@Chexpir
Copy link
Contributor Author

Chexpir commented Dec 13, 2022

Thanks! Sorry, my question was wrong. I meant if moving to Uni<Void> instead of Uni should probably stop the issue?

Nevertheless, do you want me to close the issue to clean up the board? Or should I leave it opened?

@cescoffier
Copy link
Member

I would close it as won't fix - 1) it's a code issue, 2) it's resteasy classic issue that does not happen with resteasy reactive.

@cescoffier cescoffier closed this as not planned Won't fix, can't repro, duplicate, stale Dec 13, 2022
@cescoffier cescoffier added the triage/wontfix This will not be worked on label Dec 13, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
area/rest-client area/resteasy-classic kind/bug Something isn't working triage/wontfix This will not be worked on
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@cescoffier @Chexpir @geoand