Java OOM Java heap space when I use WithKubernetesTestServer annotation in unit test

[kornys]

Describe the bug

We use in our unit tests @QuarkusTestResource(KubernetesServerTestResource.class) and all unit tests works fine with this mocked kube server, but we want to have scope of mocked kube server per class instead of per module so we switched to @WithKubernetesTestServer which is equivalent to @QuarkusTestResource(value = KubernetesServerTestResource.class, restrictToAnnotatedClass = true) and test run fails on OOM after some time of surefire run.

Expected behavior

Uni tests pass

Actual behavior

Tests fail after some time on OOM Java Heap space

How to Reproduce?

Run more unit tests from more classes with mocked kube server like we do in our unit tests

Output of uname -a or ver

Darwin dkornel-mac 20.6.0 Darwin Kernel Version 20.6.0: Wed Jun 23 00:26:27 PDT 2021; root:xnu-7195.141.2~5/RELEASE_ARM64_T8101 arm64

Output of java -version

openjdk version "11.0.11" 2021-04-20 OpenJDK Runtime Environment AdoptOpenJDK-11.0.11+9 (build 11.0.11+9) OpenJDK 64-Bit Server VM AdoptOpenJDK-11.0.11+9 (build 11.0.11+9, mixed mode)

GraalVM version (if different from Java)

No response

Quarkus version or git rev

1.13.1.Final

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

Apache Maven 3.8.1 (05c21c65bdfed0f71a2f2ada8b84da59348c4c5d)

Additional information

surefire version: maven-surefire-plugin:3.0.0-M5

Test log run
https://gist.github.com/kornys/f08ca9041c01b551af77631ff38dcd64

Error stack trace

java.lang.RuntimeException: io.quarkus.builder.BuildException: Build failure: Build failed due to errors
Error: ]: Build step io.quarkus.deployment.steps.ConfigGenerationBuildStep#generateConfigClass threw an exception: java.lang.OutOfMemoryError: Java heap space
	at io.quarkus.gizmo.BytecodeCreatorImpl.invokeVirtualMethod(BytecodeCreatorImpl.java:121)
	at io.quarkus.deployment.configuration.RunTimeConfigurationGenerator$GenerateOperation.generateParserBody(RunTimeConfigurationGenerator.java:1237)
	at io.quarkus.deployment.configuration.RunTimeConfigurationGenerator$GenerateOperation.generateParserBody(RunTimeConfigurationGenerator.java:1186)
	at io.quarkus.deployment.configuration.RunTimeConfigurationGenerator$GenerateOperation.generateParserBody(RunTimeConfigurationGenerator.java:1186)
	at io.quarkus.deployment.configuration.RunTimeConfigurationGenerator$GenerateOperation.generateParserBody(RunTimeConfigurationGenerator.java:1186)
	at io.quarkus.deployment.configuration.RunTimeConfigurationGenerator$GenerateOperation.run(RunTimeConfigurationGenerator.java:462)
	at io.quarkus.deployment.configuration.RunTimeConfigurationGenerator.generate(RunTimeConfigurationGenerator.java:249)
	at io.quarkus.deployment.steps.ConfigGenerationBuildStep.generateConfigClass(ConfigGenerationBuildStep.java:63)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at io.quarkus.deployment.ExtensionLoader$2.execute(ExtensionLoader.java:920)
	at io.quarkus.builder.BuildContext.run(BuildContext.java:277)
	at io.quarkus.builder.BuildContext$$Lambda$2710/0x00000001014f1840.run(Unknown Source)
	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2415)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1452)
	at java.base/java.lang.Thread.run(Thread.java:829)
	at org.jboss.threads.JBossThread.run(JBossThread.java:501)

[quarkus-bot]

/cc @geoand

[geoand]

Does the same happen with 1.13.7.Final or 2.0.3.Final?

[kornys]

@shawkins could we upgrade quarkus version? I think it will cause issues because of operatorSDK, right?

[shawkins]

@kornys yes we are blocked. A WIP was started by @metacosm but I'm not sure when it will get picked back up.

[geoand]

Any chance we can get a small project that reproduces the problem? Preferably without the operator-sdk involved

[metacosm]

@shawkins @kornys not sure I'm following, what is blocking you?

[shawkins]

not sure I'm following, what is blocking you?

bf2fc6cc711aee1a0c2a/kas-fleetshard#367 is marked as a WIP, are you saying that can now be completed? Alternatively you had mentioned just skipping ahead to quarkus 2.

[metacosm]

@shawkins ok, I wasn't sure what you were refering to… Let me loop back on this, I had forgotten about it… :(
By the way, I've tried to reproduce the issue locally and couldn't so far on the test I tried (ManagedKafkaAgentControllerTest.createStatus).

[geoand]

Is this still an issue?

[shawkins]

Yes, we retested after the upgrade to 2.2.2 and it still occurs.

[geoand]

If anyone can supply me with a small reproducer that exhibits the problematic behavior, I can take a look

[shawkins]

@geoand Sorry, this is not a simple reproducer, but it does show the issue - https://github.com/shawkins/mk-agent/commit/c32b0d605ef85380a6d8cd9f1569ed926de71a61

Possibly related. Here's another change that exhibits similar behavior - the introduction of another application bean cause build errors: bf2fc6cc711aee1a0c2a/kas-fleetshard#643

[geoand]

@geoand Sorry, this is not a simple reproducer, but it does show the issue - shawkins/mk-agent@c32b0d6

Anything I need to know about building / running the tests?

[shawkins]

Anything I need to know about building / running the tests?

No, "maven install" should do it.

[geoand]

I can reproduce the issue, thanks.

Is there any chance you can bump the project to the latest Quarkus version (I tried and something doesn't compile) so we can then start experimenting with possible fixes (to what appears to be a CL leak)?

[shawkins]

Is there any chance you can bump the project to the latest Quarkus version (I tried and something doesn't compile)

That's usually an involved process - we need to keep the quarkus / fabric8 / operator sdk versions in lock step. I can try updating to the latest operator sdk in another branch to give you a better starting point.

[geoand]

Thanks

[shawkins]

@geoand https://github.com/shawkins/mk-agent/tree/withtestserver has been updated to 2.6.2.Final via the 2.0.3 quarkus operation sdk. I've updated this to have a commit updating to new set of dependencies - which appears to build cleanly (as it's own pr here bf2fc6cc711aee1a0c2a/kas-fleetshard#648). And another commit that introduces two usages of WithKubernetesTestServer that reproduces the issue.

There is a 3.0.2 quarkuas operator sdk, which I can look at upgrading to if needed.

[geoand]

I had a quick look with Yourkit and I can't be sure, but it looks like the is a ClassLoader leak in okio.AsyncTimeout.
The reason is that okio.AsyncTimeout$Watchdog is a daemon thread (that obviously holds on to the TCCL) and never goes away, meaning that the Quarkus ClassLoader (which is the captured as the TCCL of the thread) cannot be GCed.

[shawkins]

I had a quick look with Yourkit and I can't be sure, but it looks like the is a ClassLoader leak in okio.AsyncTimeout.

That doesn't sound promising. We're stuck with okhttp for a while - even once it's eliminated as a dependency for the fabric8 client, it's still used as the basis for the fabric8 mock server.

[geoand]

Maybe there it has a way for the timeout feature to be disabled?

[shawkins]

Maybe there it has a way for the timeout feature to be disabled?

I'll see what is creating the timeouts. There are several system/env properties that can configure the timeouts explicitly used by the fabric8 client, but nothing that I'm aware of for configuring any timeout that may be used under the covers by the mock server.

[shawkins]

@geoand the short answer is that there isn't an easy way to disable okhttp timeouts via configuration. If you try adding things like:

%test.quarkus.kubernetes-client.connection-timeout=PT0S

The fabric8 ok http configation will ignore the value as it will only allow non-zero positive values:
https://github.com/fabric8io/kubernetes-client/blob/26c08847d1251b2e840ce5833bbe05e43ee77fa6/kubernetes-client/src/main/java/io/fabric8/kubernetes/client/utils/HttpClientUtils.java#L170

And the okhttp client explicitly hard codes the timeout defaults, so there's no mechanism at that level to override.

[geoand]

:(

[shawkins]

Updating the amount of test memory from 256m to 512m works around the issue for us on bf2fc6cc711aee1a0c2a/kas-fleetshard#643 - I'll confirm that it works for the WithKubernetesTestServer annotation as well.

Is there anything that needs in captured in fabric8 related to this?

[geoand]

Is there anything that needs in captured in fabric8 related to this?

Not sure I understand the question here

[shawkins]

Not sure I understand the question here

Does fabric8 need to work towards removing okhttp for the mock/test server as well, or at the least disable any timeouts that may cause this?

[geoand]

I can't know for sure as I didn't look into all the details, but from what I saw, having the client not create threads that check for timeouts, should do the trick.
But there is no telling if some other leak will appear once that one is gone...

[SoerenHenning]

We're facing the same issue with Quarkus 2.7.4. Increasing maxHeapSize in Gradle works, but is there any other way to avoid failing tests because of java.lang.OutOfMemoryError: Java heap space exceptions?

[geoand]

Is this still an issue? If so, can someone please attach a sample application I can use to track down the problem?

Thanks

[shawkins]

The problem still exists with fleetshard - https://github.com/shawkins/kas-fleetshard/tree/quarkus-18973 without that last commit bf2fc6cc711aee1a0c2a/kas-fleetshard@6331bdb things should build just fine with a mvn clean install from the root. With that change to use WithKubernetesTestServer, you'll get OOM errors. In a heap dump I see that QuarkusClassloaders of good size are being held by different OkHttp ConnectionPool threads. These are being held under a static executor - RealConnectionPool.executor. Each ConnectionPool that's created can apparently have one of these threads/jobs, but they are supposed to automatically cleanup when the pool is empty - not sure why it's not happening in this case. This particular problem will go away if a client other than okhttp is used as it should be on the client side only. The mock server shouldn't use a connection pool.

[shawkins]

@geoand one update - I see KubernetesConfigRecorder creating the KubernetesClient, but I don't see anything closing the client. In fact there seems to be several clients being created, and most are not getting closed. That should be addressed, but I don't think it alone will solve this. OkHttp doesn't proactively clear those jobs when the pool is empty - it can take up to 5 minutes by default for the thread to go away. Seems like we don't have a great workaround other than creating a different connection pool with a smaller keepAliveDuration, or adding a class to their package which would give us access to the RealConnectionPool on close.

[geoand]

I wonder if we can switch to one of the clients for this case too.

In any case, the only way I get work on it is if someone provides me a sample application showing the problem

[shawkins]

I wonder if we can switch to one of the clients for this case too.

Once we are have an upgrade path for kas-fleetshard, we'll likely do so.

In fact there seems to be several clients being created, and most are not getting closed.

I need to check with a later quarkus version, but at least for kas-fleetshard on 2.13.7 it looks like the clients created by KubernetesClientBuildStep and KubernetesConfigRecorder are not getting closed - and these are created per test. Each are creating connections, so there's a job being added to the static executor per instance.

However even if they are closed as mentioned above okhttp does not provide a good way to terminate that job - I'll add something upstream for that.

[gsmet]

I think the ones created via KubernetesClientBuildStep (and the build item) are OK. From what I can see, we create the client in try with resources clauses.

But I agree the one created in KubernetesConfigRecorder is problematic.

[geoand]

Yeah, I'll address that I have no real way to test it

[geoand]

#32003 is what I have in mind

[shawkins]

@gsmet I see, its been changed to buildClient, rather than getClient. So yes KubernetesClientBuildStep is good.

fabric8io/kubernetes-client#4985 will address okhttp not proactively cleaning up their tasks.

[geoand]

@shawkins do you know if this has finally been addressed?

[shawkins]

I think so.

[geoand]

Great, thanks!