[keycloak-user] cache replication problems?

[Josh Cain]

I know for us, we keep a close eye on JVM statistics.  However, if your
infinispan cluster is on the same box as your Keycloak server (not
running anything like JDG) as ours is atm, then your JVM statistics are
only part of the story.

Iif you can *safely* enable JMX and set up a service account
appropriately, MBean statistics on cache usage would give you a really
clear picture of what Infinispan is doing:

<cache-container name="keycloak" jndi-name="infinispan/Keycloak"
statistics-enabled="true">
  ...
  <distributed-cache name="sessions" mode="SYNC" owners="1"
statistics-enabled="true"/>
  <distributed-cache name="offlineSessions" mode="SYNC" owners="1"
statistics-enabled="true"/>
  ...

From there, you can get a better idea of how the cache-container
settings can be tuned in your server config.

Josh Cain
Senior Software Applications Engineer, RHCE
Red Hat North America
jcain at redhat.com IRC: jcain

On 02/07/2018 04:15 AM, Angel Abella wrote:
> This test are with the latest KC version.
> The problems starts when the number of sessions raise above 800.000. We
> have tried to lower the access token lifespan, sso session max and sso
> session idle and it helped.
> 
> Sadly the docs are not as usefull as they should. :-(
> 
> 2018-02-07 11:03 GMT+01:00 Marek Posolda <mposolda at redhat.com>:
> 
>> What is your Keycloak version? If you used 2.X and you will migrate to
>> latest 3.4.3, there is some chance that issues might be solved as we did
>> some performance improvements.
>>
>> Overally, it depends on number of sessions, network connection between
>> cluster servers etc. If network can't be tweaked, then maybe it's possible
>> to increase replication timeout? See infinispan and Wildfly Infinispan
>> Subsystem docs for how to do it.
>>
>> Marek
>>
>>
>> On 06/02/18 12:09, Angel Abella wrote:
>>
>>> Hello,
>>>
>>> We have a 2 server standalone-ha installation. When the number of sessions
>>> alive increases we get this errors:
>>>
>>>
>>> 2018-02-06 11:42:07,161 ERROR
>>> [org.infinispan.interceptors.InvocationContextInterceptor] (default
>>> task-22) ISPN000136: Error executing command PutKeyValueCommand, writing
>>> keys [f75b436f-d316-4442-8d9b-c7313647c5b8]:
>>> org.infinispan.util.concurrent.TimeoutException: Replication timeout for
>>> sson2
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> checkRsp(JGroupsTransport.java:827)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> lambda$invokeRemotelyAsync$0(JGroupsTransport.java:628)
>>>          at
>>> java.util.concurrent.CompletableFuture.uniApply(CompletableF
>>> uture.java:602)
>>>          at
>>> java.util.concurrent.CompletableFuture$UniApply.tryFire(
>>> CompletableFuture.java:577)
>>>          at
>>> java.util.concurrent.CompletableFuture.postComplete(Completa
>>> bleFuture.java:474)
>>>          at
>>> java.util.concurrent.CompletableFuture.complete(CompletableF
>>> uture.java:1962)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:46)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:17)
>>>          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.run(ScheduledThreadPoolExecutor.java:293)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>>          at java.lang.Thread.run(Thread.java:745)
>>>
>>> 2018-02-06 11:42:07,162 ERROR
>>> [org.keycloak.services.error.KeycloakErrorHandler] (default task-22)
>>> Uncaught server error: org.infinispan.util.concurrent.TimeoutException:
>>> Replication timeout for sson2
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> checkRsp(JGroupsTransport.java:827)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> lambda$invokeRemotelyAsync$0(JGroupsTransport.java:628)
>>>          at
>>> java.util.concurrent.CompletableFuture.uniApply(CompletableF
>>> uture.java:602)
>>>          at
>>> java.util.concurrent.CompletableFuture$UniApply.tryFire(
>>> CompletableFuture.java:577)
>>>          at
>>> java.util.concurrent.CompletableFuture.postComplete(Completa
>>> bleFuture.java:474)
>>>          at
>>> java.util.concurrent.CompletableFuture.complete(CompletableF
>>> uture.java:1962)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:46)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:17)
>>>          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.run(ScheduledThreadPoolExecutor.java:293)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>>          at java.lang.Thread.run(Thread.java:745)
>>>
>>> 2018-02-06 11:42:07,166 ERROR
>>> [org.infinispan.interceptors.InvocationContextInterceptor] (default
>>> task-17) ISPN000136: Error executing command RemoveCommand, writing keys
>>> [0d8d4c5c-7971-46dd-b414-cb5f16862085]:
>>> org.infinispan.util.concurrent.TimeoutException: Replication timeout for
>>> sson2
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> checkRsp(JGroupsTransport.java:827)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> lambda$invokeRemotelyAsync$0(JGroupsTransport.java:628)
>>>          at
>>> java.util.concurrent.CompletableFuture.uniApply(CompletableF
>>> uture.java:602)
>>>          at
>>> java.util.concurrent.CompletableFuture$UniApply.tryFire(
>>> CompletableFuture.java:577)
>>>          at
>>> java.util.concurrent.CompletableFuture.postComplete(Completa
>>> bleFuture.java:474)
>>>          at
>>> java.util.concurrent.CompletableFuture.complete(CompletableF
>>> uture.java:1962)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:46)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:17)
>>>          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.run(ScheduledThreadPoolExecutor.java:293)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>>          at java.lang.Thread.run(Thread.java:745)
>>>
>>> 2018-02-06 11:42:07,171 ERROR
>>> [org.infinispan.interceptors.InvocationContextInterceptor] (default
>>> task-11) ISPN000136: Error executing command PutKeyValueCommand, writing
>>> keys [dfd69644-e241-465c-8a92-ef84e76caf62]:
>>> org.infinispan.util.concurrent.TimeoutException: Replication timeout for
>>> sson2
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> checkRsp(JGroupsTransport.java:827)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> lambda$invokeRemotelyAsync$0(JGroupsTransport.java:628)
>>>          at
>>> java.util.concurrent.CompletableFuture.uniApply(CompletableF
>>> uture.java:602)
>>>          at
>>> java.util.concurrent.CompletableFuture$UniApply.tryFire(
>>> CompletableFuture.java:577)
>>>          at
>>> java.util.concurrent.CompletableFuture.postComplete(Completa
>>> bleFuture.java:474)
>>>          at
>>> java.util.concurrent.CompletableFuture.complete(CompletableF
>>> uture.java:1962)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:46)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:17)
>>>          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.run(ScheduledThreadPoolExecutor.java:293)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>>          at java.lang.Thread.run(Thread.java:745)
>>>
>>> 2018-02-06 11:42:07,173 ERROR
>>> [org.keycloak.services.error.KeycloakErrorHandler] (default task-11)
>>> Uncaught server error: org.infinispan.util.concurrent.TimeoutException:
>>> Replication timeout for sson2
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> checkRsp(JGroupsTransport.java:827)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> lambda$invokeRemotelyAsync$0(JGroupsTransport.java:628)
>>>          at
>>> java.util.concurrent.CompletableFuture.uniApply(CompletableF
>>> uture.java:602)
>>>          at
>>> java.util.concurrent.CompletableFuture$UniApply.tryFire(
>>> CompletableFuture.java:577)
>>>          at
>>> java.util.concurrent.CompletableFuture.postComplete(Completa
>>> bleFuture.java:474)
>>>          at
>>> java.util.concurrent.CompletableFuture.complete(CompletableF
>>> uture.java:1962)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:46)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:17)
>>>          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.run(ScheduledThreadPoolExecutor.java:293)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>>          at java.lang.Thread.run(Thread.java:745)
>>>
>>> 2018-02-06 11:42:07,205 ERROR
>>> [org.keycloak.services.error.KeycloakErrorHandler] (default task-17)
>>> Uncaught server error: org.infinispan.util.concurrent.TimeoutException:
>>> Replication timeout for sson2
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> checkRsp(JGroupsTransport.java:827)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.JGroupsTransport.
>>> lambda$invokeRemotelyAsync$0(JGroupsTransport.java:628)
>>>          at
>>> java.util.concurrent.CompletableFuture.uniApply(CompletableF
>>> uture.java:602)
>>>          at
>>> java.util.concurrent.CompletableFuture$UniApply.tryFire(
>>> CompletableFuture.java:577)
>>>          at
>>> java.util.concurrent.CompletableFuture.postComplete(Completa
>>> bleFuture.java:474)
>>>          at
>>> java.util.concurrent.CompletableFuture.complete(CompletableF
>>> uture.java:1962)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:46)
>>>          at
>>> org.infinispan.remoting.transport.jgroups.SingleResponseFutu
>>> re.call(SingleResponseFuture.java:17)
>>>          at java.util.concurrent.FutureTask.run(FutureTask.java:266)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.access$201(ScheduledThreadPoolExecutor.java:180)
>>>          at
>>> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFu
>>> tureTask.run(ScheduledThreadPoolExecutor.java:293)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPool
>>> Executor.java:1142)
>>>          at
>>> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoo
>>> lExecutor.java:617)
>>>          at java.lang.Thread.run(Thread.java:745)
>>>
>>>
>>>
>>> Any idea of what's going on?
>>>
>>>
>>
> 
> 

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 833 bytes
Desc: OpenPGP digital signature
Url : http://lists.jboss.org/pipermail/keycloak-user/attachments/20180207/534c1dd4/attachment-0001.bin