3.9.0 does not start #200
Description
Hi, we're using fast-data-dev for our CI tests and they stopped working today.
3.9.0 seems to have some issues starting, our log output:
2025-06-25 14:27:13.492 INFO 1536 --- [ForkJoinPool.commonPool-worker-3] e.g.j.d.c.i.DefaultServiceScheduler : Starting kafka service
2025-06-25 14:29:14.110 ERROR 1536 --- [ForkJoinPool.commonPool-worker-3] tc.lensesio/fast-data-dev:latest : Could not start container
org.testcontainers.containers.ContainerLaunchException: Timed out waiting for container port to open (localhost ports: [49092, 49093] should be listening)
at org.testcontainers.containers.wait.strategy.HostPortWaitStrategy.waitUntilReady(HostPortWaitStrategy.java:112)
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:492)
at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:346)
at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:81)
at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:336)
at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:322)
at eu.gourban.jarvis.deployment.docker.DockerService.start(DockerService.java:38)
at eu.gourban.jarvis.deployment.core.internal.DefaultServiceScheduler.lambda$deploy$0(DefaultServiceScheduler.java:39)
at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804)
at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1796)
at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)
2025-06-25 14:29:14.180 ERROR 1536 --- [ForkJoinPool.commonPool-worker-3] tc.lensesio/fast-data-dev:latest : Log output from the failed container:
Starting services.
This is Lenses.io’s fast-data-dev. Kafka 3.9.0-L0 (Lenses.io's Kafka Distribution).
You may visit http://127.0.0.1:3030 in about a minute.
2025-06-25 14:28:14,236 INFO Included extra file "/etc/supervisord.d/02-broker.conf" during parsing
2025-06-25 14:28:14,236 INFO Included extra file "/etc/supervisord.d/03-schema-registry.conf" during parsing
2025-06-25 14:28:14,236 INFO Included extra file "/etc/supervisord.d/05-connect-distributed.conf" during parsing
2025-06-25 14:28:14,236 INFO Included extra file "/etc/supervisord.d/06-caddy.conf" during parsing
2025-06-25 14:28:14,236 INFO Included extra file "/etc/supervisord.d/08-logs-to-kafka.conf" during parsing
2025-06-25 14:28:14,236 INFO Set uid to user 0 succeeded
2025-06-25 14:28:14,238 INFO RPC interface 'supervisor' initialized
2025-06-25 14:28:14,238 CRIT Server 'unix_http_server' running without any HTTP authentication checking
2025-06-25 14:28:14,238 INFO supervisord started with pid 7
2025-06-25 14:28:15,243 INFO spawned: 'broker' with pid 229
2025-06-25 14:28:15,245 INFO spawned: 'caddy' with pid 231
2025-06-25 14:28:15,247 INFO spawned: 'connect-distributed' with pid 232
2025-06-25 14:28:15,248 INFO spawned: 'logs-to-kafka' with pid 236
2025-06-25 14:28:15,249 INFO spawned: 'schema-registry' with pid 238
2025-06-25 14:28:16,613 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:16,613 INFO success: caddy entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:16,613 INFO success: connect-distributed entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:16,613 INFO success: logs-to-kafka entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:16,613 INFO success: schema-registry entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:18,549 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:18,657 INFO spawned: 'broker' with pid 2514
2025-06-25 14:28:19,666 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:21,233 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:21,277 INFO spawned: 'broker' with pid 4336
2025-06-25 14:28:22,637 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:23,954 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:24,293 INFO spawned: 'broker' with pid 6172
2025-06-25 14:28:25,627 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:26,904 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:27,057 INFO spawned: 'broker' with pid 7998
2025-06-25 14:28:28,399 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:29,678 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:29,817 INFO spawned: 'broker' with pid 9824
2025-06-25 14:28:30,832 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:32,931 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:32,964 INFO spawned: 'broker' with pid 11662
2025-06-25 14:28:34,451 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:35,773 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:35,821 INFO spawned: 'broker' with pid 13497
2025-06-25 14:28:37,300 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:38,689 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:38,993 INFO spawned: 'broker' with pid 15338
2025-06-25 14:28:40,228 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:41,694 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:41,800 INFO spawned: 'broker' with pid 17170
2025-06-25 14:28:43,129 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:44,414 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:44,478 INFO spawned: 'broker' with pid 18987
2025-06-25 14:28:45,805 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:47,117 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:47,372 INFO spawned: 'broker' with pid 20818
2025-06-25 14:28:48,706 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:50,080 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:50,196 INFO spawned: 'broker' with pid 22648
2025-06-25 14:28:51,382 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:53,157 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:53,395 INFO spawned: 'broker' with pid 24494
2025-06-25 14:28:54,575 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:56,349 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:28:57,186 INFO spawned: 'broker' with pid 26374
2025-06-25 14:28:58,278 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:28:59,782 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:29:00,177 INFO spawned: 'broker' with pid 28212
2025-06-25 14:29:01,367 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:29:02,801 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:29:02,963 INFO spawned: 'broker' with pid 30038
2025-06-25 14:29:04,066 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:29:05,768 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:29:06,601 INFO spawned: 'broker' with pid 32325
2025-06-25 14:29:07,940 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:29:09,220 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:29:09,366 INFO spawned: 'broker' with pid 34148
2025-06-25 14:29:10,675 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:29:11,957 WARN exited: broker (exit status 1; not expected)
2025-06-25 14:29:12,155 INFO spawned: 'broker' with pid 35977
2025-06-25 14:29:13,462 INFO success: broker entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)
2025-06-25 14:29:14.471 ERROR 1536 --- [ForkJoinPool.commonPool-worker-3] e.g.j.d.c.i.DefaultServiceScheduler : Service kafka readiness failed!
org.testcontainers.containers.ContainerLaunchException: Container startup failed for image lensesio/fast-data-dev:latest
at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:351)
at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:322)
at eu.gourban.jarvis.deployment.docker.DockerService.start(DockerService.java:38)
at eu.gourban.jarvis.deployment.core.internal.DefaultServiceScheduler.lambda$deploy$0(DefaultServiceScheduler.java:39)
at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1804)
at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(CompletableFuture.java:1796)
at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:387)
at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(ForkJoinPool.java:1312)
at java.base/java.util.concurrent.ForkJoinPool.scan(ForkJoinPool.java:1843)
at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1808)
at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:188)
Caused by: org.rnorth.ducttape.RetryCountExceededException: Retry limit hit with exception
at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:88)
at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:336)
... 10 common frames omitted
Caused by: org.testcontainers.containers.ContainerLaunchException: Could not create/start container
at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:556)
at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:346)
at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:81)
... 11 common frames omitted
Caused by: org.testcontainers.containers.ContainerLaunchException: Timed out waiting for container port to open (localhost ports: [49092, 49093] should be listening)
at org.testcontainers.containers.wait.strategy.HostPortWaitStrategy.waitUntilReady(HostPortWaitStrategy.java:112)
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:492)
... 13 common frames omitted