2 Replies Latest reply on Jul 25, 2016 5:52 PM by atulkaushal

    WildFly 9.0.2 not starting due to infinispan exception

    atulkaushal

      Hi,

      We deployed our application in cluster mode using the instructions given at WildFly 9 Cluster Howto - WildFly 9 - Project Documentation Editor.

      Environment details:

      1. JAVA 8
      2. WildFly-9.0.2 Final
      3. domain mode
      4. <distributable/> in web.xml for session replication
      5. full-ha profile
      6. XA datasource

      Everything was working fine with some performance issues.  To fix performance issue, we updated the broadcast-group and discovery-group  jgroup-stack to tcp from udp.

      We did some text updates in application related configuration files and after that when we tried to start severs using Admin console it started failing.

       

      2016-06-29 13:44:45,272 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (ServerService Thread Pool -- 66) ISPN000136: Execution error: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from master:server-one, see cause for remote stack trace

        at org.infinispan.remoting.transport.AbstractTransport.checkResponse(AbstractTransport.java:46)

        at org.infinispan.remoting.transport.AbstractTransport.parseResponseAndAddToResponseList(AbstractTransport.java:71)

        at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:586)

        at org.infinispan.remoting.rpc.RpcManagerImpl.invokeRemotely(RpcManagerImpl.java:287)

        at org.infinispan.interceptors.distribution.TxDistributionInterceptor.visitLockControlCommand(TxDistributionInterceptor.java:185)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:174)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:174)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:174)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.acquireRemoteIfNeeded(PessimisticLockingInterceptor.java:238)

        at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitDataWriteCommand(PessimisticLockingInterceptor.java:128)

        at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.visitPutKeyValueCommand(AbstractTxLockingInterceptor.java:68)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:71)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:44)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:71)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:367)

        at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:263)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:71)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:44)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:71)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.statetransfer.StateTransferInterceptor.handleTxWriteCommand(StateTransferInterceptor.java:265)

        at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:247)

        at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:108)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:71)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.CacheMgmtInterceptor.updateStoreStatistics(CacheMgmtInterceptor.java:191)

        at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:177)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:71)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:102)

        at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:71)

        at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:44)

        at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:71)

        at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)

        at org.infinispan.cache.impl.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1617)

        at org.infinispan.cache.impl.CacheImpl.putInternal(CacheImpl.java:1097)

        at org.infinispan.cache.impl.CacheImpl.put(CacheImpl.java:1089)

        at org.infinispan.cache.impl.DecoratedCache.put(DecoratedCache.java:437)

        at org.infinispan.cache.impl.AbstractDelegatingCache.put(AbstractDelegatingCache.java:292)

        at org.wildfly.clustering.server.registry.CacheRegistry.getLocalEntry(CacheRegistry.java:129)

        at org.wildfly.clustering.server.registry.CacheRegistry.<init>(CacheRegistry.java:76)

        at org.wildfly.clustering.server.registry.CacheRegistryFactory$1.<init>(CacheRegistryFactory.java:53)

        at org.wildfly.clustering.server.registry.CacheRegistryFactory.createRegistry(CacheRegistryFactory.java:53)

        at org.wildfly.clustering.server.registry.RegistryBuilder.start(RegistryBuilder.java:83)

        at org.wildfly.clustering.service.AsynchronousServiceBuilder$1.run(AsynchronousServiceBuilder.java:102)

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

        at java.lang.Thread.run(Thread.java:745)

        at org.jboss.threads.JBossThread.run(JBossThread.java:320)

      Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key master:server-one and requestor GlobalTransaction:<master:server-one>:1:remote. Lock is held by null, while request came from master:server-one

        at org.infinispan.util.concurrent.locks.LockManagerImpl.lock(LockManagerImpl.java:198)

        at org.infinispan.util.concurrent.locks.LockManagerImpl.acquireLock(LockManagerImpl.java:171)

        at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockKeyAndCheckOwnership(AbstractTxLockingInterceptor.java:183)

        at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.lockAndRegisterBackupLock(AbstractTxLockingInterceptor.java:116)

        at org.infinispan.interceptors.locking.PessimisticLockingInterceptor.visitLockControlCommand(PessimisticLockingInterceptor.java:200)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:174)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.TxInterceptor.invokeNextInterceptorAndVerifyTransaction(TxInterceptor.java:138)

        at org.infinispan.interceptors.TxInterceptor.visitLockControlCommand(TxInterceptor.java:258)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:174)

        at org.infinispan.statetransfer.TransactionSynchronizerInterceptor.visitLockControlCommand(TransactionSynchronizerInterceptor.java:75)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.statetransfer.StateTransferInterceptor.handleTxCommand(StateTransferInterceptor.java:200)

        at org.infinispan.statetransfer.StateTransferInterceptor.visitLockControlCommand(StateTransferInterceptor.java:103)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:111)

        at org.infinispan.commands.AbstractVisitor.visitLockControlCommand(AbstractVisitor.java:174)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:97)

        at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:102)

        at org.infinispan.interceptors.InvocationContextInterceptor.visitLockControlCommand(InvocationContextInterceptor.java:76)

        at org.infinispan.commands.control.LockControlCommand.acceptVisitor(LockControlCommand.java:110)

        at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:336)

        at org.infinispan.commands.control.LockControlCommand.perform(LockControlCommand.java:129)

        at org.infinispan.remoting.inboundhandler.BasePerCacheInboundInvocationHandler.invokePerform(BasePerCacheInboundInvocationHandler.java:85)

        at org.infinispan.remoting.inboundhandler.BaseBlockingRunnable.run(BaseBlockingRunnable.java:32)

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

        at java.lang.Thread.run(Thread.java:745)

       

      We also tried to stop wildfly and again start it but its still failing.

      Jun 29 13:42:29 jbsq34m1 jbsq34m1[25841]: MSC000001: Failed to start service jboss.clustering.registry.web.default

      Jun 29 13:42:30 jbsq34m1 jbsq34m1[25841]: WFLYSRV0021: Deploy of deployment "clinportal.war" was rolled back with the following failure message: "WFLYCTL0159: Operation handler failed to complete"

      Jun 29 13:44:45 jbsq34m1 jbsq34m1[26361]: ISPN000136: Execution error

      Jun 29 13:44:45 jbsq34m1 jbsq34m1[26361]: MSC000001: Failed to start service jboss.clustering.registry.web.default

      Jun 29 13:44:45 jbsq34m1 jbsq34m1[26361]: WFLYCTL0013: Operation ("add") failed - address: ([

          ("subsystem" => "infinispan"),

          ("cache-container" => "web")

      ]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.clustering.registry.web.default" => "org.jboss.msc.service.StartException in service jboss.clustering.registry.web.default: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from master:server-one, see cause for remote stack trace

          Caused by: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from master:server-one, see cause for remote stack trace

          Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key master:server-one and requestor GlobalTransaction:<master:server-one>:1:remote. Lock is held by null, while request came from master:server-one"}}

      Jun 29 13:44:45 jbsq34m1 jbsq34m1[26361]: WFLYSRV0026: WildFly Full 9.0.2.Final (WildFly Core 1.0.2.Final) started (with errors) in 19545ms - Started 1615 of 1801 services (6 services failed or missing dependencies, 293 services are lazy, passive or on-demand)

      Jun 29 13:44:46 jbsq34m1 jbsq34m1[22304]: ISPN000136: Execution error

      Jun 29 13:44:46 jbsq34m1 jbsq34m1[22304]: MSC000001: Failed to start service jboss.clustering.registry.web.default

      Jun 29 13:44:46 jbsq34m1 jbsq34m1[22304]: WFLYCTL0013: Operation ("add") failed - address: ([

          ("subsystem" => "infinispan"),

          ("cache-container" => "web")

      ]) - failure description: {"WFLYCTL0080: Failed services" => {"jboss.clustering.registry.web.default" => "org.jboss.msc.service.StartException in service jboss.clustering.registry.web.default: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from master:server-one, see cause for remote stack trace

          Caused by: org.infinispan.remoting.RemoteException: ISPN000217: Received exception from master:server-one, see cause for remote stack trace

          Caused by: org.infinispan.util.concurrent.TimeoutException: ISPN000299: Unable to acquire lock after 15 seconds for key slave:server-one and requestor GlobalTransaction:<slave:server-one>:1:remote. Lock is held by null, while request came from slave:server-one"}}

      Jun 29 13:44:46 jbsq34m1 jbsq34m1[22304]: WFLYSRV0026: WildFly Full 9.0.2.Final (WildFly Core 1.0.2.Final) started (with errors) in 17409ms - Started 1616 of 1802 services (6 services failed or missing dependencies, 294 services are lazy, passive or on-demand)

       

      I tried to fix this issue by implementing the solution given at HTTP Session Replication - org.infinispan.util.concurrent.TimeoutException  on both master and slave instance but it is also not working.

      <cache-container name="web" default-cache="repl" module="org.wildfly.clustering.web.infinispan">
                          <transport lock-timeout="60000"/>
                          <distributed-cache name="repl" mode="ASYNC" batching="true">
                              <locking isolation="READ_COMMITTED"/>
                              <transaction locking="OPTIMISTIC"/>
                              <file-store/>
                          </distributed-cache>
                      </cache-container>
      

      Any pointers will be appreciated.

       

       

      Thanks,

      Atul

        • 1. Re: WildFly 9.0.2 not starting due to infinispan exception
          pferraro

          Can you reproduce the issue on master?  WF 10.1 is due to be released from master very soon.

          • 2. Re: WildFly 9.0.2 not starting due to infinispan exception
            atulkaushal

            Changing configuration to the snippet given below resolved our issue.

             

            <cache-container name="web" default-cache="dist" module="org.wildfly.clustering.web.infinispan">

                                <transport lock-timeout="240000"/>

                                <distributed-cache name="dist" mode="ASYNC" owners="2" l1-lifespan="0">

                                    <locking isolation="REPEATABLE_READ"/>

                                    <transaction mode="BATCH"/>

                                    <file-store/>

                                    <state-transfer timeout="120000"/>

                                </distributed-cache>

                            </cache-container>