[
https://issues.jboss.org/browse/WFLY-10317?page=com.atlassian.jira.plugin...
]
tommaso borgato updated WFLY-10317:
-----------------------------------
Description:
We used master branch from [
wildfly|https://github.com/wildfly/wildfly.git].
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:
{noformat}
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]
{noformat}
We tried also with tag
[
12.0.0.Final|https://github.com/wildfly/wildfly/tree/12.0.0.Final], we did not have
CIRCULAR REFERENCE, but 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:
{noformat}
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
{noformat}
was:
We used master branch from [
wildfly|https://github.com/wildfly/wildfly.git].
We observe lot of errors (more than a hundred on each node) like the following, note they
occur right after one node has been failed and restarted and then another node is failed:
{noformat}
2018/04/26 03:27:37:448 EDT [DEBUG][Thread-82] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - JBossStartup, server started!
[JBossINF] [0m[0m03:28:39,359 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,366 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[0m03:28:39,366 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,367 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[0m03:28:39,368 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,369 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[0m03:28:39,369 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,370 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[31m03:28:49,087 ERROR
[org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p10-t1)
ISPN000136: Error executing command PrepareCommand, writing keys []:
org.infinispan.util.concurrent.TimeoutException: Timed out waiting for topology 29
[JBossINF] at
org.infinispan.interceptors.impl.BaseStateTransferInterceptor$CancellableRetry.run(BaseStateTransferInterceptor.java:333)
[JBossINF] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[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[31m03:28:49,094 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: Timed out waiting for topology 29
[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.server.registry.CacheRegistry.$closeResource(CacheRegistry.java:105)
[JBossINF] at
org.wildfly.clustering.server.registry.CacheRegistry.getEntry(CacheRegistry.java:178)
[JBossINF] at
org.wildfly.clustering.web.infinispan.session.InfinispanRouteLocator.locate(InfinispanRouteLocator.java:57)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionIdentifierCodec.encode(DistributableSessionIdentifierCodec.java:48)
[JBossINF] at
org.wildfly.extension.undertow.session.CodecSessionConfig.findSessionId(CodecSessionConfig.java:60)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl$ServletContextSessionConfig.findSessionId(ServletContextImpl.java:1215)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:158)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at
io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:412)
[JBossINF] at
org.jboss.weld.module.web.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)
[JBossINF] at
org.jboss.weld.module.web.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:241)
[JBossINF] at
org.jboss.weld.module.web.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)
[JBossINF] at
io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)
[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:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[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: Timed out waiting
for topology 29
[JBossINF] at
org.infinispan.interceptors.impl.BaseStateTransferInterceptor$CancellableRetry.run(BaseStateTransferInterceptor.java:333)
[JBossINF] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[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: Timed out waiting for topology 29
[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.server.registry.CacheRegistry.$closeResource(CacheRegistry.java:105)
[JBossINF] at
org.wildfly.clustering.server.registry.CacheRegistry.getEntry(CacheRegistry.java:178)
[JBossINF] at
org.wildfly.clustering.web.infinispan.session.InfinispanRouteLocator.locate(InfinispanRouteLocator.java:57)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionIdentifierCodec.encode(DistributableSessionIdentifierCodec.java:48)
[JBossINF] at
org.wildfly.extension.undertow.session.CodecSessionConfig.findSessionId(CodecSessionConfig.java:60)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl$ServletContextSessionConfig.findSessionId(ServletContextImpl.java:1215)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:158)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at
io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:412)
[JBossINF] at
org.jboss.weld.module.web.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)
[JBossINF] at
org.jboss.weld.module.web.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:241)
[JBossINF] at
org.jboss.weld.module.web.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)
[JBossINF] at
io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)
[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:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[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: Timed out
waiting for topology 29]
{noformat}
We tried also with tag
[
12.0.0.Final|https://github.com/wildfly/wildfly/tree/12.0.0.Final], we did not have
CIRCULAR REFERENCE, but we observed a high number (over a hundred for each node) of the
following exceptions:
{noformat}
[JBossINF] [0m[33m11:29:05,812 WARN [org.infinispan.commons.tx.TransactionImpl]
(default task-23) ISPN000927: exception while committing:
javax.transaction.xa.XAException
[JBossINF] at
org.infinispan.transaction.impl.TransactionCoordinator.handleCommitFailure(TransactionCoordinator.java:222)
[JBossINF] at
org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:168)
[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 [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 49235 from perf20
[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] ... 32 more
[JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed
out waiting for responses for request 49235 from perf20
[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
moreorg.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 49235 from perf20
[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] ... 32 more
[JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed
out waiting for responses for request 49235 from perf20
[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
{noformat}
TimeoutException caused by CIRCULAR REFERENCE in a 4 node cluster
during fail-over
----------------------------------------------------------------------------------
Key: WFLY-10317
URL:
https://issues.jboss.org/browse/WFLY-10317
Project: WildFly
Issue Type: Bug
Components: Clustering
Affects Versions: 13.0.0.Beta1
Reporter: tommaso borgato
Assignee: Paul Ferraro
Attachments: clusterbench-ee7.ear
We used master branch from [
wildfly|https://github.com/wildfly/wildfly.git].
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:
{noformat}
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]
{noformat}
We tried also with tag
[
12.0.0.Final|https://github.com/wildfly/wildfly/tree/12.0.0.Final], we did not have
CIRCULAR REFERENCE, but 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:
{noformat}
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
{noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)