-
Bug
-
Resolution: Won't Do
-
Blocker
-
None
-
3.1.3.Final
-
None
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.