]
tommaso borgato updated WFLY-10317:
-----------------------------------
Steps to Reproduce:
* Set up a WilfFly cluster composed of 4 nodes running in standalone-ha profile
* Use mod_jk to load balance all the 4 nodes; each node configured with
fail_on_status=404,503
* Deploy clusterbench application on each node (see attached ear file)
* Start making requests to [load
balancer|http://<load_balancer>:8080/clusterbench/session] (2000 clients, 4000 ms
delay between subsequent requests on each client)
* Start failing and then resuming all the 4 nodes in a sequence
was:
* Set up a WilfFly cluster composed of 4 nodes running in standalone-ha profile
* Use mod_jk to load balance all the 4 nodes; each node configured with
fail_on_status=404,503
* Deploy clusterbench application on each node
* Start making requests to [load
balancer|http://<load_balancer>:8080/clusterbench/session] (2000 clients, 4000 ms
delay between subsequent requests on each client)
* Start failing and then resuming all the 4 nodes in a sequence
TimeoutException caused by CIRCULAR REFERENCE in a 4 node cluster
during fail-over
----------------------------------------------------------------------------------
Key: WFLY-10317
URL:
https://issues.jboss.org/browse/WFLY-10317
Project: WildFly
Issue Type: Bug
Components: Clustering
Affects Versions: 13.0.0.Beta1
Reporter: tommaso borgato
Assignee: Paul Ferraro
Attachments: clusterbench-ee7.ear
We observe lot of errors (more than a hundred on each node) like the following, note they
occur right after one node has been failed and restarted and then another node is failed:
{noformat}
2018/04/26 03:27:37:448 EDT [DEBUG][Thread-82] HOST
perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - JBossStartup, server started!
[JBossINF] [0m[0m03:28:39,359 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,366 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[0m03:28:39,366 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,367 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[0m03:28:39,368 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,369 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[0m03:28:39,369 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN000094: Received new cluster view for channel ejb: [perf20|6] (3) [perf20, perf21,
perf18]
[JBossINF] [0m[0m03:28:39,370 INFO [org.infinispan.CLUSTER] (thread-22,ejb,perf18)
ISPN100001: Node perf19 left the cluster
[JBossINF] [0m[31m03:28:49,087 ERROR
[org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p10-t1)
ISPN000136: Error executing command PrepareCommand, writing keys []:
org.infinispan.util.concurrent.TimeoutException: Timed out waiting for topology 29
[JBossINF] at
org.infinispan.interceptors.impl.BaseStateTransferInterceptor$CancellableRetry.run(BaseStateTransferInterceptor.java:333)
[JBossINF] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[JBossINF] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[JBossINF] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[JBossINF] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF]
[JBossINF] [0m[31m03:28:49,094 ERROR
[org.infinispan.transaction.impl.TransactionCoordinator] (default task-12) ISPN000097:
Error while processing a prepare in a single-phase transaction:
org.infinispan.util.concurrent.TimeoutException: Timed out waiting for topology 29
[JBossINF] at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
[JBossINF] at
org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
[JBossINF] at
org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:155)
[JBossINF] at
org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:122)
[JBossINF] at
org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:419)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:466)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
[JBossINF] at
org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
[JBossINF] at
org.wildfly.clustering.server.registry.CacheRegistry.$closeResource(CacheRegistry.java:105)
[JBossINF] at
org.wildfly.clustering.server.registry.CacheRegistry.getEntry(CacheRegistry.java:178)
[JBossINF] at
org.wildfly.clustering.web.infinispan.session.InfinispanRouteLocator.locate(InfinispanRouteLocator.java:57)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionIdentifierCodec.encode(DistributableSessionIdentifierCodec.java:48)
[JBossINF] at
org.wildfly.extension.undertow.session.CodecSessionConfig.findSessionId(CodecSessionConfig.java:60)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl$ServletContextSessionConfig.findSessionId(ServletContextImpl.java:1215)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:158)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at
io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:412)
[JBossINF] at
org.jboss.weld.module.web.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)
[JBossINF] at
org.jboss.weld.module.web.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:241)
[JBossINF] at
org.jboss.weld.module.web.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)
[JBossINF] at
io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
[JBossINF] at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
[JBossINF] at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
[JBossINF] at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
[JBossINF] at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
[JBossINF] at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
[JBossINF] at
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
[JBossINF] at
org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
[JBossINF] at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
[JBossINF] at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
[JBossINF] at java.lang.Thread.run(Thread.java:748)
[JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: Timed out waiting
for topology 29
[JBossINF] at
org.infinispan.interceptors.impl.BaseStateTransferInterceptor$CancellableRetry.run(BaseStateTransferInterceptor.java:333)
[JBossINF] at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[JBossINF] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
[JBossINF] at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
[JBossINF] at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[JBossINF] at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[JBossINF] ... 1 more
[JBossINF] Suppressed: java.util.concurrent.ExecutionException:
org.infinispan.util.concurrent.TimeoutException: Timed out waiting for topology 29
[JBossINF] at
java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:357)
[JBossINF] at java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1915)
[JBossINF] at
org.infinispan.util.concurrent.CompletableFutures.await(CompletableFutures.java:82)
[JBossINF] at
org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:37)
[JBossINF] at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
[JBossINF] at
org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:137)
[JBossINF] at
org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:155)
[JBossINF] at
org.infinispan.transaction.xa.XaTransactionTable.commit(XaTransactionTable.java:122)
[JBossINF] at
org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:68)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.finishResource(TransactionImpl.java:419)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.commitResources(TransactionImpl.java:466)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:335)
[JBossINF] at
org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
[JBossINF] at
org.wildfly.clustering.ee.infinispan.InfinispanBatch.close(InfinispanBatch.java:97)
[JBossINF] at
org.wildfly.clustering.server.registry.CacheRegistry.$closeResource(CacheRegistry.java:105)
[JBossINF] at
org.wildfly.clustering.server.registry.CacheRegistry.getEntry(CacheRegistry.java:178)
[JBossINF] at
org.wildfly.clustering.web.infinispan.session.InfinispanRouteLocator.locate(InfinispanRouteLocator.java:57)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionIdentifierCodec.encode(DistributableSessionIdentifierCodec.java:48)
[JBossINF] at
org.wildfly.extension.undertow.session.CodecSessionConfig.findSessionId(CodecSessionConfig.java:60)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl$ServletContextSessionConfig.findSessionId(ServletContextImpl.java:1215)
[JBossINF] at
org.wildfly.clustering.web.undertow.session.DistributableSessionManager.getSession(DistributableSessionManager.java:158)
[JBossINF] at
io.undertow.servlet.spec.ServletContextImpl.getSession(ServletContextImpl.java:858)
[JBossINF] at
io.undertow.servlet.spec.HttpServletRequestImpl.getSession(HttpServletRequestImpl.java:412)
[JBossINF] at
org.jboss.weld.module.web.servlet.SessionHolder.requestInitialized(SessionHolder.java:47)
[JBossINF] at
org.jboss.weld.module.web.servlet.HttpContextLifecycle.requestInitialized(HttpContextLifecycle.java:241)
[JBossINF] at
org.jboss.weld.module.web.servlet.WeldInitialListener.requestInitialized(WeldInitialListener.java:152)
[JBossINF] at
io.undertow.servlet.core.ApplicationListeners.requestInitialized(ApplicationListeners.java:246)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:291)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:81)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:138)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:135)
[JBossINF] at
io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
[JBossINF] at
io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
[JBossINF] at
org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1521)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:272)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:81)
[JBossINF] at
io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:104)
[JBossINF] at io.undertow.server.Connectors.executeRootHandler(Connectors.java:360)
[JBossINF] at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
[JBossINF] at
org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
[JBossINF] at
org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
[JBossINF] at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
[JBossINF] at
org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
[JBossINF] ... 1 more
[JBossINF] [CIRCULAR REFERENCE:org.infinispan.util.concurrent.TimeoutException: Timed
out waiting for topology 29]
{noformat}