[keycloak-user] Standalone-ha Keycloak and ISPN000476: Timed out waiting for responses for request

[Sebastian Laskawiec]

The new view log messages look a bit weird. It seems that JGroups installed
new view every 1 ms, which is very unusual. There are three scenarios where
this may happen (at least that I can think from the top of my head):
- Very short timeout on FD_* protocols
- Faulty NIC or incorrect network level configuration in the datacenter
- Network packets are cut when in transport. I've seen it with one of the
hardware firewalls (don't remember which one though). Due to faulty
configuration it was cutting packets to certain length causing other layers
to fail miserably.

Perhaps you could set the logging level to DEBUG on org.jgroups package and
check if there's anything interesting there?

On Wed, Oct 24, 2018 at 3:11 PM Rafael Weingärtner <
rafaelweingartner at gmail.com> wrote:

> Hello Keycloakers,
> I am having some problems with Keycloak 4.5.0. I basically have set up two
> nodes, and they see each other. I am using MPING (the default
> configuration). The nodes are called “Keycloak-1” and “Keycloak-2”. In
> front of these Keycloak nodes I have an HTTPD, which is using AJP to
> connect and load balance them.
>
> When the second server starts I can see:
>
> > 2018-10-24 12:35:02,277 INFO  [org.infinispan.CLUSTER] (MSC service
> thread
> > 1-5) ISPN000094: Received new cluster view for channel ejb:
> [keycloak-1|1]
> > (2) [keycloak-1, keycloak-2]
> > 2018-10-24 12:35:02,277 INFO  [org.infinispan.CLUSTER] (MSC service
> thread
> > 1-2) ISPN000094: Received new cluster view for channel ejb:
> [keycloak-1|1]
> > (2) [keycloak-1, keycloak-2]
> > 2018-10-24 12:35:02,278 INFO  [org.infinispan.CLUSTER] (MSC service
> thread
> > 1-3) ISPN000094: Received new cluster view for channel ejb:
> [keycloak-1|1]
> > (2) [keycloak-1, keycloak-2]
> > 2018-10-24 12:35:02,279 INFO  [org.infinispan.CLUSTER] (MSC service
> thread
> > 1-8) ISPN000094: Received new cluster view for channel ejb:
> [keycloak-1|1]
> > (2) [keycloak-1, keycloak-2]
> > 2018-10-24 12:35:02,280 INFO  [org.infinispan.CLUSTER] (MSC service
> thread
> > 1-7) ISPN000094: Received new cluster view for channel ejb:
> [keycloak-1|1]
> > (2) [keycloak-1, keycloak-2]
> >
>
> So, they are seeing/reaching each other. The problem happens when I try to
> login.  I then get the following:
>
> > MSC000001: Failed to start service
> > org.wildfly.clustering.infinispan.cache.keycloak.loginFailures:
> > org.jboss.msc.service.StartException in service
> > org.wildfly.clustering.infinispan.cache.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
> >
>
> And errors like:
>
> > Suppressed: java.util.concurrent.ExecutionException:
> > org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out
> > waiting for responses for request 2 from keycloak-2
> >
>
> 018-10-24 12:55:48,990 ERROR [org.jboss.as.controller.management-operation]
> > (Controller Boot Thread) WFLYCTL0013: Operation ("add") failed -
> address: ([
> >     ("subsystem" => "infinispan"),
> >     ("cache-container" => "ejb"),
> >     ("thread-pool" => "transport")
> > ]) - failure description: {
> >     "WFLYCTL0080: Failed services" =>
> > {"org.wildfly.clustering.infinispan.cache.ejb.client-mappings" =>
> > "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 client-mappings on keycloak-2"},
> >     "WFLYCTL0288: One or more services were unable to start due to one or
> > more indirect dependencies not being available." => {
> >         "Services that were unable to start:" =>
> > ["org.wildfly.clustering.cache.group.ejb.client-mappings"],
> >         "Services that may be the cause:" => [
> >             "jboss.clustering.web.route.default-server",
> >             "jboss.deployment.discovery.\"keycloak-server.war\"",
> >             "jboss.ejb.association",
> >             "jboss.ejb.remoting.connector.client-mappings",
> >             "jboss.iiop-openjdk.poa-service.rootpoa",
> >
>
>
> I am quite puzzled, there is not ports being blocked, and the system has no
> load at all. Why would this timeout happen?
>
> --
> Rafael Weingärtner
> _______________________________________________
> keycloak-user mailing list
> keycloak-user at lists.jboss.org
> https://lists.jboss.org/mailman/listinfo/keycloak-user