[
https://issues.jboss.org/browse/WFLY-10756?page=com.atlassian.jira.plugin...
]
tommaso borgato updated WFLY-10756:
-----------------------------------
Description:
The error was observed in scenario
{{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/4/]*}}:
a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the
node jvm.
The error was observed on node
{{*[perf19|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/4/console-perf19/]*}}
right after it was re-started (the server jvm was previously killed to introduce
fail-over):
{noformat}
[JBossINF] [0m[0m02:43:51,746 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025:
WildFly Full 14.0.0.Beta2-SNAPSHOT (WildFly Core 6.0.0.Alpha4) started in 12738ms -
Started 973 of 1160 services (477 services are lazy, passive or on-demand)
[JBossINF] [0m[0m02:44:37,268 INFO [org.jboss.ejb.client] (default task-1) JBoss EJB
Client version 4.0.11.Final
[JBossINF] [0m[0m02:44:56,928 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,942 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,948 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,949 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,949 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,950 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,955 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,978 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:45:58,220 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,221 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,223 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,223 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,224 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,225 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,225 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,226 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:47:11,387 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,389 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,390 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,390 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,392 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,393 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,393 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,394 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[31m02:47:12,082 ERROR
[org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t60)
ISPN000136: Error executing command LockControlCommand, writing keys []:
org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after
0 milliseconds for key
SessionCreationMetaDataKey(2UakcseFRb1cI_zcOL5fwpJnkR8j-fo74TsVeNSo) and requestor
GlobalTx:perf20:25537. Lock is held by GlobalTx:perf19:118742
[JBossINF] at
org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:288)
[JBossINF] at
org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:261)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.localLockCommandWork(PessimisticLockingInterceptor.java:209)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.lambda$new$0(PessimisticLockingInterceptor.java:46)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:81)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:192)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:183)
[JBossINF] at
org.infinispan.interceptors.impl.TxInterceptor.visitLockControlCommand(TxInterceptor.java:222)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.lambda$new$0(BaseAsyncInterceptor.java:22)
[JBossINF] at
org.infinispan.interceptors.InvocationSuccessFunction.apply(InvocationSuccessFunction.java:25)
[JBossINF] at
org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at
org.infinispan.interceptors.InvocationStage.thenApply(InvocationStage.java:45)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.asyncInvokeNext(BaseAsyncInterceptor.java:224)
[JBossINF] at
org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:46)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at
org.infinispan.statetransfer.StateTransferInterceptor.visitLockControlCommand(StateTransferInterceptor.java:90)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
[JBossINF] at
org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:56)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
[JBossINF] at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:126)
[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)
{noformat}
was:
The error was observed in scenario
{{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/4/]*}}:
a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the
node jvm.
The error was observed on node
{{*[perf19|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/4/console-perf19/]*}}
right after it was re-started after being killed:
{noformat}
[JBossINF] [0m[0m02:43:51,746 INFO [org.jboss.as] (Controller Boot Thread) WFLYSRV0025:
WildFly Full 14.0.0.Beta2-SNAPSHOT (WildFly Core 6.0.0.Alpha4) started in 12738ms -
Started 973 of 1160 services (477 services are lazy, passive or on-demand)
[JBossINF] [0m[0m02:44:37,268 INFO [org.jboss.ejb.client] (default task-1) JBoss EJB
Client version 4.0.11.Final
[JBossINF] [0m[0m02:44:56,928 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,942 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,948 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,949 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,949 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,950 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,955 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,978 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:45:58,220 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,221 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,223 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,223 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,224 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,225 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,225 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,226 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:47:11,387 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,389 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,390 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,390 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,392 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,393 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,393 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,394 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[31m02:47:12,082 ERROR
[org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t60)
ISPN000136: Error executing command LockControlCommand, writing keys []:
org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after
0 milliseconds for key
SessionCreationMetaDataKey(2UakcseFRb1cI_zcOL5fwpJnkR8j-fo74TsVeNSo) and requestor
GlobalTx:perf20:25537. Lock is held by GlobalTx:perf19:118742
[JBossINF] at
org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:288)
[JBossINF] at
org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:261)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.localLockCommandWork(PessimisticLockingInterceptor.java:209)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.lambda$new$0(PessimisticLockingInterceptor.java:46)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:81)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:192)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:183)
[JBossINF] at
org.infinispan.interceptors.impl.TxInterceptor.visitLockControlCommand(TxInterceptor.java:222)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.lambda$new$0(BaseAsyncInterceptor.java:22)
[JBossINF] at
org.infinispan.interceptors.InvocationSuccessFunction.apply(InvocationSuccessFunction.java:25)
[JBossINF] at
org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at
org.infinispan.interceptors.InvocationStage.thenApply(InvocationStage.java:45)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.asyncInvokeNext(BaseAsyncInterceptor.java:224)
[JBossINF] at
org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:46)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at
org.infinispan.statetransfer.StateTransferInterceptor.visitLockControlCommand(StateTransferInterceptor.java:90)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
[JBossINF] at
org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:56)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
[JBossINF] at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:126)
[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)
{noformat}
ISPN000136: Error executing command LockControlCommand
-------------------------------------------------------
Key: WFLY-10756
URL:
https://issues.jboss.org/browse/WFLY-10756
Project: WildFly
Issue Type: Bug
Components: Clustering
Affects Versions: 14.0.0.CR1
Reporter: tommaso borgato
Assignee: Paul Ferraro
The error was observed in scenario
{{*[eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/4/]*}}:
a 4 nodes cluster with a mod_jk load balancer where fail-over is introduced by killing the
node jvm.
The error was observed on node
{{*[perf19|https://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/view/EAP7/view/EAP7-Clustering_JJB/view/clustering-ejb-ejbservlet-tests/job/eap-7x-failover-ejb-ejbservlet-jvmkill-dist-sync_JJB/4/console-perf19/]*}}
right after it was re-started (the server jvm was previously killed to introduce
fail-over):
{noformat}
[JBossINF] [0m[0m02:43:51,746 INFO [org.jboss.as] (Controller Boot Thread)
WFLYSRV0025: WildFly Full 14.0.0.Beta2-SNAPSHOT (WildFly Core 6.0.0.Alpha4) started in
12738ms - Started 973 of 1160 services (477 services are lazy, passive or on-demand)
[JBossINF] [0m[0m02:44:37,268 INFO [org.jboss.ejb.client] (default task-1) JBoss EJB
Client version 4.0.11.Final
[JBossINF] [0m[0m02:44:56,928 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,942 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,948 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,949 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,949 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,950 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:44:56,955 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|8] (3) [perf21, perf18,
perf19]
[JBossINF] [0m[0m02:44:56,978 INFO [org.infinispan.CLUSTER] (thread-65,ejb,perf19)
ISPN100001: Node perf20 left the cluster
[JBossINF] [0m[0m02:45:58,220 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,221 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,223 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,223 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,224 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,225 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:45:58,225 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf21|9] (4) [perf21, perf18,
perf19, perf20]
[JBossINF] [0m[0m02:45:58,226 INFO [org.infinispan.CLUSTER] (thread-71,ejb,perf19)
ISPN100000: Node perf20 joined the cluster
[JBossINF] [0m[0m02:47:11,387 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,389 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,390 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,390 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,392 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,393 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[0m02:47:11,393 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN000094: Received new cluster view for channel ejb: [perf18|10] (3) [perf18, perf19,
perf20]
[JBossINF] [0m[0m02:47:11,394 INFO [org.infinispan.CLUSTER] (thread-87,ejb,perf19)
ISPN100001: Node perf21 left the cluster
[JBossINF] [0m[31m02:47:12,082 ERROR
[org.infinispan.interceptors.impl.InvocationContextInterceptor] (remote-thread--p8-t60)
ISPN000136: Error executing command LockControlCommand, writing keys []:
org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after
0 milliseconds for key
SessionCreationMetaDataKey(2UakcseFRb1cI_zcOL5fwpJnkR8j-fo74TsVeNSo) and requestor
GlobalTx:perf20:25537. Lock is held by GlobalTx:perf19:118742
[JBossINF] at
org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:288)
[JBossINF] at
org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.lock(DefaultLockManager.java:261)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.localLockCommandWork(PessimisticLockingInterceptor.java:209)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.lambda$new$0(PessimisticLockingInterceptor.java:46)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:81)
[JBossINF] at
org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:192)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:183)
[JBossINF] at
org.infinispan.interceptors.impl.TxInterceptor.visitLockControlCommand(TxInterceptor.java:222)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:54)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.lambda$new$0(BaseAsyncInterceptor.java:22)
[JBossINF] at
org.infinispan.interceptors.InvocationSuccessFunction.apply(InvocationSuccessFunction.java:25)
[JBossINF] at
org.infinispan.interceptors.impl.SimpleAsyncInvocationStage.addCallback(SimpleAsyncInvocationStage.java:70)
[JBossINF] at
org.infinispan.interceptors.InvocationStage.thenApply(InvocationStage.java:45)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.asyncInvokeNext(BaseAsyncInterceptor.java:224)
[JBossINF] at
org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:46)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:185)
[JBossINF] at
org.infinispan.statetransfer.StateTransferInterceptor.visitLockControlCommand(StateTransferInterceptor.java:90)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:123)
[JBossINF] at
org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
[JBossINF] at
org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:56)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:160)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:117)
[JBossINF] at
org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
[JBossINF] at
org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:234)
[JBossINF] at
org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:126)
[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)
{noformat}
--
This message was sent by Atlassian JIRA
(v7.5.0#75005)