[JBoss JIRA] (WFLY-12718) Clustering: replicated-cache sampling errors

Tuesday, 29 October 2019

    [
https://issues.jboss.org/browse/WFLY-12718?page=com.atlassian.jira.plugin...
] 

Radoslav Husar commented on WFLY-12718:
---------------------------------------

The exceptions in the test log are timeouts.

{noformat}
2019-10-28 18:48:01,307 ERROR
[org.infinispan.interceptors.impl.InvocationContextInterceptor] (timeout-thread--p12-t1)
ISPN000136: Error executing command PrepareCommand on Cache
'clusterbench-ee8.ear.clusterbench-ee8-web.war', writing keys
[SessionAccessMetaDataKey(SSpenckNGHL1Y20-8vGPxHRvN-ASy2Xo19q09mJi),
SessionCreationMetaDataKey(SSpenckNGHL1Y20-8vGPxHRvN-ASy2Xo19q09mJi)]:
org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting for
responses for request 228131 from wildfly2
	at
org.infinispan@9.4.16.Final//org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
	at
org.infinispan@9.4.16.Final//org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
	at
org.infinispan@9.4.16.Final//org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at
java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)

2019-10-28 18:48:01,305 ERROR [org.infinispan.transaction.impl.TransactionCoordinator]
(default task-155) ISPN000097: Error while processing a prepare in a single-phase
transaction: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out
waiting for responses for request 228130 from wildfly2
	at
org.infinispan@9.4.16.Final//org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:259)
	at
org.infinispan@9.4.16.Final//org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:156)
	at
org.infinispan@9.4.16.Final//org.infinispan.transaction.impl.TransactionTable.afterCompletion(TransactionTable.java:861)
	at
org.infinispan@9.4.16.Final//org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:33)
	at
org.infinispan.commons@9.4.16.Final//org.infinispan.commons.tx.TransactionImpl.notifyAfterCompletion(TransactionImpl.java:506)
	at
org.infinispan.commons@9.4.16.Final//org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:338)
	at
org.infinispan.commons@9.4.16.Final//org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
	at
org.wildfly.clustering.ee.cache@18.0.0.Final//org.wildfly.clustering.ee.cache.tx.TransactionalBatch.close(TransactionalBatch.java:98)
	at
org.wildfly.clustering.web.undertow@18.0.0.Final//org.wildfly.clustering.web.undertow.session.DistributableSession.requestDone(DistributableSession.java:87)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:950)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:621)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:328)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
	at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
	at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
	at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
	at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
	at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
	at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
	at
io.undertow.core@2.0.26.Final//io.undertow.server.Connectors.executeRootHandler(Connectors.java:376)
	at
io.undertow.core@2.0.26.Final//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
	at
org.jboss.threads@2.3.3.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at
org.jboss.threads@2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
	at
org.jboss.threads@2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at
org.jboss.threads@2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1363)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000476: Timed out waiting
for responses for request 228130 from wildfly2
	at
org.infinispan@9.4.16.Final//org.infinispan.remoting.transport.impl.MultiTargetRequest.onTimeout(MultiTargetRequest.java:167)
	at
org.infinispan@9.4.16.Final//org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:87)
	at
org.infinispan@9.4.16.Final//org.infinispan.remoting.transport.AbstractRequest.call(AbstractRequest.java:22)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at
java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	... 1 more
	Suppressed: org.infinispan.util.logging.TraceException
		at
org.infinispan@9.4.16.Final//org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.get(SimpleAsyncInvocationStage.java:41)
		at
org.infinispan@9.4.16.Final//org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invoke(AsyncInterceptorChainImpl.java:250)
		at
org.infinispan@9.4.16.Final//org.infinispan.transaction.impl.TransactionCoordinator.commit(TransactionCoordinator.java:156)
		at
org.infinispan@9.4.16.Final//org.infinispan.transaction.impl.TransactionTable.afterCompletion(TransactionTable.java:861)
		at
org.infinispan@9.4.16.Final//org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:33)
		at
org.infinispan.commons@9.4.16.Final//org.infinispan.commons.tx.TransactionImpl.notifyAfterCompletion(TransactionImpl.java:506)
		at
org.infinispan.commons@9.4.16.Final//org.infinispan.commons.tx.TransactionImpl.runCommit(TransactionImpl.java:338)
		at
org.infinispan.commons@9.4.16.Final//org.infinispan.commons.tx.TransactionImpl.commit(TransactionImpl.java:110)
		at
org.wildfly.clustering.ee.cache@18.0.0.Final//org.wildfly.clustering.ee.cache.tx.TransactionalBatch.close(TransactionalBatch.java:98)
		at
org.wildfly.clustering.web.undertow@18.0.0.Final//org.wildfly.clustering.web.undertow.session.DistributableSession.requestDone(DistributableSession.java:87)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.spec.ServletContextImpl.updateSessionAccessTime(ServletContextImpl.java:950)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.spec.HttpServletResponseImpl.responseDone(HttpServletResponseImpl.java:621)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:328)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:78)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:133)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:130)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
		at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
		at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
		at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
		at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
		at
org.wildfly.extension.undertow@18.0.0.Final//org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1504)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:249)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:78)
		at
io.undertow.servlet@2.0.26.Final//io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:99)
		at
io.undertow.core@2.0.26.Final//io.undertow.server.Connectors.executeRootHandler(Connectors.java:376)
		at
io.undertow.core@2.0.26.Final//io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:830)
		at
org.jboss.threads@2.3.3.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
		at
org.jboss.threads@2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
		at
org.jboss.threads@2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
		at
org.jboss.threads@2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1363)
		... 1 more
{noformat}

...
 Clustering: replicated-cache sampling errors
 --------------------------------------------

                 Key: WFLY-12718
                 URL: https://issues.jboss.org/browse/WFLY-12718
             Project: WildFly
          Issue Type: Bug
          Components: Clustering
    Affects Versions: 18.0.0.Final
            Reporter: Tommasso Borgato
            Assignee: Paul Ferraro
            Priority: Blocker

 The issue is about replicated-cache in fail-over tests.
 WildFly is started in clustered mode using a replicated cache for replicating HTTP
session data across cluster nodes; all 4 nodes in the cluster are initialized with the
following cli script:
 {noformat}
 embed-server --server-config=standalone-ha.xml
 /subsystem=jgroups/channel=ee:write-attribute(name=stack,value=tcp)
 /subsystem=infinispan/cache-container=web/replicated-cache=testRepl:add()

/subsystem=infinispan/cache-container=web/replicated-cache=testRepl/component=locking:write-attribute(name=isolation,
value=REPEATABLE_READ)

/subsystem=infinispan/cache-container=web/replicated-cache=testRepl/component=transaction:write-attribute(name=mode,
value=BATCH)
 /subsystem=infinispan/cache-container=web/replicated-cache=testRepl/store=file:add()
 /subsystem=infinispan/cache-container=web:write-attribute(name=default-cache,
value=testRepl)
 {noformat}
 The test is run with wildfly-18.0.0.Final.zip;
 The same tests run with version wildfly-17.0.1.Final.zip do not have any problem;
 hence this looks like a regression;
 As usual, we test that the serial value stored in the scattered cache is incremented at
every call: when this is not true, we say we have a sampling error;
 Here are the runs that exhibit this issue: 
 - **22.82% Fail Rate with WildFly-18 **
[eap-7.x-clustering-http-session-shutdown-repl#23|https://eap-qe-jenkins.r...]
 - **0% Fail Rate with WildFly-17 **
[eap-7.x-clustering-http-session-shutdown-repl#24|https://eap-qe-jenkins.r...]
 We also repeated the tests to make sure it can be reproduced:
 - **22.75% Fail rate with WildFly-18 **
[eap-7.x-clustering-http-session-shutdown-repl#26|https://eap-qe-jenkins.r...]

 - **0% Fail Rate with WildFly-17 **
[eap-7.x-clustering-http-session-shutdown-repl#25|https://eap-qe-jenkins.r...]

--
This message was sent by Atlassian Jira
(v7.13.8#713008)

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006