[keycloak-user] Initial state transfer times out for cache loginFailures

Dan Corbett dcorbett at expedia.com
Tue Jun 27 18:09:01 EDT 2017


We have a 3 node cluster of Keycloak 3.1.0.Final (WildFly Core 2.0.10.Final) running in Docker AWS ECS.
It all has been running smoothly for many months, through various versions, deployments and recycles.

Just recently, when one of the containers was terminated, the new container was run by ECS but could not start Keycloak and join the cluster.

Error is:  Failed to start service jboss.infinispan.keycloak.loginFailures: org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures, Initial state transfer timed out for cache loginFailures

We also see some of the following, which may be related?
2017-06-27 05:54:01,914 DEBUG [org.infinispan.remoting.inboundhandler.NonTotalOrderPerCacheInboundInvocationHandler] (remote-thread--p10-t3) ISPN000311: Received a command from an outdated topology, returning the exception to caller: org.infinispan.statetransfer.OutdatedTopologyException: Cache topology changed while the command was executing: expected 1962, got 1963

We enabled various Debug log levels but haven’t yet found anything conclusive.
We tried clearing caches via Infinispan JMX tooling etc, but still could not start the new node.
The two remaining instances were still clustered OK.
We provisioned additional cluster and it's working as expected, so don’t believe at this stage it’s a network communication issue.

Found this report for Redhat SSO, seems similar? I can’t see solution. https://access.redhat.com/solutions/2841711

Any info on possible cause or how to debug/investigate further would be a great help.
Configs and logs below..

Thanks
Dan

Our cache config is:

<subsystem xmlns="urn:jboss:domain:infinispan:4.0">
            <cache-container name="keycloak" jndi-name="infinispan/Keycloak">
                <transport lock-timeout="60000"/>
                <local-cache name="realms">
                    <eviction max-entries="10000" strategy="LRU"/>
                </local-cache>
                <local-cache name="users">
                    <eviction max-entries="10000" strategy="LRU"/>
                </local-cache>
                <distributed-cache name="sessions" mode="SYNC" owners="5" />
                <distributed-cache name="offlineSessions" mode="SYNC" owners="1" />
                <distributed-cache name="loginFailures" mode="SYNC" owners="1"/>
                <distributed-cache name="authorization" mode="SYNC" owners="1"/>
                <replicated-cache name="work" mode="SYNC"/>
                <local-cache name="keys">
                    <eviction max-entries="1000" strategy="LRU"/>
                    <expiration max-idle="3600000"/>
                </local-cache>
            </cache-container>
            <cache-container name="server" aliases="singleton cluster" default-cache="default" module="org.wildfly.clustering.server">
                <transport lock-timeout="60000"/>
                <replicated-cache name="default" mode="SYNC">
                    <transaction mode="BATCH"/>
                </replicated-cache>
            </cache-container>
            <cache-container name="web" default-cache="dist" module="org.wildfly.clustering.web.infinispan">
                <transport lock-timeout="60000"/>
                <distributed-cache name="dist" mode="ASYNC" l1-lifespan="0" owners="2">
                    <locking isolation="REPEATABLE_READ"/>
                    <transaction mode="BATCH"/>
                    <file-store/>
                </distributed-cache>
            </cache-container>
            <cache-container name="ejb" aliases="sfsb" default-cache="dist" module="org.wildfly.clustering.ejb.infinispan">
                <transport lock-timeout="60000"/>
                <distributed-cache name="dist" mode="ASYNC" l1-lifespan="0" owners="2">
                    <locking isolation="REPEATABLE_READ"/>
                    <transaction mode="BATCH"/>
                    <file-store/>
                </distributed-cache>
            </cache-container>
            <cache-container name="hibernate" default-cache="local-query" module="org.hibernate.infinispan">
                <transport lock-timeout="60000"/>
                <local-cache name="local-query">
                    <eviction strategy="LRU" max-entries="10000"/>
                    <expiration max-idle="100000"/>
                </local-cache>
                <invalidation-cache name="entity" mode="SYNC">
                    <transaction mode="NON_XA"/>
                    <eviction strategy="LRU" max-entries="10000"/>
                    <expiration max-idle="100000"/>
                </invalidation-cache>
                <replicated-cache name="timestamps" mode="ASYNC"/>
            </cache-container>
        </subsystem>

Snip of error log below.

02:49:49,248 INFO  [org.jboss.as.clustering.infinispan] (ServerService Thread Pool -- 60) WFLYCLINF0002: Started sessions cache from keycloak container
02:53:48,262 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 53) MSC000001: Failed to start service jboss.infinispan.keycloak.loginFailures: org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
at org.wildfly.clustering.service.AsynchronousServiceBuilder$1.run(AsynchronousServiceBuilder.java:107)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at org.jboss.threads.JBossThread.run(JBossThread.java:320)
Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
at org.infinispan.commons.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:172)
at org.infinispan.factories.AbstractComponentRegistry$PrioritizedMethod.invoke(AbstractComponentRegistry.java:870)
at org.infinispan.factories.AbstractComponentRegistry.invokeStartMethods(AbstractComponentRegistry.java:639)
at org.infinispan.factories.AbstractComponentRegistry.internalStart(AbstractComponentRegistry.java:628)
at org.infinispan.factories.AbstractComponentRegistry.start(AbstractComponentRegistry.java:531)
at org.infinispan.factories.ComponentRegistry.start(ComponentRegistry.java:222)
at org.infinispan.cache.impl.CacheImpl.start(CacheImpl.java:849)
at org.infinispan.manager.DefaultCacheManager.wireAndStartCache(DefaultCacheManager.java:621)
at org.infinispan.manager.DefaultCacheManager.createCache(DefaultCacheManager.java:572)
at org.infinispan.manager.DefaultCacheManager.getCache(DefaultCacheManager.java:440)
at org.jboss.as.clustering.infinispan.DefaultCacheContainer.lambda$getCache$6(DefaultCacheContainer.java:119)
at org.jboss.as.clustering.infinispan.DefaultCacheContainer.getCache(DefaultCacheContainer.java:120)
at org.jboss.as.clustering.infinispan.DefaultCacheContainer.getCache(DefaultCacheContainer.java:114)
at org.wildfly.clustering.infinispan.spi.service.CacheBuilder.start(CacheBuilder.java:80)
at org.wildfly.clustering.service.AsynchronousServiceBuilder$1.run(AsynchronousServiceBuilder.java:102)
... 4 more
Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d
at org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete(StateTransferManagerImpl.java:224)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at org.infinispan.commons.util.ReflectionUtil.invokeAccessibly(ReflectionUtil.java:168)
... 18 more
02:53:48,275 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,276 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "backup-for")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,276 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "backups")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,277 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "eviction")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,277 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "expiration")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,277 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "locking")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,278 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "partition-handling")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,278 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "state-transfer")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,279 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("component" => "transaction")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,279 ERROR [org.jboss.as.controller.management-operation] (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed - address: ([
    ("subsystem" => "infinispan"),
    ("cache-container" => "keycloak"),
    ("distributed-cache" => "loginFailures"),
    ("store" => "none")
]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.infinispan.keycloak.loginFailures" => "org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl
    Caused by: org.infinispan.commons.CacheException: Initial state transfer timed out for cache loginFailures on 9c8ea5960a4d"}}
02:53:48,350 INFO  [org.jboss.as.server] (ServerService Thread Pool -- 51) WFLYSRV0010: Deployed "keycloak-server.war" (runtime-name : "keycloak-server.war")
02:53:48,369 INFO  [org.jboss.as.controller] (Controller Boot Thread) WFLYCTL0183: Service status report
WFLYCTL0186:   Services which failed to start:      service jboss.infinispan.keycloak.loginFailures: org.jboss.msc.service.StartException in service jboss.infinispan.keycloak.loginFailures: org.infinispan.commons.CacheException: Unable to invoke method public void org.infinispan.statetransfer.StateTransferManagerImpl.waitForInitialStateTransferToComplete() throws java.lang.Exception on object of type StateTransferManagerImpl




More information about the keycloak-user mailing list