Keycloak Dev services take more memory after bump to 25, is it expected and can something be done about it?

[michalvavrik]

After #41162 I have Quarkus Quickstarts modules security-keycloak-authorization-quickstart, security-openid-connect-quickstart. security-openid-connect-client-quickstart, security-openid-connect-web-authentication-quickstart and security-openid-connect-multi-tenancy-quickstart failing in resource constrained environment.

I get OOM:

2024-06-24 20:57:40,506 INFO  [tc.qua.io/.0.0] (build-6) Container quay.io/keycloak/keycloak:25.0.0 is starting: b26499c6586fa4cc024748c6833d2e9074324cef0b3a4b648a7fce09a3f82382
2024-06-24 20:58:40,832 ERROR [tc.qua.io/.0.0] (build-6) Could not start container: java.lang.IllegalStateException: Wait strategy failed. Container exited with code 1
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:533)
	at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:354)
	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:81)
	at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:344)
	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:330)
	at io.quarkus.oidc.deployment.devservices.keycloak.KeycloakDevServicesProcessor.lambda$startContainer$4(KeycloakDevServicesProcessor.java:377)
	at java.base/java.util.Optional.orElseGet(Optional.java:364)
	at io.quarkus.oidc.deployment.devservices.keycloak.KeycloakDevServicesProcessor.startContainer(KeycloakDevServicesProcessor.java:402)
	at io.quarkus.oidc.deployment.devservices.keycloak.KeycloakDevServicesProcessor.startKeycloakContainer(KeycloakDevServicesProcessor.java:198)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:568)
	at io.quarkus.deployment.ExtensionLoader$3.execute(ExtensionLoader.java:849)
	at io.quarkus.builder.BuildContext.run(BuildContext.java:256)
	at org.jboss.threads.ContextHandler$1.runWith(ContextHandler.java:18)
	at org.jboss.threads.EnhancedQueueExecutor$Task.doRunWith(EnhancedQueueExecutor.java:2516)
	at org.jboss.threads.EnhancedQueueExecutor$Task.run(EnhancedQueueExecutor.java:2495)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1521)
	at java.base/java.lang.Thread.run(Thread.java:840)
	at org.jboss.threads.JBossThread.run(JBossThread.java:483)
Caused by: org.testcontainers.containers.ContainerLaunchException: Timed out waiting for log output matching '.*Keycloak.*started.*'
	at org.testcontainers.containers.wait.strategy.LogMessageWaitStrategy.waitUntilReady(LogMessageWaitStrategy.java:47)
	at org.testcontainers.containers.wait.strategy.AbstractWaitStrategy.waitUntilReady(AbstractWaitStrategy.java:52)
	at org.testcontainers.containers.GenericContainer.waitUntilContainerStarted(GenericContainer.java:909)
	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:500)
	... 20 more

2024-06-24 20:58:40,849 ERROR [tc.qua.io/.0.0] (build-6) Log output from the failed container:
OpenJDK 64-Bit Server VM warning: INFO: os::commit_memory(0x00000006af400000, 4034920448, 0) failed; error='Not enough space' (errno=12)
#
# There is insufficient memory for the Java Runtime Environment to continue.
# Native memory allocation (mmap) failed to map 4034920448 bytes. Error detail: committing reserved memory.
# An error report file with more information is saved as:
# /tmp/hs_err_pid87.log

After reading keycloak/keycloak#26661 and https://www.keycloak.org/server/configuration#_second_step_start_keycloak_using_optimized I am not able to determine whether something should be done or not.

[quarkus-bot[bot]]

/cc @geoand (devservices), @pedroigor (keycloak), @sberyozkin (keycloak), @stuartwdouglas (devservices)

[geoand]

cc @vmuzikar

[vmuzikar]

Adding also @mabartos who was looking into this area previously

[sberyozkin]

There used to be a disk based mapping supported in some earlier versions but it was discontinued.

The current command to start it is start --http-enabled=true --hostname-strict=false --spi-user-profile-declarative-user-profile-config-file=/opt/keycloak/upconfig.json but it is possible to customize it. We can add the extra options which can make sense into the default sequence.

Java options are also possible to pass to the container, so if necessary, we can set some by default.

For ex, if Infinispan is used by default, may be a less memory consuming DB option can be tried ?

[vmuzikar]

We changed the GC in 25. Possibly that's the reason. Are the dev services using container only?

[fedinskiy]

Additionally, mvn clean verify -Dquarkus.keycloak.devservices.java-opts="-XX:MaxMetaspaceSize=256m -XX:AdaptiveSizePolicyWeight=90" also worked. It took 36:14 minutes, which afaik is a bit longer, than previous runs, though.

[sberyozkin]

Thanks @fedinskiy. Indeed, 36 seconds is too long...

Please experiment with -XX:MaxHeapFreeRatio and -XX:MaxRAMPercentage if you can, hopefully @mabartos can recommend something as well, thanks

[fedinskiy]

@sberyozkin it looks like there is no answer from Martin. Maybe I should create a separate issue for this?

[sberyozkin]

@fedinskiy Sure, please open an issue to have -XX:MetaspaceSize=96M -XX:MaxMetaspaceSize=256m -XX:+UseParallelGC -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90 set by default for https://github.com/quarkusio/quarkus/blob/main/extensions/oidc/deployment/src/main/java/io/quarkus/oidc/deployment/devservices/keycloak/DevServicesConfig.java#L114 to start with, if you can do a PR it would be appreciated, it is only about providing the default value for that property and making it non-optional

[fedinskiy]

done: #41813

[mabartos]

@michalvavrik @sberyozkin Little context: Since Keycloak 24, the heap size is relatively determined based on the available container memory. The default setting is to use 70% of the whole container memory for the heap, so it is necessary to set the container limit.

Did you set the limit? For more info, check this guide. You can assess the heap parameters or disable the functionality of the relative heap size by setting the env var KC_RUN_IN_CONTAINER=false (in the worst case).

The more disturbing aspect is that it tries to allocate ~4GB of memory, which is very high, and I'm curious what exactly is happening there.

As you already used Keycloak 24, it should be more the case around different settings set in Keycloak 25, as @vmuzikar mentioned.
The GC and specific JVM options have changed - see keycloak/keycloak#29941.

It'd be good to have a heap dump and track the native memory (NMT).

[michalvavrik]

Thank you everyone for answers. Just 2 things:

1. I am yet to try Sergey suggestions as I had very busy days, I'll try it later this week and then, I can provide more context.
2. We just run Quarkus Quickstarts that itself start Keycloak Dev Services. All these suggestions to setting limits etc. doesn't match our use case. So I know I can fix it for myself always, but my issue is whether we want users with weaker workstations or inside CI with weak runners to run into this issue. Answer "yes" is possible.