Keycloak 8.0.1 infinispan error

Getting advice
1

Hi,

In Keycloak 8.0.1 version, I have two nodes working in standalone cluster mode(standalone-ha).

I often get the following error:

Node1 logs:

2020-04-08 07:56:06,274 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p14-t1) ISPN000136: Error executing command RemoveExpiredCommand on Cache 'work', writing keys [4505cb41-3e1c-417d-85a3-5b0b94d406ca]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4108 from NODE2
                at org.infinispan.remoting.transport.impl.SingleTargetRequest.onTimeout(SingleTargetRequest.java:65)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)

2020-04-08 07:56:06,470 WARN  [org.infinispan.expiration.impl.ClusterExpirationManager] (expiration-thread--p26-t1) ISPN000026: Caught exception purging data container!: java.util.concurrent.CompletionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4108 from NODE2
                at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
                at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
                at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:593)
                at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)
                at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
                at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977)
                at org.infinispan.interceptors.impl.QueueAsyncInvocationStage.invokeQueuedHandlers(QueueAsyncInvocationStage.java:108)
                at org.infinispan.interceptors.impl.QueueAsyncInvocationStage.accept(QueueAsyncInvocationStage.java:81)
                at org.infinispan.interceptors.impl.QueueAsyncInvocationStage.accept(QueueAsyncInvocationStage.java:30)
                at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760)
                at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736)
                at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
                at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977)
                at org.infinispan.remoting.transport.AbstractRequest.completeExceptionally(AbstractRequest.java:74)
                at org.infinispan.remoting.transport.impl.SingleTargetRequest.onTimeout(SingleTargetRequest.java:65)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)
Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4108 from NODE2
                ... 9 more

2020-04-08 07:56:17,800 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p14-t1) ISPN000136: Error executing command RemoveExpiredCommand on Cache 'work', writing keys [1a7463c7-d1c8-4066-b9b9-1b866a0e6fa5]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4110 from NODE2
                at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)

2020-04-08 07:56:17,800 WARN  [org.infinispan.remoting.inboundhandler.NonTotalOrderPerCacheInboundInvocationHandler] (timeout-thread--p14-t1) ISPN000071: Caught exception when handling command SingleRpcCommand{cacheName='work', command=RemoveExpiredCommand{key=1a7463c7-d1c8-4066-b9b9-1b866a0e6fa5, value=WrapperClusterEvent [ eventKey=REALM_INVALIDATION_EVENTS, sender=NODE2, senderSite=null, delegateEvent=RealmUpdatedEvent [ realmId=master, realmName=master ] ], lifespan=120000, maxIde=false}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4110 from NODE2
                at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)

Node2 logs:

2020-04-08 07:56:43,125 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p12-t1) ISPN000136: Error executing command RemoveExpiredCommand on Cache 'work', writing keys [4505cb41-3e1c-417d-85a3-5b0b94d406ca]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4135 from NODE1
                at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)

2020-04-08 07:56:43,227 WARN  [org.infinispan.remoting.inboundhandler.NonTotalOrderPerCacheInboundInvocationHandler] (timeout-thread--p12-t1) ISPN000071: Caught exception when handling command SingleRpcCommand{cacheName='work', command=RemoveExpiredCommand{key=4505cb41-3e1c-417d-85a3-5b0b94d406ca, value=WrapperClusterEvent [ eventKey=REALM_INVALIDATION_EVENTS, sender=NODE2, senderSite=null, delegateEvent=RealmUpdatedEvent [ realmId=master, realmName=master ] ], lifespan=120000, maxIde=false}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4135 from NODE1
                at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)

2020-04-08 07:56:54,393 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p12-t1) ISPN000136: Error executing command RemoveExpiredCommand on Cache 'work', writing keys [af4f1a20-7f78-402b-82ce-7a0ff9d8ec0d]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4138 from NODE1
                at org.infinispan.remoting.transport.impl.SingleTargetRequest.onTimeout(SingleTargetRequest.java:65)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)
				
2020-04-08 07:56:54,392 WARN  [org.infinispan.expiration.impl.ClusterExpirationManager] (expiration-thread--p26-t1) ISPN000026: Caught exception purging data container!: java.util.concurrent.CompletionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4137 from NODE1
                at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:292)
                at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:308)
                at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:593)
                at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577)
                at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
                at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977)
                at org.infinispan.interceptors.impl.QueueAsyncInvocationStage.invokeQueuedHandlers(QueueAsyncInvocationStage.java:108)
                at org.infinispan.interceptors.impl.QueueAsyncInvocationStage.accept(QueueAsyncInvocationStage.java:81)
                at org.infinispan.interceptors.impl.QueueAsyncInvocationStage.accept(QueueAsyncInvocationStage.java:30)
                at java.util.concurrent.CompletableFuture.uniWhenComplete(CompletableFuture.java:760)
                at java.util.concurrent.CompletableFuture$UniWhenComplete.tryFire(CompletableFuture.java:736)
                at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474)
                at java.util.concurrent.CompletableFuture.completeExceptionally(CompletableFuture.java:1977)
                at org.infinispan.remoting.transport.AbstractRequest.completeExceptionally(AbstractRequest.java:74)
                at org.infinispan.remoting.transport.impl.SingleTargetRequest.onTimeout(SingleTargetRequest.java:65)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
                at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
                at java.util.concurrent.FutureTask.run(FutureTask.java:266)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
                at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
                at java.lang.Thread.run(Thread.java:748)
Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4137 from NODE1
                ... 9 more

When this error occurs, I cant login to the portal, it gives an Internal server error.
I refresh the page, it gives a warning that you are already logged in.

This is valid for both nodes.

When i restart the one of this nodes, problem solved.

Has anyone experienced situation like this before?

1 Like
2

Hi,

please did you resolve this issue? I had the same issue

2021-11-10 16:02:02,590 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread–p16-t1) ISPN000136: Error executing command RemoveCommand on Cache ‘authenticationSessions’, writing
keys [9733ce4f-4ae9-4095-8c35-f44a2933b9a7]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 11371503 from slave
at org.infinispan.remoting.transport.impl.SingleTargetRequest.onTimeout(SingleTargetRequest.java:82)
at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)

3

What is your configuration for jgroups? how do you do node discovery? this is most likely a discovery issue.

4

Having similar issue, in my case when one of the keycloak nodes goes down other one gives below timeout errors and are not operational, + healthcheck shows ok 200 but in reality it does not work properly.

`2022-07-25 03:41:40,827 ERROR 
[org.infinispan.interceptors.impl.InvocationContextInterceptor] 
(timeout-thread--p4-t1) ISPN000136: Error executing command 
PutKeyValueCommand on Cache 'work', writing keys 
[task::RadiusLogout$Lambda$779/0x00000008408d9c40]: 
org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out 
waiting for responses for request 212 from host1`
5

I have the same issue.
Does anyone fix this issue?