I'm using jboss/keycloak:15.1.0 docker image for integration testing in the Gitlab CI. Single Keycloak service for a job with many jobs as a part of a single pipeline. Sometimes it fails to start (in less than 1/4 of cases). The issue was observable for jboss/keycloak:15.0.2 as well.
The only startup arguments that I set are KEYCLOAK_USER, KEYCLOAK_PASSWORD, KEYCLOAK_LOGLEVEL, and DB_VENDOR. Which is equivalent to docker run -e KEYCLOAK_USER=admin@email.com -e KEYCLOAK_PASSWORD=admin -e KEYCLOAK_LOGLEVEL=DEBUG -e DB_VENDOR=h2 jboss/keycloak:15.0.2.
The first error in the chain is
11:03:41,856 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 64) MSC000001: Failed to start service org.wildfly.clustering.infinispan.cache.keycloak.work: org.jboss.msc.service.StartException in service org.wildfly.clustering.infinispan.cache.keycloak.work: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
Here are more error/warning logs
2021-12-16 11:03:42
11:03:42,079 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0051: Admin console listening on http://127.0.0.1:9990
2021-12-16 11:03:42
11:03:42,078 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0060: Http management interface listening on http://127.0.0.1:9990/management
2021-12-16 11:03:42
11:03:42,075 ERROR [org.jboss.as] (Controller Boot Thread) WFLYSRV0026: Keycloak 15.1.0 (WildFly Core 15.0.1.Final) started (with errors) in 246739ms - Started 633 of 949 services (14 services failed or missing dependencies, 701 services are lazy, passive or on-demand)
2021-12-16 11:03:42
11:03:42,066 INFO [org.jboss.as.server] (Controller Boot Thread) WFLYSRV0212: Resuming server
2021-12-16 11:03:42
WFLYCTL0448: 3 additional services are down due to their dependencies being missing or failed
2021-12-16 11:03:42
WFLYCTL0186: Services which failed to start: service org.wildfly.clustering.infinispan.cache.keycloak.work: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:42
11:03:42,004 INFO [org.jboss.as.controller] (Controller Boot Thread) WFLYCTL0183: Service status report
2021-12-16 11:03:42
11:03:42,003 INFO [org.jboss.as.server] (ServerService Thread Pool -- 46) WFLYSRV0010: Deployed "keycloak-server.war" (runtime-name : "keycloak-server.war")
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("store" => "none")
2021-12-16 11:03:41
("replicated-cache" => "work"),
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,989 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("memory" => "heap")
2021-12-16 11:03:41
("replicated-cache" => "work"),
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,989 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("component" => "transaction")
2021-12-16 11:03:41
("replicated-cache" => "work"),
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,989 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("component" => "state-transfer")
2021-12-16 11:03:41
("replicated-cache" => "work"),
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,988 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("component" => "partition-handling")
2021-12-16 11:03:41
("replicated-cache" => "work"),
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,988 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("component" => "locking")
2021-12-16 11:03:41
("replicated-cache" => "work"),
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,988 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("component" => "backups")
2021-12-16 11:03:41
("replicated-cache" => "work"),
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,987 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4"}}
2021-12-16 11:03:41
]) - failure description: {"WFLYCTL0080: Failed services" => {"org.wildfly.clustering.infinispan.cache.keycloak.work" => "org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
("replicated-cache" => "work")
2021-12-16 11:03:41
("cache-container" => "keycloak"),
2021-12-16 11:03:41
("subsystem" => "infinispan"),
2021-12-16 11:03:41
11:03:41,986 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
2021-12-16 11:03:41
2021-12-16 11:03:41
... 7 more
2021-12-16 11:03:41
at org.wildfly.clustering.service@23.0.2.Final//org.wildfly.clustering.service.FunctionalService.start(FunctionalService.java:63)
2021-12-16 11:03:41
at org.wildfly.clustering.infinispan.spi@23.0.2.Final//org.wildfly.clustering.infinispan.spi.service.CacheServiceConfigurator.get(CacheServiceConfigurator.java:55)
2021-12-16 11:03:41
at org.wildfly.clustering.infinispan.spi@23.0.2.Final//org.wildfly.clustering.infinispan.spi.service.CacheServiceConfigurator.get(CacheServiceConfigurator.java:77)
2021-12-16 11:03:41
at org.jboss.as.clustering.infinispan@23.0.2.Final//org.jboss.as.clustering.infinispan.DefaultCacheContainer.getCache(DefaultCacheContainer.java:92)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.manager.DefaultCacheManager.getCache(DefaultCacheManager.java:510)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.manager.DefaultCacheManager.internalGetCache(DefaultCacheManager.java:532)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:643)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.manager.DefaultCacheManager.wireAndStartCache(DefaultCacheManager.java:697)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:512)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:512)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.cache.impl.AbstractDelegatingCache.start(AbstractDelegatingCache.java:512)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.cache.impl.CacheImpl.start(CacheImpl.java:1011)
2021-12-16 11:03:41
at org.infinispan@11.0.9.Final//org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete(StateTransferManagerImpl.java:246)
2021-12-16 11:03:41
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:03:41
at org.jboss.threads@2.4.0.Final//org.jboss.threads.JBossThread.run(JBossThread.java:513)
2021-12-16 11:03:41
at java.base/java.lang.Thread.run(Thread.java:829)
2021-12-16 11:03:41
at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1348)
2021-12-16 11:03:41
at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
2021-12-16 11:03:41
at org.jboss.threads@2.4.0.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
2021-12-16 11:03:41
at org.jboss.threads@2.4.0.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
2021-12-16 11:03:41
at org.wildfly.clustering.service@23.0.2.Final//org.wildfly.clustering.service.AsyncServiceConfigurator$AsyncService.lambda$start$0(AsyncServiceConfigurator.java:117)
2021-12-16 11:03:41
at org.wildfly.clustering.service@23.0.2.Final//org.wildfly.clustering.service.FunctionalService.start(FunctionalService.java:66)
2021-12-16 11:03:41
11:03:41,856 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 64) MSC000001: Failed to start service org.wildfly.clustering.infinispan.cache.keycloak.work: org.jboss.msc.service.StartException in service org.wildfly.clustering.infinispan.cache.keycloak.work: org.infinispan.commons.CacheException: Initial state transfer timed out for cache work on runner-ajvcf6kf-project-136-concurrent-54h6r4
2021-12-16 11:00:06
11:00:06,819 WARN [org.jboss.as.ejb3.remote] (ClusterTopologyRegistrar - 1) WFLYEJB0509: Clustered Jakarta Enterprise Beans in Node: runner-ajvcf6kf-project-136-concurrent-6x4j6c are bound to INADDR_ANY(0.0.0.0). Either use a non-wildcard server bind address or add client-mapping entries to the relevant socket-binding for the Remoting connector
Here are full logs.
It looks like a bug in Keycloak or its dependencies. I assume that the underlying error is Wildfly not being able to start Initial state transfer timed out for cache work. It's not clear what causes the issue though.
It looks like the others face similar issues. E.g., here and here. The suggested workarounds where to reconfigure Wildfly (e.g., to increase the timeout), yet I'm not sure if it's feasible for the Keycloak docker container.
Here is the corresponding Keycloak issue.
Any ideas (even workarounds) are welcome.
