How to close HTTP response with the new HTTP Client abstraction

[scholzj]

In 5.11, the new HTTP abstraction was introduced which abstracts the OkHttp client with Fabric8's own classes. However, the HttpResponse class does not seem to have any method to close the response. When the response is not closed, OkHttp is leaking connections and complaining to the log:

Dec 27, 2021 3:11:34 PM okhttp3.internal.platform.Platform log
WARNING: A connection to https://10.96.0.1/ was leaked. Did you forget to close a response body? To see where this was allocated, set the OkHttpClient logger level to FINE: Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);
Dec 27, 2021 3:11:34 PM okhttp3.internal.platform.Platform log
WARNING: A connection to https://10.96.0.1/ was leaked. Did you forget to close a response body? To see where this was allocated, set the OkHttpClient logger level to FINE: Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);
Dec 27, 2021 3:11:34 PM okhttp3.internal.platform.Platform log
WARNING: A connection to https://10.96.0.1/ was leaked. Did you forget to close a response body? To see where this was allocated, set the OkHttpClient logger level to FINE: Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);

Is this some feature still missing in 5.11? Or what is the right way to close the response?

[shawkins]

Is this some feature still missing in 5.11? Or what is the right way to close the response?

Generally the end user is not responsible for closing the response. Only if a stream is directly returned will the response be held open - something like a pod operation getLogReader. In those cases the user is responsible for closing the stream to close the response.

Can you use the log override to determine what code path is being warned about here?

[scholzj]

Yeah, sorry, I think I opened this too early. I thought this is coming from the places where we use the HttpClient directly. But I did some more investigation and it seems to be coming from Fabric8 as well. Within Strimzi, this seems to be the full stack when the response bodies are not closed:

Dec 27, 2021 5:11:21 PM okhttp3.internal.platform.Platform log
WARNING: A connection to https://172.30.0.1/ was leaked. Did you forget to close a response body?
java.lang.Throwable: response.body().close()
	at okhttp3.internal.platform.Platform.getStackTraceForCloseable(Platform.java:148)
	at okhttp3.RealCall.captureCallStackTrace(RealCall.java:116)
	at okhttp3.RealCall.execute(RealCall.java:88)
	at io.fabric8.kubernetes.client.okhttp.OkHttpClientImpl.send(OkHttpClientImpl.java:138)
	at io.fabric8.kubernetes.client.dsl.base.OperationSupport.retryWithExponentialBackoff(OperationSupport.java:575)
	at io.fabric8.kubernetes.client.dsl.base.OperationSupport.handleResponse(OperationSupport.java:554)
	at io.fabric8.kubernetes.client.dsl.base.OperationSupport.handleResponse(OperationSupport.java:519)
	at io.fabric8.kubernetes.client.dsl.base.OperationSupport.handleGet(OperationSupport.java:488)
	at io.fabric8.kubernetes.client.dsl.base.OperationSupport.handleGet(OperationSupport.java:458)
	at io.fabric8.kubernetes.client.dsl.base.BaseOperation.handleGet(BaseOperation.java:696)
	at io.fabric8.kubernetes.client.dsl.base.BaseOperation.getMandatory(BaseOperation.java:182)
	at io.fabric8.kubernetes.client.dsl.base.BaseOperation.get(BaseOperation.java:149)
	at io.fabric8.kubernetes.client.dsl.base.BaseOperation.get(BaseOperation.java:83)
	at io.strimzi.operator.common.operator.resource.AbstractResourceOperator.lambda$reconcile$0(AbstractResourceOperator.java:109)
	at io.vertx.core.impl.ContextImpl.lambda$null$0(ContextImpl.java:159)
	at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100)
	at io.vertx.core.impl.ContextImpl.lambda$executeBlocking$1(ContextImpl.java:157)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:829)

The Fabric8 part of the stacktrace seems to be always the same. The part which triggers it in Strimzi differs, but it is always calling the get() method. For example as MixedOperation.inNamespace(...).withName(...).get(), NonNamespaceOperation.withName(...).get() and so on.

I created a simple reproducer:

final KubernetesClient client = new DefaultKubernetesClient();
java.util.logging.Logger.getLogger(OkHttpClient.class.getName()).setLevel(Level.FINE);

Runnable getter = () -> {
    while (true) {
        client.rbac().clusterRoles().withName("some-name").get();

        try {
            Thread.sleep(1000L);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
};

Thread t1 = new Thread(getter);
t1.start();

If you run it and wait few minutes, you will see the errors show up in the log. It seems to reproduce with 5.11.0 and 5.11.1. But it never happens with 5.10.1. So it looks like something changed in the code between these versions.

[shawkins]

Can you convert this to an issue? I'm seeing that this is primarily due to the BackwardsCompatiblityInterceptor - it isn't closing the initial request before retrying. There will need to be an explicit closure for all interceptors: shawkins@e41aea5

[scholzj]

I opened #3697 for this. Thanks.