2 Replies Latest reply on Feb 1, 2012 10:20 PM by Sandeep Kumar

    startcaches working in 5.1.0.CR3 not working in 5.1.0.Final

    Sandeep Kumar Newbie

      i am doing a startCaches on startup of every node in a cluster.

      Configuration is :

      cache mode Distributed Async

      I am using the fluent style for configuration.

       

      I am using 2 node cluster starting 5 caches using startcaches.  I name them Cache-0 to Cache-4

      i simultaneously start treecaches too based on the map cache that i create.

      this has been working for me till 5.1.0.CR3 when i changed version to 5.1.0.Final i am getting following errors in one of the nodes:

       

      This is the node where i could get the cashes to start up and immediately after i see following errors:

       

      2012-01-26 16:04:48,968 ERROR [CacheViewsManagerImpl] (CacheViewInstaller-1,delsku11784387-1680) ISPN000172: Failed to prepare view CacheView{viewId=2, members=[delsku11784387-1680, delsku11784387-16280]} for cache  ___defaultcache, rolling back to view CacheView{viewId=1, members=[delsku11784387-1680]}

      java.util.concurrent.TimeoutException

                at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:228)

                at java.util.concurrent.FutureTask.get(FutureTask.java:91)

                at org.infinispan.cacheviews.CacheViewsManagerImpl.clusterPrepareView(CacheViewsManagerImpl.java:322)

                at org.infinispan.cacheviews.CacheViewsManagerImpl.clusterInstallView(CacheViewsManagerImpl.java:250)

                at org.infinispan.cacheviews.CacheViewsManagerImpl$ViewInstallationTask.call(CacheViewsManagerImpl.java:877)

                at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)

                at java.util.concurrent.FutureTask.run(FutureTask.java:138)

                at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

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

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

       

      In the second node i am not able to create a tree cache:

      2012-01-26 16:20:14,750 ERROR [InvocationContextInterceptor] (main) ISPN000136: Execution error

      org.infinispan.statetransfer.StateTransferInProgressException: Timed out waiting for the state transfer lock, state transfer in progress for view 2

                at org.infinispan.interceptors.StateTransferLockInterceptor.signalStateTransferInProgress(StateTransferLockInterceptor.java:199)

                at org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:80)

                at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131)

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

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

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

                at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113)

                at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131)

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

                at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:86)

                at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113)

                at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131)

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

                at org.infinispan.transaction.TransactionCoordinator.commit(TransactionCoordinator.java:174)

                at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:83)

                at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:272)

                at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:321)

                at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:90)

                at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:100)

                at org.infinispan.batch.BatchContainer.resolveTransaction(BatchContainer.java:123)

                at org.infinispan.batch.BatchContainer.endBatch(BatchContainer.java:105)

                at org.infinispan.batch.AutoBatchSupport.endAtomic(AutoBatchSupport.java:49)

                at org.infinispan.tree.TreeStructureSupport.exists(TreeStructureSupport.java:52)

                at org.infinispan.tree.TreeCacheImpl.createRoot(TreeCacheImpl.java:465)

                at org.infinispan.tree.TreeCacheImpl.<init>(TreeCacheImpl.java:55)

                at org.infinispan.tree.TreeCacheImpl.<init>(TreeCacheImpl.java:47)

                at org.infinispan.tree.TreeCacheFactory.createTreeCache(TreeCacheFactory.java:59)

                at com.xweld.services.cache.infinispan.tree.InfinispanTreeCache.<init>(InfinispanTreeCache.java:128)

                at com.xweld.services.cache.infinispan.Cache.<init>(Cache.java:91)

                at com.xweld.services.cache.infinispan.CacheManager.configure(CacheManager.java:264)

                at com.xweld.services.cache.CacheManagerFactory.getInstance(CacheManagerFactory.java:101)

                at com.xweld.services.cache.signed.TestSignedCacheSlaveNode.testSignedCacheOnSlave(TestSignedCacheSlaveNode.java:222)

                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

                at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

                at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

                at java.lang.reflect.Method.invoke(Method.java:597)

                at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)

                at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)

                at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)

                at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)

                at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)

                at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)

                at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)

                at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)

                at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)

                at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)

                at org.junit.runners.ParentRunner.run(ParentRunner.java:236)

                at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)

                at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

      2012-01-26 16:20:14,750 ERROR [TransactionCoordinator] (main) ISPN000097: Error while processing 1PC PrepareCommand

      org.infinispan.statetransfer.StateTransferInProgressException: Timed out waiting for the state transfer lock, state transfer in progress for view 2

                at org.infinispan.interceptors.StateTransferLockInterceptor.signalStateTransferInProgress(StateTransferLockInterceptor.java:199)

                at org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:80)

                at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131)

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

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

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

                at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113)

                at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131)

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

                at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:86)

                at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113)

                at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131)

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

                at org.infinispan.transaction.TransactionCoordinator.commit(TransactionCoordinator.java:174)

                at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:83)

                at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:272)

                at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:321)

                at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:90)

                at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:100)

                at org.infinispan.batch.BatchContainer.resolveTransaction(BatchContainer.java:123)

                at org.infinispan.batch.BatchContainer.endBatch(BatchContainer.java:105)

                at org.infinispan.batch.AutoBatchSupport.endAtomic(AutoBatchSupport.java:49)

                at org.infinispan.tree.TreeStructureSupport.exists(TreeStructureSupport.java:52)

                at org.infinispan.tree.TreeCacheImpl.createRoot(TreeCacheImpl.java:465)

                at org.infinispan.tree.TreeCacheImpl.<init>(TreeCacheImpl.java:55)

                at org.infinispan.tree.TreeCacheImpl.<init>(TreeCacheImpl.java:47)

                at org.infinispan.tree.TreeCacheFactory.createTreeCache(TreeCacheFactory.java:59)

                at com.xweld.services.cache.infinispan.tree.InfinispanTreeCache.<init>(InfinispanTreeCache.java:128)

                at com.xweld.services.cache.infinispan.Cache.<init>(Cache.java:91)

                at com.xweld.services.cache.infinispan.CacheManager.configure(CacheManager.java:264)

                at com.xweld.services.cache.CacheManagerFactory.getInstance(CacheManagerFactory.java:101)

                at com.xweld.services.cache.signed.TestSignedCacheSlaveNode.testSignedCacheOnSlave(TestSignedCacheSlaveNode.java:222)

                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

                at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

                at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

                at java.lang.reflect.Method.invoke(Method.java:597)

                at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)

                at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)

                at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)

                at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)

                at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)

                at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)

                at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)

                at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)

                at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)

                at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)

                at org.junit.runners.ParentRunner.run(ParentRunner.java:236)

                at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)

                at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

      2012-01-26 16:20:14,765 ERROR [DummyTransaction] (main) ISPN000111: afterCompletion() failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=1}, status=3}, lockedKeys=null, backupKeyLocks=null, viewId=1} org.infinispan.transaction.synchronization.SyncLocalTransaction@1} org.infinispan.transaction.synchronization.SynchronizationAdapter@20

      org.infinispan.CacheException: Could not commit.

                at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:85)

                at org.infinispan.transaction.tm.DummyTransaction.notifyAfterCompletion(DummyTransaction.java:272)

                at org.infinispan.transaction.tm.DummyTransaction.runCommitTx(DummyTransaction.java:321)

                at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:90)

                at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:100)

                at org.infinispan.batch.BatchContainer.resolveTransaction(BatchContainer.java:123)

                at org.infinispan.batch.BatchContainer.endBatch(BatchContainer.java:105)

                at org.infinispan.batch.AutoBatchSupport.endAtomic(AutoBatchSupport.java:49)

                at org.infinispan.tree.TreeStructureSupport.exists(TreeStructureSupport.java:52)

                at org.infinispan.tree.TreeCacheImpl.createRoot(TreeCacheImpl.java:465)

                at org.infinispan.tree.TreeCacheImpl.<init>(TreeCacheImpl.java:55)

                at org.infinispan.tree.TreeCacheImpl.<init>(TreeCacheImpl.java:47)

                at org.infinispan.tree.TreeCacheFactory.createTreeCache(TreeCacheFactory.java:59)

                at com.xweld.services.cache.infinispan.tree.InfinispanTreeCache.<init>(InfinispanTreeCache.java:128)

                at com.xweld.services.cache.infinispan.Cache.<init>(Cache.java:91)

                at com.xweld.services.cache.infinispan.CacheManager.configure(CacheManager.java:264)

                at com.xweld.services.cache.CacheManagerFactory.getInstance(CacheManagerFactory.java:101)

                at com.xweld.services.cache.signed.TestSignedCacheSlaveNode.testSignedCacheOnSlave(TestSignedCacheSlaveNode.java:222)

                at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

                at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)

                at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

                at java.lang.reflect.Method.invoke(Method.java:597)

                at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)

                at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)

                at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)

                at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:76)

                at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50)

                at org.junit.runners.ParentRunner$3.run(ParentRunner.java:193)

                at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:52)

                at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:191)

                at org.junit.runners.ParentRunner.access$000(ParentRunner.java:42)

                at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:184)

                at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:28)

                at org.junit.runners.ParentRunner.run(ParentRunner.java:236)

                at org.eclipse.jdt.internal.junit4.runner.JUnit4TestReference.run(JUnit4TestReference.java:50)

                at org.eclipse.jdt.internal.junit.runner.TestExecution.run(TestExecution.java:38)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:467)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.runTests(RemoteTestRunner.java:683)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.run(RemoteTestRunner.java:390)

                at org.eclipse.jdt.internal.junit.runner.RemoteTestRunner.main(RemoteTestRunner.java:197)

      Caused by: javax.transaction.xa.XAException

                at org.infinispan.transaction.TransactionCoordinator.handleCommitFailure(TransactionCoordinator.java:219)

                at org.infinispan.transaction.TransactionCoordinator.commit(TransactionCoordinator.java:176)

                at org.infinispan.transaction.synchronization.SynchronizationAdapter.afterCompletion(SynchronizationAdapter.java:83)

                ... 40 more

       

      Please find attached log file debug level is trace.

       

       

      i did some more debugging and found that all my problems in forming a cluster go away when i disable deadlock detection and enable l1 stack.

      Could you tell me why this would hapen?

      Follwoing is the config that makes it work:

      <tns:namedCacheConfiguration xmlns:tns="urn:infinispan:config:5.1" xmlns:xs="http://www.w3.org/2001/XMLSchema">

          <tns:locking writeSkewCheck="false" useLockStriping="false" lockAcquisitionTimeout="300000" isolationLevel="READ_COMMITTED" concurrencyLevel="5000"/>

          <tns:loaders shared="false" preload="false" passivation="false"/>

          <tns:transaction useSynchronization="false" useEagerLocking="false" use1PcForAutoCommitTransactions="false" transactionMode="TRANSACTIONAL" syncRollbackPhase="false" syncCommitPhase="true" lockingMode="OPTIMISTIC" eagerLockSingleNode="false" cacheStopTimeout="30000" autoCommit="true">

              <tns:recovery recoveryInfoCacheName="__recoveryInfoCacheName__" enabled="false"/>

          </tns:transaction>

          <tns:customInterceptors/>

          <tns:dataContainer class="org.infinispan.container.DefaultDataContainer">

              <tns:properties/>

          </tns:dataContainer>

          <tns:eviction wakeUpInterval="-9223372036854775808" threadPolicy="DEFAULT" strategy="NONE" maxEntries="-1"/>

          <tns:expiration wakeUpInterval="60000" maxIdle="-1" lifespan="-1" reaperEnabled="true"/>

          <tns:unsafe unreliableReturnValues="false"/>

          <tns:clustering>

              <tns:sync replTimeout="300000"/>

              <tns:stateRetrieval timeout="300000" retryWaitTimeIncreaseFactor="2" numRetries="10" maxNonProgressingLogWrites="100" logFlushTimeout="60000" initialRetryWaitTime="500" fetchInMemoryState="false" alwaysProvideInMemoryState="false">

                  <tns:chunkSize>10000</tns:chunkSize>

              </tns:stateRetrieval>

              <tns:l1 onRehash="true" lifespan="600000" invalidationThreshold="0" enabled="true"/>

              <tns:async useReplQueue="false" replQueueMaxElements="1000" replQueueInterval="5000" replQueueClass="org.infinispan.remoting.ReplicationQueueImpl" asyncMarshalling="false"/>

              <tns:hash rehashWait="60000" rehashRpcTimeout="600000" rehashEnabled="true" numVirtualNodes="1" numOwners="2" hashFunctionClass="org.infinispan.commons.hash.MurmurHash3">

                  <tns:groups enabled="false"/>

              </tns:hash>

          </tns:clustering>

          <tns:jmxStatistics enabled="false"/>

          <tns:storeAsBinary storeValuesAsBinary="true" storeKeysAsBinary="true" enabled="false"/>

          <tns:lazyDeserialization enabled="false"/>

          <tns:deadlockDetection spinDuration="100" enabled="false"/>

          <tns:indexing indexLocalOnly="false" enabled="false">

              <tns:properties/>

          </tns:indexing>

          <tns:versioning versioningScheme="NONE" enabled="false"/>

          <tns:invocationBatching enabled="true"/>

      </tns:namedCacheConfiguration>

      i did a configuration.toXmlString to print this ... here too i am seeing no mode printed though i am using cache mode as Distributed Async.