Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-10317

CIRCULAR REFERENCE:org.infinispan.util.concurrent.TimeoutException in a 4 node cluster during fail-over

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Obsolete
    • Icon: Minor Minor
    • None
    • 13.0.0.Beta1
    • Clustering
    • None
    • Hide
      • Set up a WilfFly cluster composed of 4 nodes running in standalone-ha profile
      • Use mod_jk to load balance all the 4 nodes; each node configured with fail_on_status=404,503
      • Deploy clusterbench application on each node (see attached ear file)
      • Start making requests to load balancer (2000 clients, 4000 ms delay between subsequent requests on each client)
      • Start failing and then resuming all the 4 nodes in a sequence
      Show
      Set up a WilfFly cluster composed of 4 nodes running in standalone-ha profile Use mod_jk to load balance all the 4 nodes; each node configured with fail_on_status=404,503 Deploy clusterbench application on each node (see attached ear file) Start making requests to load balancer (2000 clients, 4000 ms delay between subsequent requests on each client) Start failing and then resuming all the 4 nodes in a sequence

      We observed this new "CIRCULAR REFERENCE" message in the logs while running one of the regular fail-over tests.
      Given that performance is not impacted, the goal of this Issue is to get some investigation on what changed and why this message appeared.
      We observed the following error when the cache is configured as replicated and synchronous.
      We did not have the error when the cache is configured as distributed and synchronous.

      The following Jenkins runs provide both the new and the old situation for comparison:

      • CIRCULAR REFERENCE : jenkins execution with latest wildfly version 13.0.0.Alpha1-SNAPSHOT where the "CIRCULAR REFERENCE" message can be seen in logs
      • NO CIRCULAR REFERENCE : jenkins execution with latest wildfly version 12.0.0.Final where no "CIRCULAR REFERENCE" message is present

      In the following we give more details about the two runs.

      For the first run, we used master branch from 13.0.0.Alpha1-SNAPSHO​T.
      We observe lot of errors (more than a hundred on each node) like the following, note they occur right after one node has been stopped and restarted and then another node is stopped and restarted:

      2018/05/02 09:03:33:843 EDT [DEBUG][Thread-82] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - JBossStartup, server started!
      [JBossINF] �[0m�[0m09:03:34,007 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-5) New session created: TXIN2deAqLp1QHmZzzQXXrUyTslOYCAx9pazOIo5
      [JBossINF] �[0m�[0m09:03:34,007 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-6) New session created: px4vAOKxK8pJ74234T406YgN3jG4e0Z72MDNEkZS
      [JBossINF] �[0m�[0m09:03:34,009 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-20) New session created: LzmtOORpjJqz7ZqRhmIg6rro3Top9GlWBixfcS7D
      [JBossINF] �[0m�[0m09:03:34,010 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-1) New session created: FYJS0bQVNA4bxHusRV2gI6stJCQxO0rJ2IuzA7b4
      [JBossINF] �[0m�[0m09:03:34,010 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-9) New session created: Jh5jc4oR_KeSt29lfasKTdszo4dWrr2_A8_nxm3x
      [JBossINF] �[0m�[0m09:03:34,010 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-2) New session created: 5AVElPWyS2H2WvqhfdXuZDOltSvQLyodrR1ckK5S
      [JBossINF] �[0m�[0m09:03:34,010 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-3) New session created: _selI14cpR26Q_zCUFCj5Vq_-B2YkPIsi6BB_kMv
      [JBossINF] �[0m�[0m09:03:34,010 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-7) New session created: DU8zan7woAW5gNRX_JraITeBnnXOTHla2q_5DOpZ
      [JBossINF] �[0m�[0m09:03:34,011 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-8) New session created: uU7mbyQQNWsdhKR091t66AZAQ089IFlYuCqZR0ml
      [JBossINF] �[0m�[0m09:03:34,007 INFO  [org.jboss.test.clusterbench.common.session.CommonHttpSessionServlet] (default task-4) New session created: Tm9d19lL4oFFotC_2PETa1WRKR3kypz3VEhrYF1f
      [JBossINF] �[0m�[0m09:04:35,431 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|6] (3) [perf21, perf20, perf18]
      [JBossINF] �[0m�[0m09:04:35,437 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m09:04:35,438 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|6] (3) [perf21, perf20, perf18]
      [JBossINF] �[0m�[0m09:04:35,438 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m09:04:35,440 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|6] (3) [perf21, perf20, perf18]
      [JBossINF] �[0m�[0m09:04:35,440 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m09:04:35,441 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|6] (3) [perf21, perf20, perf18]
      [JBossINF] �[0m�[0m09:04:35,441 INFO  [org.infinispan.CLUSTER] (thread-28,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m09:05:43,742 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|7] (4) [perf21, perf20, perf18, perf19]
      [JBossINF] �[0m�[0m09:05:43,744 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[0m09:05:43,745 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|7] (4) [perf21, perf20, perf18, perf19]
      [JBossINF] �[0m�[0m09:05:43,745 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[0m09:05:43,748 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|7] (4) [perf21, perf20, perf18, perf19]
      [JBossINF] �[0m�[0m09:05:43,748 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[0m09:05:43,749 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf21|7] (4) [perf21, perf20, perf18, perf19]
      [JBossINF] �[0m�[0m09:05:43,749 INFO  [org.infinispan.CLUSTER] (thread-32,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[31m09:05:53,824 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p11-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionCreationMetaDataKey(Rx1s7LTnrMx33fFVg13vLwN5GLYK049ZIbwqD-Ba), SessionAttributesKey(Rx1s7LTnrMx33fFVg13vLwN5GLYK049ZIbwqD-Ba), SessionAccessMetaDataKey(Rx1s7LTnrMx33fFVg13vLwN5GLYK049ZIbwqD-Ba)]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21248 from perf19
      [JBossINF] 	at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:164)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
      [JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      [JBossINF] 	at java.lang.Thread.run(Thread.java:748)
      [JBossINF] 
      [JBossINF] �[0m�[31m09:05:53,840 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p11-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionCreationMetaDataKey(MXA09ctVC96ZOxYRU38Hg6A7xYgXFsizn31SR-1h), SessionAccessMetaDataKey(MXA09ctVC96ZOxYRU38Hg6A7xYgXFsizn31SR-1h), SessionAttributesKey(MXA09ctVC96ZOxYRU38Hg6A7xYgXFsizn31SR-1h)]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21249 from perf19
      [JBossINF] 	at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:164)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
      [JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      [JBossINF] 	at java.lang.Thread.run(Thread.java:748)
      [JBossINF] 
      [JBossINF] �[0m�[31m09:05:53,843 ERROR [org.infinispan.transaction.impl.TransactionCoordinator] (default task-12) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21249 from perf19
      [JBossINF] 	at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
      [JBossINF] 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
      [JBossINF] 	at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:155)
      [JBossINF] 	at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:122)
      [JBossINF] 	at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:419)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:466)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
      [JBossINF] 	at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
      [JBossINF] 	at org.wildfly.clustering.web.undertow.session.DistributableSession.$closeResource(DistributableSession.java:92)
      [JBossINF] 	at org.wildfly.clustering.web.undertow.session.DistributableSession.requestDone(DistributableSession.java:91)
      [JBossINF] 	at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:945)
      [JBossINF] 	at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:339)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
      [JBossINF] 	at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
      [JBossINF] 	at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
      [JBossINF] 	at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
      [JBossINF] 	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
      [JBossINF] 	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
      [JBossINF] 	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
      [JBossINF] 	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
      [JBossINF] 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
      [JBossINF] 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
      [JBossINF] 	at java.lang.Thread.run(Thread.java:748)
      [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21249 from perf19
      [JBossINF] 	at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:164)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
      [JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      [JBossINF] 	... 1 more
      [JBossINF] 	Suppressed: java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21249 from perf19
      [JBossINF] 		at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
      [JBossINF] 		at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
      [JBossINF] 		at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:82)
      [JBossINF] 		at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:37)
      [JBossINF] 		at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
      [JBossINF] 		at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
      [JBossINF] 		at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:155)
      [JBossINF] 		at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:122)
      [JBossINF] 		at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
      [JBossINF] 		at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:419)
      [JBossINF] 		at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:466)
      [JBossINF] 		at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
      [JBossINF] 		at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
      [JBossINF] 		at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
      [JBossINF] 		at org.wildfly.clustering.web.undertow.session.DistributableSession.$closeResource(DistributableSession.java:92)
      [JBossINF] 		at org.wildfly.clustering.web.undertow.session.DistributableSession.requestDone(DistributableSession.java:91)
      [JBossINF] 		at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:945)
      [JBossINF] 		at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
      [JBossINF] 		at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:339)
      [JBossINF] 		at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
      [JBossINF] 		at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
      [JBossINF] 		at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
      [JBossINF] 		at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
      [JBossINF] 		at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
      [JBossINF] 		at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
      [JBossINF] 		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 		at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1514)
      [JBossINF] 		at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
      [JBossINF] 		at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
      [JBossINF] 		at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
      [JBossINF] 		at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
      [JBossINF] 		at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
      [JBossINF] 		at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
      [JBossINF] 		at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
      [JBossINF] 		at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
      [JBossINF] 		at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
      [JBossINF] 		... 1 more
      [JBossINF] 	[CIRCULAR REFERENCE:org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21249 from perf19]
      [JBossINF] 
      

      For the second run, we used tag 12.0.0.Final and we did not have the CIRCULAR REFERENCE message; anyway we observed a high number (over a hundred for each node) of the following exceptions, note they occur (just like before) right after one node has been stopped and restarted and then another node is stopped and restarted:

      2018/05/02 11:17:02:743 EDT [DEBUG][Thread-82] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - JBossStartup, server started!
      [JBossINF] �[0m�[0m11:18:06,946 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21, perf18]
      [JBossINF] �[0m�[0m11:18:06,956 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m11:18:06,956 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21, perf18]
      [JBossINF] �[0m�[0m11:18:06,957 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m11:18:06,960 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21, perf18]
      [JBossINF] �[0m�[0m11:18:06,961 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m11:18:06,961 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21, perf18]
      [JBossINF] �[0m�[0m11:18:06,962 INFO  [org.infinispan.CLUSTER] (thread-12,ejb,perf18) ISPN100001: Node perf19 left the cluster
      [JBossINF] �[0m�[0m11:19:18,519 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|7] (4) [perf20, perf21, perf18, perf19]
      [JBossINF] �[0m�[0m11:19:18,521 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[0m11:19:18,521 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|7] (4) [perf20, perf21, perf18, perf19]
      [JBossINF] �[0m�[0m11:19:18,522 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[0m11:19:18,523 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|7] (4) [perf20, perf21, perf18, perf19]
      [JBossINF] �[0m�[0m11:19:18,524 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[0m11:19:18,524 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN000094: Received new cluster view for channel ejb: [perf20|7] (4) [perf20, perf21, perf18, perf19]
      [JBossINF] �[0m�[0m11:19:18,524 INFO  [org.infinispan.CLUSTER] (thread-42,ejb,perf18) ISPN100000: Node perf19 joined the cluster
      [JBossINF] �[0m�[31m11:19:28,697 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p10-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionAccessMetaDataKey(6t_HBz794DetKUT7Do1B8P1TZ2W8pynlk6NGYiBI), SessionAttributesKey(6t_HBz794DetKUT7Do1B8P1TZ2W8pynlk6NGYiBI), SessionCreationMetaDataKey(6t_HBz794DetKUT7Do1B8P1TZ2W8pynlk6NGYiBI)]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21976 from perf19
      [JBossINF] 	at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
      [JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      [JBossINF] 	at java.lang.Thread.run(Thread.java:748)
      [JBossINF] 
      [JBossINF] �[0m�[31m11:19:28,702 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p10-t1) ISPN000136: Error executing command PrepareCommand, writing keys [SessionCreationMetaDataKey(Uu_wR07Vr_DkG5twQ0wk7Cqo2RD6radIQk0Uj_s5), SessionAttributesKey(Uu_wR07Vr_DkG5twQ0wk7Cqo2RD6radIQk0Uj_s5), SessionAccessMetaDataKey(Uu_wR07Vr_DkG5twQ0wk7Cqo2RD6radIQk0Uj_s5)]: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21977 from perf19
      [JBossINF] 	at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
      [JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      [JBossINF] 	at java.lang.Thread.run(Thread.java:748)
      [JBossINF] 
      [JBossINF] �[0m�[31m11:19:28,702 ERROR [org.infinispan.transaction.impl.TransactionCoordinator] (default task-14) ISPN000097: Error while processing a prepare in a single-phase transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21976 from perf19
      [JBossINF] 	at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
      [JBossINF] 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
      [JBossINF] 	at org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:166)
      [JBossINF] 	at org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:126)
      [JBossINF] 	at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:446)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:493)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
      [JBossINF] 	at org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
      [JBossINF] 	at org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
      [JBossINF] 	at org.wildfly.clustering.web.undertow.session.DistributableSession.$closeResource(DistributableSession.java:92)
      [JBossINF] 	at org.wildfly.clustering.web.undertow.session.DistributableSession.requestDone(DistributableSession.java:91)
      [JBossINF] 	at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:945)
      [JBossINF] 	at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:577)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:339)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
      [JBossINF] 	at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
      [JBossINF] 	at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
      [JBossINF] 	at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
      [JBossINF] 	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1526)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
      [JBossINF] 	at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
      [JBossINF] 	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
      [JBossINF] 	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
      [JBossINF] 	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
      [JBossINF] 	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
      [JBossINF] 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
      [JBossINF] 	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
      [JBossINF] 	at java.lang.Thread.run(Thread.java:748)
      [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 21976 from perf19
      [JBossINF] 	at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:163)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:86)
      [JBossINF] 	at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:21)
      [JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
      [JBossINF] 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      [JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      [JBossINF] 	... 1 more
      

              pferraro@redhat.com Paul Ferraro
              tborgato@redhat.com Tommaso Borgato
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

                Created:
                Updated:
                Resolved: