spring-cloud / spring-cloud-circuitbreaker

Spring Cloud Circuit Breaker API and Implementations
Apache License 2.0
328 stars 109 forks source link

Spring Boot Semaphore Bulkhead Creating Threadpool #147

Closed kkotamar closed 2 years ago

kkotamar commented 2 years ago

Is your feature request related to a problem? Please describe. Our application makes lot api calls to other applications. So our application executes these api calls using feign client in a thread pool managed by application. We recently started integrating with Resilience4j/feign/spring cloud. When integrating with resilience4j bulkhead pattern, spring cloud is creating another threadpool even though configured for semaphore bulk head. Our goal is to not turnoff this additional threadpool created by resilience4j. So we tried to switch to using semaphore bulkhead. But it still creates new threadpool or submits to fork join pool. I tried not using the bulkhead pattern but still a new threadpool is created.

Describe the solution you'd like Provide a flag to run the remote calls on same thread. I see below as an option.

  1. Provide a flag to not submit to executor service in Resilience4JCircuitBreaker.java

Describe alternatives you've considered A clear and concise description of any alternative solutions or features you've considered.

Additional context Add any other context or screenshots about the feature request here.

ryanjbaxter commented 2 years ago

Can you provide a complete, minimal, verifiable sample that reproduces the problem? It should be available as a GitHub (or similar) project or attached to this issue as a zip file.

kkotamar commented 2 years ago

I will provide example.

ryanjbaxter commented 2 years ago

Could you not pass your own executor service to the circuit breaker factory? https://github.com/spring-cloud/spring-cloud-circuitbreaker/blob/main/spring-cloud-circuitbreaker-resilience4j/src/main/java/org/springframework/cloud/circuitbreaker/resilience4j/Resilience4JCircuitBreakerFactory.java#L104

kkotamar commented 2 years ago

Here is an example of logs. In the logs feign client is executed in a seperate thread pool with name "pool-2-thread-x". 2022-05-20 10:20:37.867 INFO 44605 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1320 ms 2022-05-20 10:20:39.762 INFO 44605 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator' 2022-05-20 10:20:39.830 INFO 44605 --- [ main] o.s.b.w.embedded.tomc [test.logs.zip](https://github.com/spring-cloud/spring-cloud-circuitbreaker/files/8740875/test.logs.zip) at.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2022-05-20 10:20:39.846 INFO 44605 --- [ main] com.springcloud.App : Started App in 3.657 seconds (JVM running for 9.244) 2022-05-20 10:20:40.212 INFO 44605 --- [)-192.168.7.110] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet' 2022-05-20 10:20:40.212 INFO 44605 --- [)-192.168.7.110] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet' 2022-05-20 10:20:40.214 INFO 44605 --- [)-192.168.7.110] o.s.web.servlet.DispatcherServlet : Completed initialization in 2 ms 2022-05-20 10:20:59.603 DEBUG 44605 --- [pool-2-thread-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] ---> GET https://run.mocky.io/v3/db578cf2-a126-48df-82c1-868318c25e2f HTTP/1.1 2022-05-20 10:20:59.603 DEBUG 44605 --- [pool-2-thread-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] ---> END HTTP (0-byte body) 2022-05-20 10:21:00.282 DEBUG 44605 --- [pool-2-thread-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] <--- HTTP/1.1 200 OK (679ms) 2022-05-20 10:21:00.283 DEBUG 44605 --- [pool-2-thread-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] content-length: 22 2022-05-20 10:21:00.283 DEBUG 44605 --- [pool-2-thread-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] content-type: application/json; charset=UTF-8

ryanjbaxter commented 2 years ago

Thanks.

See my question 39 minutes ago

kkotamar commented 2 years ago

@ryanjbaxter Thanks for providing an option. I would not want this to execute in a seperate threadpool at all since this is already getting executed in a seperate thread created by application service layer.

ryanjbaxter commented 2 years ago

I am still a little confused because you said the problem occurs when using a semaphore bulkhead however your changes in the PR seem to only take place when not using a bulkhead https://github.com/spring-cloud/spring-cloud-circuitbreaker/pull/148/files#diff-2607a9cbb0e372736be5ffe6ba5ca96d4cfeadd25671af0f81a457640250f957R125

kkotamar commented 2 years ago

Sorry for confusion. I was initially testing with semaphore bulkhead because i read somewhere about semaphore bulkhead runs in same thread. But it did not work. I tested with out any bulkheads(either semaphore or threadpool) and it still creates thread pool. For our case, bulkhead is not required. That is why i created PR with regular Circuit breaker with out bulkhead.

ryanjbaxter commented 2 years ago

So you tried setting spring.cloud.circuitbreaker.resilience4j.enableSemaphoreDefaultBulkhead=true? Again a working sample would help.

kkotamar commented 2 years ago

Yes. I tried with that option. Here are the logs. A new thread pool is created and thread name is t#getStatus()-x

2022-05-20 12:47:52.851 DEBUG 58015 --- [ main] com.springcloud.App : Running with Spring Boot v2.6.3, Spring v5.3.15 2022-05-20 12:47:52.851 INFO 58015 --- [ main] com.springcloud.App : No active profile set, falling back to default profiles: default 2022-05-20 12:47:53.818 INFO 58015 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=c4ef7f99-1906-3ae0-8dfa-40afb6c71650 2022-05-20 12:47:54.342 INFO 58015 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http) 2022-05-20 12:47:54.372 INFO 58015 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2022-05-20 12:47:54.372 INFO 58015 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.56] 2022-05-20 12:47:54.467 INFO 58015 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext 2022-05-20 12:47:54.468 INFO 58015 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1580 ms 2022-05-20 12:47:56.539 INFO 58015 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator' 2022-05-20 12:47:56.608 INFO 58015 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2022-05-20 12:47:56.624 INFO 58015 --- [ main] com.springcloud.App : Started App in 4.143 seconds (JVM running for 9.844) 2022-05-20 12:47:56.973 INFO 58015 --- [)-192.168.7.110] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet' 2022-05-20 12:47:56.974 INFO 58015 --- [)-192.168.7.110] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet' 2022-05-20 12:47:56.975 INFO 58015 --- [)-192.168.7.110] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms 2022-05-20 12:48:06.199 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] ---> GET https://run.mocky.io/v3/db578cf2-a126-48df-82c1-868318c25e2f HTTP/1.1 2022-05-20 12:48:06.199 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] ---> END HTTP (0-byte body) 2022-05-20 12:48:07.042 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] <--- HTTP/1.1 200 OK (842ms) 2022-05-20 12:48:07.042 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] content-length: 22 2022-05-20 12:48:07.042 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] content-type: application/json; charset=UTF-8 2022-05-20 12:48:07.043 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] date: Fri, 20 May 2022 16:48:07 GMT 2022-05-20 12:48:07.043 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] sozu-id: 01G3H5X10Q3B7TBZQ5X0QVGJZR 2022-05-20 12:48:07.043 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] 2022-05-20 12:48:07.044 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] { "status":"success" } 2022-05-20 12:48:07.044 DEBUG 58015 --- [t#getStatus()-1] com.springcloud.feign.MockyClient : [MockyClient#getStatus] <--- END HTTP (22-byte body)

ryanjbaxter commented 2 years ago

Can you provide a complete, minimal, verifiable sample that reproduces the problem? It should be available as a GitHub (or similar) project or attached to this issue as a zip file.

kkotamar commented 2 years ago

@ryanjbaxter attaching the project as zip file. spring-cloud-problem.zip

ryanjbaxter commented 2 years ago

You should really be using the Spring Boot and Spring Cloud BOM. I am not sure the versions you are using are all correct, its very fragile. Please try using Spring Cloud 2021.0.2 and try again.

kkotamar commented 2 years ago

How would updating spring versions help? This library is submitting to executor for executing tasks with bulkhead and without bulkhead?

ryanjbaxter commented 2 years ago

There was a change in the code that looks like it might impact what you are experiencing

kkotamar commented 2 years ago

I tried with spring cloud 2021.0.2 and still see the same issue. Please see logs here.

2022-05-26 09:02:43.835 DEBUG 3014 --- [ main] com.springcloud.App : Running with Spring Boot v2.6.7, Spring v5.3.19 2022-05-26 09:02:43.836 INFO 3014 --- [ main] com.springcloud.App : No active profile set, falling back to 1 default profile: "default" 2022-05-26 09:02:44.743 INFO 3014 --- [ main] o.s.cloud.context.scope.GenericScope : BeanFactory id=f3ac583d-2c0a-37f1-91f4-671f503fa900 2022-05-26 09:02:45.174 INFO 3014 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http) 2022-05-26 09:02:45.181 INFO 3014 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2022-05-26 09:02:45.182 INFO 3014 --- [ main] org.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/9.0.62] 2022-05-26 09:02:45.297 INFO 3014 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext 2022-05-26 09:02:45.297 INFO 3014 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1424 ms 2022-05-26 09:02:47.331 INFO 3014 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 1 endpoint(s) beneath base path '/actuator' 2022-05-26 09:02:47.397 INFO 3014 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2022-05-26 09:02:47.413 INFO 3014 --- [ main] com.springcloud.App : Started App in 3.922 seconds (JVM running for 9.507) 2022-05-26 09:02:47.595 INFO 3014 --- [)-192.168.7.110] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet' 2022-05-26 09:02:47.595 INFO 3014 --- [)-192.168.7.110] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet' 2022-05-26 09:02:47.597 INFO 3014 --- [)-192.168.7.110] o.s.web.servlet.DispatcherServlet : Completed initialization in 2 ms 2022-05-26 09:02:51.917 INFO 3014 --- [nio-8080-exec-1] c.springcloud.controller.TestController : Logging here 2022-05-26 09:02:51.949 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] ---> GET https://run.mocky.io/v3/db578cf2-a126-48df-82c1-868318c25e2f HTTP/1.1 2022-05-26 09:02:51.949 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] ---> END HTTP (0-byte body) 2022-05-26 09:02:52.618 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] <--- HTTP/1.1 200 OK (669ms) 2022-05-26 09:02:52.618 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] content-length: 22 2022-05-26 09:02:52.619 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] content-type: application/json; charset=UTF-8 2022-05-26 09:02:52.619 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] date: Thu, 26 May 2022 13:02:52 GMT 2022-05-26 09:02:52.619 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] sozu-id: 01G407CX8A84WH677N7YDYB0M2 2022-05-26 09:02:52.619 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] 2022-05-26 09:02:52.620 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] { "status":"success" } 2022-05-26 09:02:52.620 DEBUG 3014 --- [nPool-worker-19] com.springcloud.feign.MockyClient : [MockyClient#getStatus] <--- END HTTP (22-byte body) 2022-05-26 09:02:52.683 INFO 3014 --- [nio-8080-exec-1] c.springcloud.controller.TestController : Done

Attaching project here. spring-cloud-debug.zip

Part of the code in Resilience4jCircuitbreaker.java where it is submitting to executor service is first line below. `Supplier<Future> futureSupplier = () -> executorService.submit(toRun::get);

    Callable restrictedCall = TimeLimiter.decorateFutureSupplier(timeLimiter, futureSupplier);
    io.github.resilience4j.circuitbreaker.CircuitBreaker defaultCircuitBreaker = registry.circuitBreaker(this.id,
            this.circuitBreakerConfig, tags);
    circuitBreakerCustomizer.ifPresent(customizer -> customizer.customize(defaultCircuitBreaker));

    if (bulkheadProvider != null) {
        return bulkheadProvider.run(this.groupName, toRun, fallback, defaultCircuitBreaker, timeLimiter, tags);
    }
    else {
        Callable<T> callable = io.github.resilience4j.circuitbreaker.CircuitBreaker
                .decorateCallable(defaultCircuitBreaker, restrictedCall);
        return Try.of(callable::call).recover(fallback).get();
    }`

For semaphore Circuitbreaker it is here.

CompletableFuture<T> asyncCall = CompletableFuture.supplyAsync(supplier);

if (semaphoreDefaultBulkhead || (bulkheadRegistry.find(id).isPresent() && !threadPoolBulkheadRegistry.find(id).isPresent())) { Bulkhead bulkhead = bulkheadRegistry.bulkhead(id, configuration.getBulkheadConfig(), tags); CompletableFuture<T> asyncCall = CompletableFuture.supplyAsync(supplier); return Bulkhead.decorateCompletionStage(bulkhead, () -> asyncCall); }

ryanjbaxter commented 2 years ago

This is where I was confused....I thought you were purely focusing on the bulkhead execution, not the circuit breaker.

kkotamar commented 2 years ago

@ryanjbaxter i am testing both of the options. I am ok with simply using the circuit breaker with out bulkhead.

kkotamar commented 2 years ago

@ryanjbaxter I made the code changes requested. Can you review?

kkotamar commented 2 years ago

@ryanjbaxter Is it released part of 2.1.3?

ryanjbaxter commented 2 years ago

It will be included as part of Spring Cloud 2021.0.4

kkotamar commented 2 years ago

Thank you. What is the release date for spring cloud 2021.0.4. Are there any options to get snapshot version?

ryanjbaxter commented 2 years ago

Here are tentative release dates https://github.com/spring-cloud/spring-cloud-release/milestones

Yes you can use 2021.0.4-SNAPSHOT