Resource not closed warning with rest client #10813

pilhuhn · 2020-07-17T15:14:01Z

This is a bit hard to reproduce for me. Like in #10804 I am doing remote calls via the MP Rest Client

 @Inject
  @RestClient
  RbacServer rbac;
...
   try {
      result = getRbacInfo(user.getRawRhIdHeader());
    } catch (Throwable e) {
...

  @CacheResult(cacheName = "rbac-cache")
  RbacRaw getRbacInfo(String xrhidHeader)  {
    RbacRaw result;
    result = rbac.getRbacInfo("policies", xrhidHeader);  // <---
    return result;
  }

And I get (not always) the following in the logs:

2020-07-17 16:58:30,999 WARN [org.jbo.res.cli.jax.i18n] (Finalizer) RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.

Locally I could reproduce it now with the remote service returning a 401, but I also see that on our production instance, where I do not see any errors from the remote call.

2020-07-17 17:38:59,103 WARNING [RbacFilter] (executor-thread-1) Call to RBAC took 1301ms
2020-07-17 17:38:59,102 WARNING [com.git.ben.caf.cac.LocalAsyncCache] (Thread-13) Exception thrown during asynchronous load: java.util.concurrent.CompletionException: javax.ws.rs.WebApplicationException: Unknown error, status code 401
        at java.base/java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:314)
        at java.base/java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:319)
        at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1702)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: javax.ws.rs.WebApplicationException: Unknown error, status code 401
        at org.jboss.resteasy.microprofile.client.DefaultResponseExceptionMapper.toThrowable(DefaultResponseExceptionMapper.java:16)
        at org.jboss.resteasy.microprofile.client.ExceptionMapping$HandlerException.mapException(ExceptionMapping.java:38)
        at org.jboss.resteasy.microprofile.client.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:151)
        at com.sun.proxy.$Proxy75.getRbacInfo(Unknown Source)
        at com.redhat.cloud.policies.app.auth.RbacFilter.getRbacInfo(RbacFilter.java:95)
        at com.redhat.cloud.policies.app.auth.RbacFilter_Subclass.getRbacInfo$$superaccessor1(RbacFilter_Subclass.zig:205)
        at com.redhat.cloud.policies.app.auth.RbacFilter_Subclass$$function$$1.apply(RbacFilter_Subclass$$function$$1.zig:33)
        at io.quarkus.arc.impl.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:54)
        at io.quarkus.cache.runtime.CacheResultInterceptor.lambda$intercept$0(CacheResultInterceptor.java:27)
        at io.quarkus.cache.runtime.caffeine.CaffeineCache$MappingSupplier.get(CaffeineCache.java:136)
        at io.quarkus.cache.runtime.caffeine.CaffeineCache.lambda$get$0(CaffeineCache.java:58)
        at com.github.benmanes.caffeine.cache.LocalAsyncCache.lambda$get$0(LocalAsyncCache.java:77)
        at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
        ... 1 more

{"date":"Fri, 17 Jul 2020 15:38:57 GMT","method":"GET","uri":"/api/policies/v1.0/policies/123","acct":"901578","http_version":"HTTP/1.1","status":403,"content_length":0,"duration":1318,"user_agent":"curl/7.54.0","remote":"0:0:0:0:0:0:0:1"}
2020-07-17 17:39:09,854 WARN  [org.jbo.res.cli.jax.i18n] (Finalizer) RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.

Commenting out the @CacheResult() makes the warning/stack trace go away, but still shows the Finalizer-warning.

The text was updated successfully, but these errors were encountered:

pilhuhn · 2020-07-24T10:45:59Z

We saw that issue in our project first on June 18th when we bumped Quarkus from 1.3.2 to 1.5.1

stuartwdouglas · 2020-07-27T04:36:13Z

What scope is the client?

michalszynkiewicz · 2020-07-27T13:37:01Z

MP RC spec says @Dependent is the default scope

The destroyer was not setup, so request scoped instances (or @dependent instances injected into request scoped beans) would not be destroyed. Also wired this up correctly in ArC. Fixes quarkusio#10813

bbntrk · 2021-11-06T08:35:54Z

Still happening at Quarkus 2.4.0-Final

stuartwdouglas · 2021-11-07T22:30:27Z

@bbntrk this is likely a different issue, please file a new one with a reproducer.

TheParad0X · 2022-03-24T12:10:02Z

I am still getting the same error 2.7.5 Final. It happens almost everytime an internal REST call happens (i.e. with the Keycloak API), or an explicit one when Testing with RESTAssured.

WARN [org.jbo.res.cli.jax.i18n] (Finalizer) RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.

After running all my tests, the whole console is full of those messages. They usually appear after a timeout of a couple of seconds.

julianseeger · 2022-03-29T07:55:47Z

We had this problem for a long time now, too. Now we found at least a workaround.

Using Quarkus 2.7.4.Final with kotlin.

Reproduce:

@Path("/test")
class TestEndpoint @Inject constructor(
    @RestClient
    private val testService: TestService
) {
    @GET
    @Produces(MediaType.APPLICATION_JSON)
    fun test(): String {
        return "test"
    }
}


@RegisterRestClient(configKey = "my-api")
interface TestService {
    @GET
    @Path("health")
    fun health(): Response
}

As you can see, the dependency injection is sufficient to reproduce the error. I don't make any actuall call to the RestClient.
Now, when I make about 2500-3000 calls to my endpoint:

for i in $(seq 3000); do curl 'http://localhost:8080/api/test'; echo $i;  done

the warning occurs (for about 2500 requests nothing happens and then all open clinets seem to be forced closed):

09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
09:46:52 WARN  traceId= [org.jbo.res.cli.jax.i18n] RESTEASY004687: Closing a class org.jboss.resteasy.client.jaxrs.engines.ApacheHttpClient43Engine instance for you. Please close clients yourself.
...

The important part here is that the RestClient is not a singleton. Thus, a new instance seems to be created for each request and is not closed.
As soon as I add an @Singleton annotation to the TestService or add the corresponding config to my application.yaml:

my-api/mp-rest/scope: javax.inject.Singleton

I can no longer reproduce the error. Sounds plausible to me because only one client is ever created.

But actually, shouldn't a connection pool be used, that closes the clients even when @Singleton is used?

Edit: even with @Singleton, the warnings happen but only on server termination (or maybe after a long timeout that is longer than i waited 🤷‍♂️ ).

tonbiklas · 2023-08-30T15:06:51Z

Still happening on quarkus 2.8.0-FINAL

pilhuhn added the kind/bug Something isn't working label Jul 17, 2020

kenfinnigan added the area/rest-client label Jul 22, 2020

stuartwdouglas mentioned this issue Jul 28, 2020

Make sure REST clients are closed #11011

Merged

mkouba closed this as completed in #11011 Jul 28, 2020

gsmet changed the title ~~resource not closed warning with rest client~~ Resource not closed warning with rest client Jul 28, 2020

gsmet added this to the 1.7.0 - master milestone Jul 28, 2020

jerboaa mentioned this issue Apr 8, 2024

Build perf app Karm/mandrel-integration-tests#254

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Resource not closed warning with rest client #10813

Resource not closed warning with rest client #10813

pilhuhn commented Jul 17, 2020 •

edited

pilhuhn commented Jul 24, 2020

stuartwdouglas commented Jul 27, 2020

michalszynkiewicz commented Jul 27, 2020

bbntrk commented Nov 6, 2021

stuartwdouglas commented Nov 7, 2021

TheParad0X commented Mar 24, 2022

julianseeger commented Mar 29, 2022 •

edited

tonbiklas commented Aug 30, 2023

Resource not closed warning with rest client #10813

Resource not closed warning with rest client #10813

Comments

pilhuhn commented Jul 17, 2020 • edited

pilhuhn commented Jul 24, 2020

stuartwdouglas commented Jul 27, 2020

michalszynkiewicz commented Jul 27, 2020

bbntrk commented Nov 6, 2021

stuartwdouglas commented Nov 7, 2021

TheParad0X commented Mar 24, 2022

julianseeger commented Mar 29, 2022 • edited

tonbiklas commented Aug 30, 2023

pilhuhn commented Jul 17, 2020 •

edited

julianseeger commented Mar 29, 2022 •

edited