I am using Spring Reactive WebClient to make HTTP calls. It uses JettyClientHttpConnector underneath. I am facing an issue that is frequent but doesn't always occur.
On spinning up the service sometimes all the calls through the web client are throwing InterruptedException(stack trace at the end). After about 200 requests we start receiving the below "Insufficient configured threads" exception possibly because earlier threads are not being released(is it possible to release these threads so they take on the next requests?).
What is causing the requests to fail with InterruptedException? I have verified that requests are not reaching the downstream service.
org.springframework.web.reactive.function.client.WebClientRequestException: Insufficient configured threads: required=200 \u003c max=200 for QueuedThreadPool[CustomJettyHttpClient@4fe3f9ef]@5ee9a1c4{STARTED,8\u003c=11\u003c=200,i=2,r=-1,q=0}[ReservedThreadExecutor@2e87a488{reserved=0/2,pending=0}]; nested exception is java.lang.IllegalStateException: Insufficient configured threads: required=200 \u003c max=200 for QueuedThreadPool[CustomJettyHttpClient@4fe3f9ef]@5ee9a1c4{STARTED,8\u003c=11\u003c=200,i=2,r=-1,q=0}[ReservedThreadExecutor@2e87a488{reserved=0/2,pending=0}]
Dependency
org.springframework:spring-webflux:jar:5.3.21.RELEASE
org.eclipse.jetty:jetty-client:9.4.48v20220622
org.springframework.boot:spring-boot-starter-jetty:jar:2.7.1.RELEASE
org.springframework.cloud:spring-cloud-stream-reactive:jar:2.2.0.RELEASE
WebClientConfig
WebClient.Builder.clone()
.clientConnector(new JettyClientHttpConnector(new HttpClient()))
.exchangeStrategies(ExchangeStrategies.builder().codecs((configurer) -> {
configurer.defaultCodecs().maxInMemorySize(2097152);
}).build())
.build();
ClientCall
URI request = UriComponentsBuilder
.fromUriString("foo")
.path("/path")
.build();
webClient.post()
.uri(request)
.contentType(MediaType.APPLICATION_JSON)
.body(BodyInserters.fromObject(requestbody))
.retrieve()
.bodyToMono(responsebody);
Exception:
org.springframework.web.reactive.function.client.WebClientRequestException: nested exception is java.lang.InterruptedException?
org.springframework.web.reactive.function.client.ExchangeFunctions$DefaultExchangeFunction.lambda$wrapException$9(ExchangeFunctions.java:141) ~[spring-webflux-5.3.21.jar!/:5.3.21]?
reactor.core.publisher.MonoErrorSupplied.subscribe(MonoErrorSupplied.java:55) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Mono.subscribe(Mono.java:4397) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:222) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxPeek$PeekSubscriber.onError(FluxPeek.java:222) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Operators.error(Operators.java:198) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoError.subscribe(MonoError.java:53) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.web.client.TraceExchangeFilterFunction$MonoWebClientTrace.subscribe(TraceExchangeFilterFunction.java:136) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onNext(ScopePassingSpanSubscriber.java:89) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2398) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.request(ScopePassingSpanSubscriber.java:75) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:110) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onSubscribe(ScopePassingSpanSubscriber.java:68) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.MonoCurrentContext.subscribe(MonoCurrentContext.java:36) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoDeferContextual.subscribe(MonoDeferContextual.java:55) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoDefer.subscribe(MonoDefer.java:52) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Mono.subscribe(Mono.java:4397) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxFlatMap.trySubscribeScalarMap(FluxFlatMap.java:200) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap.subscribeOrReturn(MonoFlatMap.java:53) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:57) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxRetryWhen.subscribe(FluxRetryWhen.java:77) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoRetryWhen.subscribeOrReturn(MonoRetryWhen.java:46) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:57) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onNext(FluxMapFuseable.java:129) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2398) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:110) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1816) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:249) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1816) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:151) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1816) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:151) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.onNext(FluxFilterFuseable.java:118) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onNext(ScopePassingSpanSubscriber.java:89) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2398) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.request(ScopePassingSpanSubscriber.java:75) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.request(FluxFilterFuseable.java:191) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:110) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxFilterFuseable$FilterFuseableSubscriber.onSubscribe(FluxFilterFuseable.java:87) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onSubscribe(ScopePassingSpanSubscriber.java:68) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.MonoCurrentContext.subscribe(MonoCurrentContext.java:36) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:64) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:157) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onNext(ScopePassingSpanSubscriber.java:89) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2398) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.request(ScopePassingSpanSubscriber.java:75) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:110) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onSubscribe(ScopePassingSpanSubscriber.java:68) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.MonoCurrentContext.subscribe(MonoCurrentContext.java:36) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.Mono.subscribe(Mono.java:4397) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxFlatMap$FlatMapMain.onNext(FluxFlatMap.java:426) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ScopePassingSpanSubscriber.onNext(ScopePassingSpanSubscriber.java:89) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.publisher.FluxPublishOn$PublishOnSubscriber.runAsync(FluxPublishOn.java:440) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.publisher.FluxPublishOn$PublishOnSubscriber.run(FluxPublishOn.java:527) ~[reactor-core-3.4.19.jar!/:3.4.19]?
org.springframework.cloud.sleuth.instrument.reactor.ReactorSleuth.lambda$null$6(ReactorSleuth.java:324) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?
reactor.core.scheduler.WorkerTask.call(WorkerTask.java:84) ~[reactor-core-3.4.19.jar!/:3.4.19]?
reactor.core.scheduler.WorkerTask.call(WorkerTask.java:37) ~[reactor-core-3.4.19.jar!/:3.4.19]?
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]?
java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) ~[na:na]?
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]?
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]?
java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]?Caused by: java.lang.InterruptedException: null?
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1040) ~[na:na]?
java.base/java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1345) ~[na:na]?
java.base/java.util.concurrent.CountDownLatch.await(CountDownLatch.java:232) ~[na:na]?
org.eclipse.jetty.io.ManagedSelector.doStart(ManagedSelector.java:127) ~[jetty-io-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:110) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.io.SelectorManager.doStart(SelectorManager.java:262) ~[jetty-io-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:110) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.client.AbstractConnectorHttpClientTransport.doStart(AbstractConnectorHttpClientTransport.java:64) ~[jetty-client-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:169) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:110) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.client.HttpClient.doStart(HttpClient.java:255) ~[jetty-client-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:73) ~[jetty-util-9.4.48.v20220622.jar!/:9.4.48.v20220622]?
org.springframework.http.client.reactive.JettyClientHttpConnector.connect(JettyClientHttpConnector.java:115) ~[spring-web-5.3.21.jar!/:5.3.21]?
org.springframework.web.reactive.function.client.ExchangeFunctions$DefaultExchangeFunction.exchange(ExchangeFunctions.java:103) ~[spring-webflux-5.3.21.jar!/:5.3.21]?
org.springframework.cloud.sleuth.instrument.web.client.TraceExchangeFilterFunction$MonoWebClientTrace.subscribe(TraceExchangeFilterFunction.java:135) ~[spring-cloud-sleuth-instrumentation-3.1.2.jar!/:3.1.2]?\t... 69 common frames omitted?
Try starting your Jetty HttpClient before you give it to the Spring JettyClientHttpConnector.
Your code:
WebClient.Builder.clone()
.clientConnector(new JettyClientHttpConnector(new HttpClient()))
...
Changed code:
HttpClient httpClient = new HttpClient();
QueuedThreadPool threadPool = new QueuedThreadPool();
threadPool.setMaxThreads(400);
httpClient.setExecutor(threadPool);
httpClient.start();
WebClient.Builder.clone()
.clientConnector(new JettyClientHttpConnector(httpClient))
...
That will let Jetty components start properly, before the lazy init of the spring side. Bonus is that you can now control the thread pool.
The 200 threads used can be quite normal, depends on how you are using the client. (eg: all 200 requests could be active at the same time and being processed).
It's not uncommon on aggressive HttpClient usage to have a system with thousands of threads connected to tens of thousands of remote sites (more common with HTTP/2 usage than HTTP/1)
You can periodically use httpClient.dump() to get a String dump of the state of the HttpClient at that point in time, including how it's using the connections, connection pools, requests, responses, thread pool, etc ...
Be aware of configuration on Jetty HttpClient for things like setMaxConnectionsPerDestination and setMaxRequestsQueuedPerDestination which could prove useful to know about in your situation.