Uploaded image for project: 'JBoss Enterprise Application Platform'
  1. JBoss Enterprise Application Platform
  2. JBEAP-29381

(8.1.z) [CLUSTERING] ISPN000299 after node re-start

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Critical Critical
    • None
    • 8.0 Update 1, 8.0 Update 5, 8.0 Update 6, 8.1.0.GA-CR2, 8.1.0.GA-CR4, 8.1.0.Beta, 8.1.0.GA-CR7, 8.1.0.GA-CR9, 8.1.0.GA-CR10
    • Clustering
    • None
    • False
    • Hide

      None

      Show
      None
    • False
    • Known Issue

      In a cluster where cluster communication is asymmetrically encrypted (the issue is not limited to asym encrypt scenarios - see comments below), we get an error when a node is re-started; this error is particularly interesting because it doesn't happen when a node in the cluster is failed but, rather, when the node is re-started; this is quite unusual and even thought the client fail rate isn't much affected, the server logs are literally flooded by this error;

      We observed the error also in 8.0, hence we are not setting priority to blocker;

      We have a 4 nodes cluster where cluster communication is asymmetrically encrypted; each node is configured as in the following:

      embed-server --server-config=standalone-ha.xml
/subsystem=infinispan/cache-container=web/distributed-cache=testDist:add()
/subsystem=infinispan/cache-container=web/distributed-cache=testDist/component=locking:write-attribute(name=isolation, value=REPEATABLE_READ)
/subsystem=infinispan/cache-container=web/distributed-cache=testDist/component=transaction:write-attribute(name=mode, value=BATCH)
/subsystem=infinispan/cache-container=web:write-attribute(name=default-cache, value=testDist)
batch
/subsystem=jgroups/stack=udp/protocol=AUTH:add(add-index=8)
/subsystem=jgroups/stack=udp/protocol=AUTH/token=digest:add(algorithm=SHA-512, shared-secret-reference={clear-text=123PIPPOBAUDO})
/subsystem=jgroups/stack=tcp/protocol=AUTH:add(add-index=8)
/subsystem=jgroups/stack=tcp/protocol=AUTH/token=digest:add(algorithm=SHA-512, shared-secret-reference={clear-text=123PIPPOBAUDO})
run-batch
/subsystem=jgroups/stack=udp/protocol=ASYM_ENCRYPT:add(add-index=5,properties={sym_keylength=128,sym_algorithm=AES/ECB/PKCS5Padding,asym_keylength=512,asym_algorithm=RSA})
/subsystem=jgroups/stack=tcp/protocol=ASYM_ENCRYPT:add(add-index=5,properties={sym_keylength=128,sym_algorithm=AES/ECB/PKCS5Padding,asym_keylength=512,asym_algorithm=RSA})
if (outcome != success) of /subsystem=jgroups:read-attribute(name=default-stack)
/subsystem=jgroups/channel=ee:write-attribute(name=stack,value=tcp)
else
/subsystem=jgroups:write-attribute(name=default-stack,value=tcp)
/subsystem=jgroups/channel=ee:write-attribute(name=stack,value=tcp)

      Fail over is triggered by killing the server JVM;

      We noticed the following error when a node is re-started (see details in the comment below):

      2025-02-18 21:27:34,442 INFO  [org.infinispan.CLUSTER] (thread-51,ejb,wildfly4) ISPN100000: Node wildfly2 joined the cluster
2025-02-18 21:27:34,613 ERROR [org.infinispan.interceptors.impl.InvocationContextInterceptor] (thread-18,ejb,wildfly4) ISPN000136: Error executing command LockControlCommand on Cache 'clusterbench-ee10.ear.clusterbench-ee10-web.war', writing keys []: org.infinispan.commons.TimeoutException: ISPN000299: Unable to acquire lock after 0 milliseconds for key SessionMetaDataKey(ywL7uk5WBSE1virGu4hIv0JD9b81M50ZGGcbMb8P) and requestor GlobalTransaction{id=55069, addr=wildfly3, remote=true, xid=null, internalId=-1}. Lock is held by GlobalTransaction{id=55060, addr=wildfly3, remote=true, xid=null, internalId=-1}
	at org.infinispan.core@15.0.11.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:299)
	at org.infinispan.core@15.0.11.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.get(DefaultLockManager.java:229)
	at org.infinispan.core@15.0.11.Final//org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.checkState(InfinispanLock.java:554)
	at org.infinispan.core@15.0.11.Final//org.infinispan.util.concurrent.locks.impl.InfinispanLock$LockPlaceHolder.toInvocationStage(InfinispanLock.java:481)
	at org.infinispan.core@15.0.11.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:259)
	at org.infinispan.core@15.0.11.Final//org.infinispan.util.concurrent.locks.impl.DefaultLockManager$KeyAwareExtendedLockPromise.toInvocationStage(DefaultLockManager.java:283)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.locking.AbstractLockingInterceptor.lockAllAndRecord(AbstractLockingInterceptor.java:293)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.checkPendingAndLockAllKeys(AbstractTxLockingInterceptor.java:157)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAllOrRegisterBackupLock(AbstractTxLockingInterceptor.java:109)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.locking.PessimisticLockingInterceptor.localLockCommandWork(PessimisticLockingInterceptor.java:211)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.locking.PessimisticLockingInterceptor.lambda$new$0(PessimisticLockingInterceptor.java:44)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextThenApply(BaseAsyncInterceptor.java:85)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:193)
	at org.infinispan.core@15.0.11.Final//org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:102)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:187)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.impl.TxInterceptor.visitLockControlCommand(TxInterceptor.java:224)
	at org.infinispan.core@15.0.11.Final//org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:102)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.asyncInvokeNext(BaseAsyncInterceptor.java:231)
	at org.infinispan.core@15.0.11.Final//org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitCommand(TransactionSynchronizerInterceptor.java:46)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndHandle(BaseAsyncInterceptor.java:189)
	at org.infinispan.core@15.0.11.Final//org.infinispan.statetransfer.StateTransferInterceptor.visitLockControlCommand(StateTransferInterceptor.java:90)
	at org.infinispan.core@15.0.11.Final//org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:102)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:58)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.DDAsyncInterceptor.handleDefault(DDAsyncInterceptor.java:54)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:165)
	at org.infinispan.core@15.0.11.Final//org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:102)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNextAndExceptionally(BaseAsyncInterceptor.java:127)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.impl.InvocationContextInterceptor.visitCommand(InvocationContextInterceptor.java:90)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.BaseAsyncInterceptor.invokeNext(BaseAsyncInterceptor.java:60)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.impl.BatchingInterceptor.handleDefault(BatchingInterceptor.java:74)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.DDAsyncInterceptor.visitLockControlCommand(DDAsyncInterceptor.java:165)
	at org.infinispan.core@15.0.11.Final//org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:102)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.DDAsyncInterceptor.visitCommand(DDAsyncInterceptor.java:50)
	at org.infinispan.core@15.0.11.Final//org.infinispan.interceptors.impl.AsyncInterceptorChainImpl.invokeAsync(AsyncInterceptorChainImpl.java:211)
	at org.infinispan.core@15.0.11.Final//org.infinispan.commands.control.LockControlCommand.invokeAsync(LockControlCommand.java:112)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokeCommand(BasePerCacheInboundInvocationHandler.java:108)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.invoke(BaseBlockingRunnable.java:111)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.runAsync(BaseBlockingRunnable.java:79)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:48)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.handleRunnable(BasePerCacheInboundInvocationHandler.java:154)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.TxPerCacheInboundInvocationHandler.handle(TxPerCacheInboundInvocationHandler.java:37)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler.handleCacheRpcCommand(GlobalInboundInvocationHandler.java:123)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.inboundhandler.GlobalInboundInvocationHandler.handleFromCluster(GlobalInboundInvocationHandler.java:77)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.transport.jgroups.JGroupsTransport.processRequest(JGroupsTransport.java:1527)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.transport.jgroups.JGroupsTransport.processMessage(JGroupsTransport.java:1454)
	at org.infinispan.core@15.0.11.Final//org.infinispan.remoting.transport.jgroups.JGroupsTransport$ChannelCallbacks.up(JGroupsTransport.java:1649)
	at org.jgroups@5.3.13.Final//org.jgroups.JChannel.up(JChannel.java:748)
	at org.jgroups@5.3.13.Final//org.jgroups.fork.ForkProtocolStack.up(ForkProtocolStack.java:132)
	at org.jgroups@5.3.13.Final//org.jgroups.stack.Protocol.up(Protocol.java:360)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.FORK.up(FORK.java:146)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.FRAG2.up(FRAG2.java:139)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.FlowControl.up(FlowControl.java:253)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.FlowControl.up(FlowControl.java:261)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.pbcast.GMS.up(GMS.java:853)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:235)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.AUTH.up(AUTH.java:119)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.UNICAST3.deliverMessage(UNICAST3.java:1144)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.UNICAST3.addMessage(UNICAST3.java:880)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.UNICAST3.handleDataReceived(UNICAST3.java:862)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.UNICAST3.up(UNICAST3.java:474)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.pbcast.NAKACK2.up(NAKACK2.java:669)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.VERIFY_SUSPECT2.up(VERIFY_SUSPECT2.java:105)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.Encrypt.handleEncryptedMessage(Encrypt.java:272)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.Encrypt.up(Encrypt.java:167)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.ASYM_ENCRYPT.up(ASYM_ENCRYPT.java:162)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.FailureDetection.up(FailureDetection.java:180)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.FD_SOCK2.up(FD_SOCK2.java:190)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.MERGE3.up(MERGE3.java:274)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.Discovery.up(Discovery.java:296)
	at org.jgroups@5.3.13.Final//org.jgroups.stack.Protocol.up(Protocol.java:360)
	at org.jgroups@5.3.13.Final//org.jgroups.protocols.TP.passMessageUp(TP.java:1232)
	at org.jgroups@5.3.13.Final//org.jgroups.util.SubmitToThreadPool$SingleMessageHandler.run(SubmitToThreadPool.java:95)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at org.wildfly.clustering.context@5.0.4.Final//org.wildfly.clustering.context.ContextualExecutor$1.execute(ContextualExecutor.java:180)
	at org.wildfly.clustering.context@5.0.4.Final//org.wildfly.clustering.context.ContextualExecutor.execute(ContextualExecutor.java:31)
	at org.wildfly.clustering.context@5.0.4.Final//org.wildfly.clustering.context.Contextualizer$2$1.run(Contextualizer.java:220)
	at java.base/java.lang.Thread.run(Thread.java:840)

      Complete server logs and configuration in eap-8.x-clustering-http-session-encrypt-asym_297.zip ;

      Details about the erorr in the comment below;

        1. eap-8.x-clustering-http-session-encrypt-asym_297.zip
          3.70 MB
        2. JAVA_STACK.zip
          198 kB
        3. wildfly-eap-8.x-clustering-ejb-ejbservlet-shutdown-dist_366.zip
          1004 kB
        4. wildfly-run-204.zip
          969 kB

              pferraro@redhat.com Paul Ferraro
              tborgato@redhat.com Tommaso Borgato
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

                Created:
                Updated: