Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Keycloak container consumes too much memory in devmode #41813

Closed
fedinskiy opened this issue Jul 10, 2024 · 7 comments · Fixed by #43601
Closed

Keycloak container consumes too much memory in devmode #41813

fedinskiy opened this issue Jul 10, 2024 · 7 comments · Fixed by #43601
Labels
Milestone

Comments

@fedinskiy
Copy link
Contributor

Describe the bug

After #41162 I get tests in Quarkas quickstarts fail with OOM exception inside DevMode containers. This issue can only be reproduced, when modules are run together and not one after another, when using machine with 8GB or less of memory

Expected behavior

Tests should not fail (as in 3.12.0)

Actual behavior

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

How to Reproduce?

  1. git clone -b development https://github.com/quarkusio/quarkus-quickstarts.git && cd quarkus-quickstarts
  2. mvn clean verify

If run with mvn clean verify -Dquarkus.keycloak.devservices.java-opts="-XX:MetaspaceSize=96M -XX:MaxMetaspaceSize=256m -XX:+UseParallelGC -XX:GCTimeRatio=4 -XX:AdaptiveSizePolicyWeight=90" or even mvn clean verify -Dquarkus.keycloak.devservices.java-opts="-XX:MaxMetaspaceSize=256m -XX:AdaptiveSizePolicyWeight=90", this doesn't fail

Output of uname -a or ver

4.18.0-553.5.1.el8_10.x86_64

Output of java -version

17.0.7, vendor: Red Hat, Inc.

Quarkus version or git rev

999-SNAPSHOT (see above)

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

Apache Maven 3.8.6 (84538c9988a25aec085021c365c560670ad80f63)

Additional information

Was fist created as a question[1], but later it was decided, that this worth filling a bug

[1] #41426 (reply in thread)

@fedinskiy fedinskiy added the kind/bug Something isn't working label Jul 10, 2024
@quarkus-bot
Copy link

quarkus-bot bot commented Jul 10, 2024

/cc @pedroigor (keycloak), @sberyozkin (keycloak)

fedinskiy added a commit to fedinskiy/quarkus that referenced this issue Jul 11, 2024
fedinskiy added a commit to fedinskiy/quarkus that referenced this issue Jul 12, 2024
fedinskiy added a commit to fedinskiy/quarkus that referenced this issue Jul 12, 2024
@geoand
Copy link
Contributor

geoand commented Sep 30, 2024

What's the status of this?

@fedinskiy
Copy link
Contributor Author

@geoand I can still reproduce the issue as described on a machine with 8 RAM using 999-SNAPSHOT from yesterday, so it is not fixed.

@geoand
Copy link
Contributor

geoand commented Sep 30, 2024

Thanks for the update

@fedinskiy
Copy link
Contributor Author

fedinskiy commented Sep 30, 2024

In the comments to the original question, @sberyozkin recommended to discuss it with @mabartos . I suppose, that one of them can be assigned to this issue.

Update: there is a #41833 by me which fixes this, but there is no activity from the reviewer since July

@mabartos
Copy link
Contributor

Sorry, totally missed it. I'll look at it.

mabartos added a commit to mabartos/quarkus that referenced this issue Sep 30, 2024
Fixes quarkusio#41813

Signed-off-by: Martin Bartoš <mabartos@redhat.com>
mabartos added a commit to mabartos/quarkus that referenced this issue Sep 30, 2024
Fixes quarkusio#41813

Signed-off-by: Martin Bartoš <mabartos@redhat.com>
mabartos added a commit to mabartos/quarkus that referenced this issue Sep 30, 2024
Fixes quarkusio#41813

Signed-off-by: Martin Bartoš <mabartos@redhat.com>
@quarkus-bot quarkus-bot bot added this to the 3.16 - main milestone Oct 1, 2024
@jcarranzan
Copy link
Contributor

We also have the same issue not just in devmode, observed in our CI jenkins jobs the failure:

03:31:11 [INFO] Running io.quarkus.ts.http.advanced.HttpAdvancedIT
03:31:12 01:31:12,230 INFO  ⭐  PKCS12 keystore and truststore generated successfully!
03:31:12 01:31:12,231 INFO  🔐  Key Store File: /tmp/quarkus-qe-certs11648231087839990117/quarkus-qe-keystore.p12
03:31:12 01:31:12,231 INFO  🔓  Trust Store File: /tmp/quarkus-qe-certs11648231087839990117/quarkus-qe-truststore.p12
03:31:12 01:31:12,271 INFO  [keycloak] Initialize service (quay.io/keycloak/keycloak:25.0)
03:31:12 01:31:12,295 Image pull policy will be performed by: DefaultPullPolicy()
03:31:12 01:31:12,297 Image name substitution will be performed by: DefaultImageNameSubstitutor (composite of 'ConfigurationFileImageNameSubstitutor' and 'PrefixingImageNameSubstitutor')
03:31:12 01:31:12,309 Testcontainers version: 1.20.1
03:31:12 01:31:12,865 Found Docker environment with Environment variables, system properties and defaults. Resolved dockerHost=unix:///run/user/600/podman/podman.sock
03:31:12 01:31:12,866 Docker host IP address is localhost
03:31:12 01:31:12,911 Connected to docker: 
03:31:12   Server Version: 4.9.4-rhel
03:31:12   API Version: 1.41
03:31:12   Operating System: rhel
03:31:12   Total Memory: 7695 MB
03:31:12 01:31:12,931 Pulling docker image: testcontainers/ryuk:0.8.1. Please be patient; this may take some time but only needs to be done once.
03:31:13 01:31:13,159 Starting to pull image
03:31:13 01:31:13,187 Pulling image layers:  2 pending,  1 downloaded,  0 extracted, (0 bytes/? MB)
03:31:13 01:31:13,228 Pulling image layers:  1 pending,  2 downloaded,  0 extracted, (0 bytes/? MB)
03:31:13 01:31:13,437 Pulling image layers:  0 pending,  3 downloaded,  0 extracted, (0 bytes/0 bytes)
03:31:13 01:31:13,440 Pulling image layers:  0 pending,  4 downloaded,  0 extracted, (0 bytes/0 bytes)
03:31:13 01:31:13,445 Pulling image layers:  0 pending,  4 downloaded,  0 extracted, (0 bytes/0 bytes)
03:31:13 01:31:13,446 Image testcontainers/ryuk:0.8.1 pull took PT0.515026139S
03:31:13 01:31:13,463 Creating container for image: testcontainers/ryuk:0.8.1
03:31:13 01:31:13,511 Container testcontainers/ryuk:0.8.1 is starting: 2ab279a2dd2ec6cebf0769110d2be287ba53258260a0bd2d13770dafa9b26d39
03:31:13 01:31:13,873 Container testcontainers/ryuk:0.8.1 started in PT0.409386568S
03:31:13 01:31:13,875 Ryuk started - will monitor and terminate Testcontainers containers on JVM exit
03:31:13 01:31:13,876 Checking the system...
03:31:13 01:31:13,876 ✔︎ Docker server version should be at least 1.6.0
03:31:13 01:31:13,878 Pulling docker image: quay.io/keycloak/keycloak:25.0. Please be patient; this may take some time but only needs to be done once.
03:31:14 01:31:14,417 Starting to pull image
03:31:14 01:31:14,424 Pulling image layers:  0 pending,  1 downloaded,  0 extracted, (0 bytes/0 bytes)
03:31:14 01:31:14,933 Pulling image layers:  2 pending,  2 downloaded,  0 extracted, (0 bytes/? MB)
03:31:15 01:31:15,947 Pulling image layers:  1 pending,  3 downloaded,  0 extracted, (137 MB/? MB)
03:31:18 01:31:18,591 Pulling image layers:  0 pending,  4 downloaded,  0 extracted, (137 MB/217 MB)
03:31:18 01:31:18,593 Pulling image layers:  0 pending,  5 downloaded,  0 extracted, (137 MB/217 MB)
03:31:18 01:31:18,615 Pulling image layers:  0 pending,  5 downloaded,  0 extracted, (137 MB/217 MB)
03:31:18 01:31:18,615 Pull complete. 5 layers, pulled in 4s (downloaded 137 MB at 34 MB/s)
03:31:18 01:31:18,615 Image quay.io/keycloak/keycloak:25.0 pull took PT4.73656389S
03:31:18 01:31:18,620 Creating container for image: quay.io/keycloak/keycloak:25.0
03:31:18 01:31:18,737 Container quay.io/keycloak/keycloak:25.0 is starting: 89e8405a27e8a395d749c589ffdb970b0a5b66514f78e533853aee49ba7b2eba
03:36:19 01:36:19,075 Could not start container: java.lang.IllegalStateException: Wait strategy failed. Container exited with code 1
03:36:19 	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:533)
03:36:19 	at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:354)
03:36:19 	at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:81)
03:36:19 	at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:344)
03:36:19 	at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:330)
03:36:19 	at io.quarkus.test.services.containers.DockerContainerManagedResource.doStart(DockerContainerManagedResource.java:122)
03:36:19 	at io.quarkus.test.services.containers.DockerContainerManagedResource.start(DockerContainerManagedResource.java:72)
03:36:19 	at io.quarkus.test.bootstrap.BaseService.doStart(BaseService.java:356)
03:36:19 	at io.quarkus.test.bootstrap.BaseService.start(BaseService.java:245)
03:36:19 	at io.quarkus.test.bootstrap.QuarkusScenarioBootstrap.launchService(QuarkusScenarioBootstrap.java:172)
03:36:19 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
03:36:19 	at io.quarkus.test.bootstrap.QuarkusScenarioBootstrap.beforeAll(QuarkusScenarioBootstrap.java:73)
03:36:19 	at io.quarkus.test.bootstrap.QuarkusScenarioBootstrap.beforeAll(QuarkusScenarioBootstrap.java:50)
03:36:19 	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.lambda$invokeBeforeAllCallbacks$12(ClassBasedTestDescriptor.java:396)
03:36:19 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
03:36:19 	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.invokeBeforeAllCallbacks(ClassBasedTestDescriptor.java:396)
03:36:19 	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.before(ClassBasedTestDescriptor.java:212)
03:36:19 	at org.junit.jupiter.engine.descriptor.ClassBasedTestDescriptor.before(ClassBasedTestDescriptor.java:85)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:148)
03:36:19 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
03:36:19 	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
03:36:19 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
03:36:19 	at java.base/java.util.ArrayList.forEach(ArrayList.java:1511)
03:36:19 	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.invokeAll(SameThreadHierarchicalTestExecutorService.java:41)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$6(NodeTestTask.java:155)
03:36:19 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$8(NodeTestTask.java:141)
03:36:19 	at org.junit.platform.engine.support.hierarchical.Node.around(Node.java:137)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.lambda$executeRecursively$9(NodeTestTask.java:139)
03:36:19 	at org.junit.platform.engine.support.hierarchical.ThrowableCollector.execute(ThrowableCollector.java:73)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.executeRecursively(NodeTestTask.java:138)
03:36:19 	at org.junit.platform.engine.support.hierarchical.NodeTestTask.execute(NodeTestTask.java:95)
03:36:19 	at org.junit.platform.engine.support.hierarchical.SameThreadHierarchicalTestExecutorService.submit(SameThreadHierarchicalTestExecutorService.java:35)
03:36:19 	at org.junit.platform.engine.support.hierarchical.HierarchicalTestExecutor.execute(HierarchicalTestExecutor.java:57)
03:36:19 	at org.junit.platform.engine.support.hierarchical.HierarchicalTestEngine.execute(HierarchicalTestEngine.java:54)
03:36:19 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:198)
03:36:19 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:169)
03:36:19 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:93)
03:36:19 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.lambda$execute$0(EngineExecutionOrchestrator.java:58)
03:36:19 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.withInterceptedStreams(EngineExecutionOrchestrator.java:141)
03:36:19 	at org.junit.platform.launcher.core.EngineExecutionOrchestrator.execute(EngineExecutionOrchestrator.java:57)
03:36:19 	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:103)
03:36:19 	at org.junit.platform.launcher.core.DefaultLauncher.execute(DefaultLauncher.java:85)
03:36:19 	at org.junit.platform.launcher.core.DelegatingLauncher.execute(DelegatingLauncher.java:47)
03:36:19 	at org.apache.maven.surefire.junitplatform.LazyLauncher.execute(LazyLauncher.java:56)
03:36:19 	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.execute(JUnitPlatformProvider.java:184)
03:36:19 	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invokeAllTests(JUnitPlatformProvider.java:148)
03:36:19 	at org.apache.maven.surefire.junitplatform.JUnitPlatformProvider.invoke(JUnitPlatformProvider.java:122)
03:36:19 	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:385)
03:36:19 	at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:162)
03:36:19 	at org.apache.maven.surefire.booter.ForkedBooter.run(ForkedBooter.java:507)
03:36:19 	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:495)
03:36:19 Caused by: org.testcontainers.containers.ContainerLaunchException: Timed out waiting for log output matching '.*started in.*\s'
03:36:19 	at org.testcontainers.containers.wait.strategy.LogMessageWaitStrategy.waitUntilReady(LogMessageWaitStrategy.java:47)
03:36:19 	at org.testcontainers.containers.wait.strategy.AbstractWaitStrategy.waitUntilReady(AbstractWaitStrategy.java:52)
03:36:19 	at org.testcontainers.containers.GenericContainer.waitUntilContainerStarted(GenericContainer.java:909)
03:36:19 	at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:500)
03:36:19 	... 55 more
03:36:19 
03:36:19 01:36:19,101 Log output from the failed container:
03:36:19 OpenJDK 64-Bit Server VM warning: INFO: os::commit_memory(0x00000006af400000, 4034920448, 0) failed; error='Not enough space' (errno=12)
03:36:19 #
03:36:19 # There is insufficient memory for the Java Runtime Environment to continue.
03:36:19 # Native memory allocation (mmap) failed to map 4034920448 bytes. Error detail: committing reserved memory.
03:36:19 # An error report file with more information is saved as:
03:36:19 # /tmp/hs_err_pid84.log
03:36:19 
03:36:20 [ERROR] Tests run: 1, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 308.6 s <<< FAILURE! -- in io.quarkus.ts.http.advanced.HttpAdvancedIT
03:36:20 [ERROR] io.quarkus.ts.http.advanced.HttpAdvancedIT -- Time elapsed: 308.6 s <<< ERROR!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
4 participants