[jboss-jira] [JBoss JIRA] (WFLY-10736) Server in cluster hangs during start after previous kill
tommaso borgato (JIRA)
issues at jboss.org
Thu Aug 23 04:51:01 EDT 2018
[ https://issues.jboss.org/browse/WFLY-10736?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13623026#comment-13623026 ]
tommaso borgato edited comment on WFLY-10736 at 8/23/18 4:50 AM:
-----------------------------------------------------------------
[~pferraro] With both distributions the server often fails to shutdown within 60 seconds and the jvm is killed: "Server shutdown timed out. Terminating forcefully".
In both cases we observe the WARN log message: "ISPN000197: Error updating cluster member list".
In the test performed on wildfly:master build 22 Aug 2018, we always observe the WARN log message "ISPN000071: Caught exception when handling command LockControlCommand{...}" as the last log from the server before being forcefully terminated.
h2. eap-7.2.0.CD14-20180815
h3. [perf18|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf18/]
{noformat}
[JBossINF] [0m[0m16:13:04,626 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-3) ISPN000080: Disconnecting JGroups channel ejb
[JBossINF] [0m[0m16:13:04,660 INFO [org.jboss.as] (MSC service thread 1-7) WFLYSRV0050: JBoss EAP CD 7.2.0.CD14 (WildFly Core 6.0.0.Final-redhat-20180815) stopped in 10153ms
[JBossINF] [0m[0m16:28:20,518 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-4) ISPN000080: Disconnecting JGroups channel ejb
2018/08/21 16:30:10:437 EDT [DEBUG][RMI TCP Connection(61)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h3. [perf19|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf19/]
{noformat}
[JBossINF] [0m[0m16:15:20,382 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-8) ISPN000080: Disconnecting JGroups channel ejb
...
2018/08/21 16:17:20:263 EDT [DEBUG][RMI TCP Connection(44)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
[JBossINF] [0m[0m16:30:23,976 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-5) ISPN000080: Disconnecting JGroups channel ejb
2018/08/21 16:32:13:927 EDT [DEBUG][RMI TCP Connection(53)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h3. [perf20|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf20/]
{noformat}
[JBossINF] [0m[0m16:19:34,766 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-6) ISPN000080: Disconnecting JGroups channel ejb
...
2018/08/21 16:21:34:692 EDT [DEBUG][RMI TCP Connection(31)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
[JBossINF] [0m[0m16:35:37,668 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-5) ISPN000080: Disconnecting JGroups channel ejb
2018/08/21 16:37:27:615 EDT [DEBUG][RMI TCP Connection(42)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h3. [perf21|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf21/]
{noformat}
[JBossINF] [0m[0m16:23:49,076 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-8) ISPN000080: Disconnecting JGroups channel ejb
...
2018/08/21 16:25:49:018 EDT [DEBUG][RMI TCP Connection(22)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h2. wildfly:master (22 Aug 2018)
h3. [perf18|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf18/]
OK
h3. [perf19|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf19/]
{noformat}
[JBossINF] [0m[33m11:42:26,122 WARN [org.infinispan.remoting.inboundhandler.NonTotalOrderTxPerCacheInboundInvocationHandler] (remote-thread--p7-t4) ISPN000071: Caught exception when handling command LockControlCommand{cache=clusterbench-ee7.ear.clusterbench-ee7-web-default.war, keys=[SessionCreationMetaDataKey(FQgZzMUpaFIWVPc7RKrrbuacvIyOjApj1EWlKKqc)], flags=[FORCE_WRITE_LOCK], unlock=false, gtx=GlobalTx:perf18:37}: org.infinispan.commons.CacheException: ISPN000482: Cannot create remote transaction GlobalTx:perf18:37, already completed
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.lambda$getOrCreateRemoteTransaction$1(TransactionTable.java:388)
[JBossINF] at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:381)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:361)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.createContext(LockControlCommand.java:139)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:122)
[JBossINF] at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:94)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF]
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf20:336 timed out. Rolling back after 74863 ms
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf20:334 timed out. Rolling back after 76777 ms
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:331 timed out. Rolling back after 74864 ms
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf18:31 timed out. Rolling back after 74787 ms
2018/08/22 11:43:17:160 EDT [DEBUG][RMI TCP Connection(44)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
meanwhile on perf18 we observe:
{noformat}
[JBossINF] [0m[31m11:42:26,135 ERROR [io.undertow.request] (default task-2) UT005071: Undertow request failed HttpServerExchange{ GET /clusterbench/session request {Cookie=[$Version=0; JSESSIONID=FQgZzMUpaFIWVPc7RKrrbuacvIyOjApj1EWlKKqc.perf19; $Path=/clusterbench], Content-Length=[0], User-Agent=[Jakarta Commons-HttpClient/3.1], Host=[perf17:8080]} response {Content-Type=[text/html;charset=UTF-8], Content-Length=[80], Date=[Wed, 22 Aug 2018 15:42:06 GMT]}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 56 from perf19
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[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 56 from perf19
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
[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: org.infinispan.util.logging.TraceException
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[JBossINF] ... 1 more
{noformat}
h3. [perf20|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf20/]
{noformat}
[JBossINF] [0m[33m11:46:40,348 WARN [org.infinispan.remoting.inboundhandler.NonTotalOrderTxPerCacheInboundInvocationHandler] (remote-thread--p5-t11) ISPN000071: Caught exception when handling command LockControlCommand{cache=clusterbench-ee7.ear.clusterbench-ee7-web-default.war, keys=[SessionCreationMetaDataKey(jKed4QLgTwwLw_q5p34roD_P-Bygv8umfynvDuHB)], flags=[FORCE_WRITE_LOCK], unlock=false, gtx=GlobalTx:perf19:53}: org.infinispan.commons.CacheException: ISPN000482: Cannot create remote transaction GlobalTx:perf19:53, already completed
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.lambda$getOrCreateRemoteTransaction$1(TransactionTable.java:388)
[JBossINF] at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:381)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:361)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.createContext(LockControlCommand.java:139)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:122)
[JBossINF] at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:94)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF]
[JBossINF] [0m[33m11:46:56,082 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:952 timed out. Rolling back after 83324 ms
[JBossINF] [0m[33m11:46:56,082 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:954 timed out. Rolling back after 81452 ms
[JBossINF] [0m[33m11:46:56,082 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:950 timed out. Rolling back after 83328 ms
[JBossINF] [0m[33m11:46:56,083 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf19:46 timed out. Rolling back after 81377 ms
[JBossINF] [0m[33m11:46:56,083 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf18:42 timed out. Rolling back after 83337 ms
2018/08/22 11:47:31:216 EDT [DEBUG][RMI TCP Connection(31)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
meanwhile on perf19:
{noformat}
[JBossINF] [0m[31m11:46:40,357 ERROR [io.undertow.request] (default task-2) UT005071: Undertow request failed HttpServerExchange{ GET /clusterbench/session request {Cookie=[$Version=0; JSESSIONID=jKed4QLgTwwLw_q5p34roD_P-Bygv8umfynvDuHB.perf20; $Path=/clusterbench], Content-Length=[0], User-Agent=[Jakarta Commons-HttpClient/3.1], Host=[perf17:8080]} response {Content-Type=[text/html;charset=UTF-8], Content-Length=[80], Date=[Wed, 22 Aug 2018 15:46:20 GMT]}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 57 from perf20
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[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 57 from perf20
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
[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: org.infinispan.util.logging.TraceException
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[JBossINF] ... 1 more
{noformat}
h3. [perf21|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf21/]
{noformat}
[JBossINF] [0m[33m11:50:54,509 WARN [org.infinispan.remoting.inboundhandler.NonTotalOrderTxPerCacheInboundInvocationHandler] (remote-thread--p6-t20) ISPN000071: Caught exception when handling command LockControlCommand{cache=clusterbench-ee7.ear.clusterbench-ee7-web-default.war, keys=[SessionCreationMetaDataKey(VKJbgfNUhPq0zSCYr-QmL_TNDcqv85k1Y20kOSqf)], flags=[FORCE_WRITE_LOCK], unlock=false, gtx=GlobalTx:perf19:139}: org.infinispan.commons.CacheException: ISPN000482: Cannot create remote transaction GlobalTx:perf19:139, already completed
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.lambda$getOrCreateRemoteTransaction$1(TransactionTable.java:388)
[JBossINF] at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:381)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:361)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.createContext(LockControlCommand.java:139)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:122)
[JBossINF] at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:94)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF]
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:47 timed out. Rolling back after 72674 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:46 timed out. Rolling back after 72676 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:49 timed out. Rolling back after 72677 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:48 timed out. Rolling back after 72675 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf19:81 timed out. Rolling back after 70864 ms
2018/08/22 11:51:45:682 EDT [DEBUG][RMI TCP Connection(24)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
meanwhile on perf19:
{noformat}
[JBossINF] [0m[31m11:50:54,512 ERROR [io.undertow.request] (default task-3) UT005071: Undertow request failed HttpServerExchange{ GET /clusterbench/session request {Cookie=[$Version=0; JSESSIONID=VKJbgfNUhPq0zSCYr-QmL_TNDcqv85k1Y20kOSqf.perf21; $Path=/clusterbench], Content-Length=[0], User-Agent=[Jakarta Commons-HttpClient/3.1], Host=[perf17:8080]} response {Content-Type=[text/html;charset=UTF-8], Content-Length=[80], Date=[Wed, 22 Aug 2018 15:50:34 GMT]}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 135 from perf21
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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 135 from perf21
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
[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: org.infinispan.util.logging.TraceException
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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
{noformat}
was (Author: tommaso-borgato):
With both distributions the server often fails to shutdown within 60 seconds and the jvm is killed: "Server shutdown timed out. Terminating forcefully".
In both cases we observe the WARN log message: "ISPN000197: Error updating cluster member list".
In the test performed on wildfly:master build 22 Aug 2018, we always observe the WARN log message "ISPN000071: Caught exception when handling command LockControlCommand{...}" as the last log from the server before being forcefully terminated.
h2. eap-7.2.0.CD14-20180815
h3. [perf18|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf18/]
{noformat}
[JBossINF] [0m[0m16:13:04,626 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-3) ISPN000080: Disconnecting JGroups channel ejb
[JBossINF] [0m[0m16:13:04,660 INFO [org.jboss.as] (MSC service thread 1-7) WFLYSRV0050: JBoss EAP CD 7.2.0.CD14 (WildFly Core 6.0.0.Final-redhat-20180815) stopped in 10153ms
[JBossINF] [0m[0m16:28:20,518 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-4) ISPN000080: Disconnecting JGroups channel ejb
2018/08/21 16:30:10:437 EDT [DEBUG][RMI TCP Connection(61)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h3. [perf19|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf19/]
{noformat}
[JBossINF] [0m[0m16:15:20,382 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-8) ISPN000080: Disconnecting JGroups channel ejb
...
2018/08/21 16:17:20:263 EDT [DEBUG][RMI TCP Connection(44)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
[JBossINF] [0m[0m16:30:23,976 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-5) ISPN000080: Disconnecting JGroups channel ejb
2018/08/21 16:32:13:927 EDT [DEBUG][RMI TCP Connection(53)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h3. [perf20|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf20/]
{noformat}
[JBossINF] [0m[0m16:19:34,766 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-6) ISPN000080: Disconnecting JGroups channel ejb
...
2018/08/21 16:21:34:692 EDT [DEBUG][RMI TCP Connection(31)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
[JBossINF] [0m[0m16:35:37,668 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-5) ISPN000080: Disconnecting JGroups channel ejb
2018/08/21 16:37:27:615 EDT [DEBUG][RMI TCP Connection(42)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h3. [perf21|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/31/console-perf21/]
{noformat}
[JBossINF] [0m[0m16:23:49,076 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (MSC service thread 1-8) ISPN000080: Disconnecting JGroups channel ejb
...
2018/08/21 16:25:49:018 EDT [DEBUG][RMI TCP Connection(22)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
h2. wildfly:master (22 Aug 2018)
h3. [perf18|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf18/]
OK
h3. [perf19|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf19/]
{noformat}
[JBossINF] [0m[33m11:42:26,122 WARN [org.infinispan.remoting.inboundhandler.NonTotalOrderTxPerCacheInboundInvocationHandler] (remote-thread--p7-t4) ISPN000071: Caught exception when handling command LockControlCommand{cache=clusterbench-ee7.ear.clusterbench-ee7-web-default.war, keys=[SessionCreationMetaDataKey(FQgZzMUpaFIWVPc7RKrrbuacvIyOjApj1EWlKKqc)], flags=[FORCE_WRITE_LOCK], unlock=false, gtx=GlobalTx:perf18:37}: org.infinispan.commons.CacheException: ISPN000482: Cannot create remote transaction GlobalTx:perf18:37, already completed
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.lambda$getOrCreateRemoteTransaction$1(TransactionTable.java:388)
[JBossINF] at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:381)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:361)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.createContext(LockControlCommand.java:139)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:122)
[JBossINF] at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:94)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF]
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf20:336 timed out. Rolling back after 74863 ms
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf20:334 timed out. Rolling back after 76777 ms
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:331 timed out. Rolling back after 74864 ms
[JBossINF] [0m[33m11:42:35,287 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf18:31 timed out. Rolling back after 74787 ms
2018/08/22 11:43:17:160 EDT [DEBUG][RMI TCP Connection(44)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
meanwhile on perf18 we observe:
{noformat}
[JBossINF] [0m[31m11:42:26,135 ERROR [io.undertow.request] (default task-2) UT005071: Undertow request failed HttpServerExchange{ GET /clusterbench/session request {Cookie=[$Version=0; JSESSIONID=FQgZzMUpaFIWVPc7RKrrbuacvIyOjApj1EWlKKqc.perf19; $Path=/clusterbench], Content-Length=[0], User-Agent=[Jakarta Commons-HttpClient/3.1], Host=[perf17:8080]} response {Content-Type=[text/html;charset=UTF-8], Content-Length=[80], Date=[Wed, 22 Aug 2018 15:42:06 GMT]}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 56 from perf19
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[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 56 from perf19
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
[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: org.infinispan.util.logging.TraceException
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[JBossINF] ... 1 more
{noformat}
h3. [perf20|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf20/]
{noformat}
[JBossINF] [0m[33m11:46:40,348 WARN [org.infinispan.remoting.inboundhandler.NonTotalOrderTxPerCacheInboundInvocationHandler] (remote-thread--p5-t11) ISPN000071: Caught exception when handling command LockControlCommand{cache=clusterbench-ee7.ear.clusterbench-ee7-web-default.war, keys=[SessionCreationMetaDataKey(jKed4QLgTwwLw_q5p34roD_P-Bygv8umfynvDuHB)], flags=[FORCE_WRITE_LOCK], unlock=false, gtx=GlobalTx:perf19:53}: org.infinispan.commons.CacheException: ISPN000482: Cannot create remote transaction GlobalTx:perf19:53, already completed
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.lambda$getOrCreateRemoteTransaction$1(TransactionTable.java:388)
[JBossINF] at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:381)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:361)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.createContext(LockControlCommand.java:139)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:122)
[JBossINF] at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:94)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF]
[JBossINF] [0m[33m11:46:56,082 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:952 timed out. Rolling back after 83324 ms
[JBossINF] [0m[33m11:46:56,082 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:954 timed out. Rolling back after 81452 ms
[JBossINF] [0m[33m11:46:56,082 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf21:950 timed out. Rolling back after 83328 ms
[JBossINF] [0m[33m11:46:56,083 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf19:46 timed out. Rolling back after 81377 ms
[JBossINF] [0m[33m11:46:56,083 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p9-t1) ISPN000326: Remote transaction GlobalTx:perf18:42 timed out. Rolling back after 83337 ms
2018/08/22 11:47:31:216 EDT [DEBUG][RMI TCP Connection(31)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
meanwhile on perf19:
{noformat}
[JBossINF] [0m[31m11:46:40,357 ERROR [io.undertow.request] (default task-2) UT005071: Undertow request failed HttpServerExchange{ GET /clusterbench/session request {Cookie=[$Version=0; JSESSIONID=jKed4QLgTwwLw_q5p34roD_P-Bygv8umfynvDuHB.perf20; $Path=/clusterbench], Content-Length=[0], User-Agent=[Jakarta Commons-HttpClient/3.1], Host=[perf17:8080]} response {Content-Type=[text/html;charset=UTF-8], Content-Length=[80], Date=[Wed, 22 Aug 2018 15:46:20 GMT]}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 57 from perf20
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[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 57 from perf20
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
[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: org.infinispan.util.logging.TraceException
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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:1349)
[JBossINF] ... 1 more
{noformat}
h3. [perf21|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-http-session-shutdown-dist-sync-auth-asymEncrypt/32/console-perf21/]
{noformat}
[JBossINF] [0m[33m11:50:54,509 WARN [org.infinispan.remoting.inboundhandler.NonTotalOrderTxPerCacheInboundInvocationHandler] (remote-thread--p6-t20) ISPN000071: Caught exception when handling command LockControlCommand{cache=clusterbench-ee7.ear.clusterbench-ee7-web-default.war, keys=[SessionCreationMetaDataKey(VKJbgfNUhPq0zSCYr-QmL_TNDcqv85k1Y20kOSqf)], flags=[FORCE_WRITE_LOCK], unlock=false, gtx=GlobalTx:perf19:139}: org.infinispan.commons.CacheException: ISPN000482: Cannot create remote transaction GlobalTx:perf19:139, already completed
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.lambda$getOrCreateRemoteTransaction$1(TransactionTable.java:388)
[JBossINF] at java.util.concurrent.ConcurrentHashMap.compute(ConcurrentHashMap.java:1853)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:381)
[JBossINF] at org.infinispan.transaction.impl.TransactionTable.getOrCreateRemoteTransaction(TransactionTable.java:361)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.createContext(LockControlCommand.java:139)
[JBossINF] at org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:122)
[JBossINF] at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:94)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:99)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:71)
[JBossINF] at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:40)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF]
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:47 timed out. Rolling back after 72674 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:46 timed out. Rolling back after 72676 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:49 timed out. Rolling back after 72677 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf20:48 timed out. Rolling back after 72675 ms
[JBossINF] [0m[33m11:50:59,714 WARN [org.infinispan.transaction.impl.TransactionTable] (timeout-thread--p10-t1) ISPN000326: Remote transaction GlobalTx:perf19:81 timed out. Rolling back after 70864 ms
2018/08/22 11:51:45:682 EDT [DEBUG][RMI TCP Connection(24)-10.16.90.52] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Server shutdown timed out. Terminating forcefully.
{noformat}
meanwhile on perf19:
{noformat}
[JBossINF] [0m[31m11:50:54,512 ERROR [io.undertow.request] (default task-3) UT005071: Undertow request failed HttpServerExchange{ GET /clusterbench/session request {Cookie=[$Version=0; JSESSIONID=VKJbgfNUhPq0zSCYr-QmL_TNDcqv85k1Y20kOSqf.perf21; $Path=/clusterbench], Content-Length=[0], User-Agent=[Jakarta Commons-HttpClient/3.1], Host=[perf17:8080]} response {Content-Type=[text/html;charset=UTF-8], Content-Length=[80], Date=[Wed, 22 Aug 2018 15:50:34 GMT]}}: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 135 from perf21
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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 135 from perf21
[JBossINF] at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
[JBossINF] at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
[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: org.infinispan.util.logging.TraceException
[JBossINF] at org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
[JBossINF] at org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
[JBossINF] at org.infinispan.cache.impl.CacheImpl.get(CacheImpl.java:479)
[JBossINF] at org.infinispan.cache.impl.DecoratedCache.get(DecoratedCache.java:529)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.infinispan.cache.impl.EncoderCache.get(EncoderCache.java:659)
[JBossINF] at org.infinispan.cache.impl.AbstractDelegatingCache.get(AbstractDelegatingCache.java:348)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.getValue(InfinispanSessionMetaDataFactory.java:78)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:68)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionMetaDataFactory.findValue(InfinispanSessionMetaDataFactory.java:39)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:59)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionFactory.findValue(InfinispanSessionFactory.java:37)
[JBossINF] at org.wildfly.clustering.web.infinispan.session.InfinispanSessionManager.findSession(InfinispanSessionManager.java:208)
[JBossINF] at org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:211)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:933)
[JBossINF] at io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:937)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:579)
[JBossINF] at io.undertow.servlet.spec.HttpServletResponseImpl.doErrorDispatch(HttpServletResponseImpl.java:178)
[JBossINF] at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:334)
[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:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[JBossINF] at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1502)
[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
{noformat}
> Server in cluster hangs during start after previous kill
> --------------------------------------------------------
>
> Key: WFLY-10736
> URL: https://issues.jboss.org/browse/WFLY-10736
> Project: WildFly
> Issue Type: Bug
> Components: Clustering
> Reporter: Miroslav Novak
> Assignee: Paul Ferraro
> Priority: Blocker
> Labels: blocker-WF14
> Attachments: Lodh2TestCase.testRemoteJcaInboundOnly-traces.zip, Lodh2TestCase.testRemoteJcaInboundOnly.zip, clusterKilTest.zip, logs-with-workaround.zip, node-1-thread-dump-before-kill-shutdown-sequence.txt, server-with-mdb.log, standalone-full-ha-1.xml, standalone-full-ha-2.xml
>
>
> There is regression in JGroups or Infinispan in one of our tests for fault tolerance of JMS bridges. However work on JMS bridge appears to be unrelated. Issue was hit in WF weekly run.
> Test Scenario:
> * There are two servers. InQueue is deployed on Node 1,
> * OutQueue is deployed on Node 2. Both servers are started.
> * Large byte messages are sent to InQueue deployed on Node 1. Bridge between servers/queues transfers messages from node 1 to node 2.
> * Node 1 is killed and started again.
> * All messages are received from OutQueue deployed on Node 2.
> Result:
> Node 1 does not start after kill and hangs. There is following exception logged in node 2:
> {code}
> :26:17,894 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100000: Node node-1 joined the cluster
> 09:26:18,520 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,521 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,521 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,522 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN000094: Received new cluster view for channel ejb: [node-2|7] (2) [node-2, node-1]
> 09:26:18,523 INFO [org.infinispan.CLUSTER] (thread-12,ejb,node-2) ISPN100001: Node node-1 left the cluster
> 09:26:18,868 INFO [org.infinispan.CLUSTER] (remote-thread--p5-t2) ISPN000310: Starting cluster-wide rebalance for cache default, topology CacheTopology{id=17, phase=READ_OLD_WRITE_ALL, rebalanceId=6, currentCH=ReplicatedConsistentHash{ns = 256, owners = (2)[node-2: 122, node-1: 134]}, pendingCH=ReplicatedConsistentHash{ns = 256, owners = (3)[node-2: 84, node-1: 90, node-1: 82]}, unionCH=null, actualMembers=[node-2, node-1, node-1], persistentUUIDs=[12443bfb-e88a-46f3-919e-9213bf38ce19, 2873237f-d881-463f-8a5a-940bf1d764e5, a05ea8af-a83b-42a9-b937-dc2da1cae6d1]}
> 09:26:18,869 INFO [org.infinispan.CLUSTER] (remote-thread--p5-t2) [Context=default][Scope=node-2]ISPN100002: Started rebalance with topology id 17
> 09:26:18,870 INFO [org.infinispan.CLUSTER] (transport-thread--p14-t5) [Context=default][Scope=node-2]ISPN100003: Node node-2 finished rebalance phase with topology id 17
> 09:26:18,981 INFO [org.infinispan.CLUSTER] (remote-thread--p5-t2) [Context=default][Scope=node-1]ISPN100003: Node node-1 finished rebalance phase with topology id 17
> 09:27:18,530 WARN [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread--p15-t4) ISPN000197: Error updating cluster member list: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]
> Suppressed: java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357) [rt.jar:1.8.0_131]
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) [rt.jar:1.8.0_131]
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:82)
> at org.infinispan.remoting.transport.Transport.invokeRemotely(Transport.java:71)
> at org.infinispan.topology.ClusterTopologyManagerImpl.confirmMembersAvailable(ClusterTopologyManagerImpl.java:540)
> at org.infinispan.topology.ClusterTopologyManagerImpl.updateCacheMembers(ClusterTopologyManagerImpl.java:523)
> at org.infinispan.topology.ClusterTopologyManagerImpl.handleClusterView(ClusterTopologyManagerImpl.java:334)
> at org.infinispan.topology.ClusterTopologyManagerImpl.access$500(ClusterTopologyManagerImpl.java:85)
> at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.lambda$handleViewChange$0(ClusterTopologyManagerImpl.java:745)
> at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144)
> at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33)
> at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
> ... 1 more
> Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> ... 1 more
> [CIRCULAR REFERENCE:java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1]
> 09:27:18,530 WARN [org.infinispan.topology.ClusterTopologyManagerImpl] (transport-thread--p16-t4) ISPN000197: Error updating cluster member list: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_131]
> Suppressed: java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357) [rt.jar:1.8.0_131]
> at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915) [rt.jar:1.8.0_131]
> at org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:82)
> at org.infinispan.remoting.transport.Transport.invokeRemotely(Transport.java:71)
> at org.infinispan.topology.ClusterTopologyManagerImpl.confirmMembersAvailable(ClusterTopologyManagerImpl.java:540)
> at org.infinispan.topology.ClusterTopologyManagerImpl.updateCacheMembers(ClusterTopologyManagerImpl.java:523)
> at org.infinispan.topology.ClusterTopologyManagerImpl.handleClusterView(ClusterTopologyManagerImpl.java:334)
> at org.infinispan.topology.ClusterTopologyManagerImpl.access$500(ClusterTopologyManagerImpl.java:85)
> at org.infinispan.topology.ClusterTopologyManagerImpl$ClusterViewListener.lambda$handleViewChange$0(ClusterTopologyManagerImpl.java:745)
> at org.infinispan.executors.LimitedExecutor.runTasks(LimitedExecutor.java:144)
> at org.infinispan.executors.LimitedExecutor.access$100(LimitedExecutor.java:33)
> at org.infinispan.executors.LimitedExecutor$Runner.run(LimitedExecutor.java:174)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> at org.wildfly.clustering.service.concurrent.ClassLoaderThreadFactory.lambda$newThread$0(ClassLoaderThreadFactory.java:47)
> ... 1 more
> Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1
> at org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
> at org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [rt.jar:1.8.0_131]
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [rt.jar:1.8.0_131]
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [rt.jar:1.8.0_131]
> ... 1 more
> [CIRCULAR REFERENCE:java.util.concurrent.ExecutionException: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for responses for request 4 from node-1]
> {code}
> There is default JGroups udp stack configured which is used by Infinispan. Both of the servers (jgroups udp) are bound to 127.0.0.1. Node 2 has port offset 1000.
> Attaching thread dump from node 1 when it hangs during start.
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)
More information about the jboss-jira
mailing list