[jboss-jira] [JBoss JIRA] (WFLY-10756) ISPN000136: Error executing command LockControlCommand
tommaso borgato (JIRA)
issues at jboss.org
Mon Jul 30 09:53:00 EDT 2018
[ https://issues.jboss.org/browse/WFLY-10756?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
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)
More information about the jboss-jira
mailing list