Uploaded image for project: 'ModeShape'
  1. ModeShape
  2. MODE-1845

Can't start multiple nodes at once while storing indexes in Infinispan

    XMLWordPrintable

Details

    • Bug
    • Resolution: Won't Do
    • Blocker
    • None
    • 3.1.3.Final
    • Clustering
    • None

    Description

      Use same configuration as from MODE-1843, this issues are related

      How to reproduce:
      unpack https://issues.jboss.org/secure/attachment/12361073/modeshape-remote-infinispan-store-example.tar.gz, run in 3 or 4 consoles:
      mvn exec:java -Djava.net.preferIPv4Stack=true

      then press 'l' and then enter in all consoles quickly.

      One instance would start cleanly, others would have errors like that in console:

      java.lang.IllegalStateException: Transaction DummyTransaction{xid=DummyXid{id=9}, status=1} is not in a valid state to be invoking cache operations on.
      	at org.infinispan.interceptors.TxInterceptor.enlist(TxInterceptor.java:228)
      	at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:204)
      	at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:149)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.handleWriteCommand(StateTransferLockInterceptor.java:181)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.visitPutKeyValueCommand(StateTransferLockInterceptor.java:152)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:127)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:132)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:91)
      	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:86)
      	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
      	at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1006)
      	at org.infinispan.CacheImpl.put(CacheImpl.java:702)
      	at org.infinispan.DecoratedCache.put(DecoratedCache.java:319)
      	at org.infinispan.lucene.InfinispanIndexOutput.close(InfinispanIndexOutput.java:209)
      	at org.apache.lucene.index.TermInfosWriter.close(TermInfosWriter.java:248)
      	at org.apache.lucene.util.IOUtils.close(IOUtils.java:141)
      	at org.apache.lucene.index.FormatPostingsFieldsWriter.finish(FormatPostingsFieldsWriter.java:70)
      	at org.apache.lucene.index.FreqProxTermsWriter.flush(FreqProxTermsWriter.java:138)
      	at org.apache.lucene.index.TermsHash.flush(TermsHash.java:113)
      	at org.apache.lucene.index.DocInverter.flush(DocInverter.java:70)
      	at org.apache.lucene.index.DocFieldProcessor.flush(DocFieldProcessor.java:60)
      	at org.apache.lucene.index.DocumentsWriter.flush(DocumentsWriter.java:581)
      	at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3623)
      	at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3588)
      	at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1858)
      	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1822)
      	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1786)
      	at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.closeIndexWriter(IndexWriterHolder.java:163)
      	at org.hibernate.search.backend.impl.lucene.SharedIndexWorkspaceImpl.afterTransactionApplied(SharedIndexWorkspaceImpl.java:54)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.applyUpdates(LuceneBackendQueueTask.java:138)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.run(LuceneBackendQueueTask.java:67)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
      	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:662)
      2013-03-06 16:31:59,101 ERROR [Hibernate Search: Index updates queue processor for index nodeinfo-1] (LogErrorHandler.java:83) - HSEARCH000058: Exception occurred java.lang.IllegalStateException: Transaction DummyTransaction{xid=DummyXid{id=9}, status=1} is not in a valid state to be invoking cache operations on.
      Primary Failure:
      	Entity org.modeshape.jcr.query.lucene.basic.NodeInfo  Id de0a8057505d64/  Work Type  org.hibernate.search.backend.UpdateLuceneWork
      
      java.lang.IllegalStateException: Transaction DummyTransaction{xid=DummyXid{id=9}, status=1} is not in a valid state to be invoking cache operations on.
      	at org.infinispan.interceptors.TxInterceptor.enlist(TxInterceptor.java:228)
      	at org.infinispan.interceptors.TxInterceptor.enlistWriteAndInvokeNext(TxInterceptor.java:204)
      	at org.infinispan.interceptors.TxInterceptor.visitPutKeyValueCommand(TxInterceptor.java:149)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.handleWriteCommand(StateTransferLockInterceptor.java:181)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.visitPutKeyValueCommand(StateTransferLockInterceptor.java:152)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:127)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:132)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:91)
      	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:86)
      	at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:62)
      	at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:77)
      	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
      	at org.infinispan.CacheImpl.executeCommandAndCommitIfNeeded(CacheImpl.java:1006)
      	at org.infinispan.CacheImpl.put(CacheImpl.java:702)
      	at org.infinispan.DecoratedCache.put(DecoratedCache.java:319)
      	at org.infinispan.lucene.InfinispanIndexOutput.close(InfinispanIndexOutput.java:209)
      	at org.apache.lucene.index.TermInfosWriter.close(TermInfosWriter.java:248)
      	at org.apache.lucene.util.IOUtils.close(IOUtils.java:141)
      	at org.apache.lucene.index.FormatPostingsFieldsWriter.finish(FormatPostingsFieldsWriter.java:70)
      	at org.apache.lucene.index.FreqProxTermsWriter.flush(FreqProxTermsWriter.java:138)
      	at org.apache.lucene.index.TermsHash.flush(TermsHash.java:113)
      	at org.apache.lucene.index.DocInverter.flush(DocInverter.java:70)
      	at org.apache.lucene.index.DocFieldProcessor.flush(DocFieldProcessor.java:60)
      	at org.apache.lucene.index.DocumentsWriter.flush(DocumentsWriter.java:581)
      	at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3623)
      	at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3588)
      	at org.apache.lucene.index.IndexWriter.closeInternal(IndexWriter.java:1858)
      	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1822)
      	at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1786)
      	at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.closeIndexWriter(IndexWriterHolder.java:163)
      	at org.hibernate.search.backend.impl.lucene.SharedIndexWorkspaceImpl.afterTransactionApplied(SharedIndexWorkspaceImpl.java:54)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.applyUpdates(LuceneBackendQueueTask.java:138)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.run(LuceneBackendQueueTask.java:67)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
      	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:662)
      

      or

      2013-03-06 16:32:02,712 ERROR [Hibernate Search: Index updates queue processor for index nodeinfo-1] (LogErrorHandler.java:83) - HSEARCH000058: Exception occurred org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@426e05
      Primary Failure:
      	Entity org.modeshape.jcr.query.lucene.basic.NodeInfo  Id de0a805619b7f2/  Work Type  org.hibernate.search.backend.UpdateLuceneWork
      
      org.apache.lucene.store.LockObtainFailedException: Lock obtain timed out: org.infinispan.lucene.locking.BaseLuceneLock@426e05
      	at org.apache.lucene.store.Lock.obtain(Lock.java:84)
      	at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:1108)
      	at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.createNewIndexWriter(IndexWriterHolder.java:127)
      	at org.hibernate.search.backend.impl.lucene.IndexWriterHolder.getIndexWriter(IndexWriterHolder.java:102)
      	at org.hibernate.search.backend.impl.lucene.AbstractWorkspaceImpl.getIndexWriter(AbstractWorkspaceImpl.java:119)
      	at org.hibernate.search.backend.impl.lucene.SharedIndexWorkspaceImpl.getIndexWriter(SharedIndexWorkspaceImpl.java:77)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.applyUpdates(LuceneBackendQueueTask.java:99)
      	at org.hibernate.search.backend.impl.lucene.LuceneBackendQueueTask.run(LuceneBackendQueueTask.java:67)
      	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
      	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:662)
      2013-03-06 16:32:02,712 ERROR [Hibernate Search: Index updates queue processor for index nodeinfo-1] (LuceneBackendQueueTask.java:101) - HSEARCH000072: Couldn't open the IndexWriter because of previous error: operation skipped, index ouf of sync!
      

      This issue is probably caused by underlying infinispan and hibernate, but affect modeshape behaviour, and should be fixed in my opinion.

      As you can see, different instances fail with different errors, so that's not only lock timeout issue, BTW. even when making lock timeout very, very large (20s) I still get different errors on console.

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              pjakub_jira Jakub Pawłowski (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: