[infinispan-issues] [JBoss JIRA] (ISPN-6981) AffinityIndexManager fails to index documents in async mode
Gustavo Fernandes (JIRA)
issues at jboss.org
Wed Sep 7 13:29:00 EDT 2016
[ https://issues.jboss.org/browse/ISPN-6981?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13290081#comment-13290081 ]
Gustavo Fernandes commented on ISPN-6981:
-----------------------------------------
Digging a bit more on the {{This lock is no longer being held}} error, it seems a visibility issue with the LockCache:
1) Index {{entity.235}} is started on {{NodeB}}, it acquires and release the lock, common practice when initializing the Infinispan Directory:
{code}
21:04:15,598 DEBUG (pool-3-thread-2:[]) [WorkspaceHolder] HSEARCH000236: Backend for index 'entity.235' started: using asynchronous backend with periodic commits.
21:04:15,608 TRACE (pool-3-thread-2:[]) [BaseLuceneLock] Lock: write.lock acquired for index: entity.235 from AffinityTopologyChangeAsyncTest-NodeB-33534
21:04:15,628 TRACE (pool-3-thread-2:[]) [BaseLuceneLock] Lock: write.lock removed for index: entity.235 from AffinityTopologyChangeAsyncTest-NodeB-33534 (was AffinityTopologyChangeAsyncTest-NodeB-33534)
{code}
2) An index work arrives on {{NodeB}}, and it re-acquires the lock
{code}
21:04:15,632 TRACE (Hibernate Search: Index updates queue processor for index entity.235-1:[]) [BaseLuceneLock] Lock: write.lock acquired for index: entity.235 from AffinityTopologyChangeAsyncTest-NodeB-33534
21:04:15,635 TRACE (Hibernate Search: Index updates queue processor for index entity.235-1:[]) [InfinispanIndexOutput] Opened new IndexOutput for file:_0.fdt in index: entity.235
{code}
3) Due to topology changes, {{NodeB}} looses ownership of segment 235, and thus from index {{entity.235}}. It starts the process of flushing the index as part of the close:
{code}
21:04:16,479 DEBUG (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [AffinityIndexManager] Topology changed notification for entity.235
21:04:16,480 DEBUG (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [AffinityIndexManager] Ownership lost to 'AffinityTopologyChangeAsyncTest-NodeD-30445', closing index manager
21:04:16,480 DEBUG (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [AffinityIndexManager] Flushing directory provider
21:04:16,489 DEBUG (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [AbstractWorkspaceImpl] HSEARCH000304: Closing index writer for IndexManager 'entity.235'
21:04:17,542 DEBUG (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [DirectoryImplementor] Removed file: segments_1 from index: entity.235 from AffinityTopologyChangeAsyncTest-NodeB-33534
21:04:17,543 TRACE (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [InfinispanIndexOutput] Refreshed file listing view
{code}
4) While the flushing is happening, the new owner of segment 235, {{NodeD}}, *for an unknown reason, acquires the lock* for {{entity.235}}, when it shouldn't, since in theory {{NodeB}} still holds the lock.
{code}
21:04:17,835 DEBUG (remote-thread-AffinityTopologyChangeAsyncTest-NodeD-p26-t5:[]) [AffinityIndexManager] *Lock holder for 235 is null*
21:04:17,843 TRACE (Hibernate Search: Index updates queue processor for index entity.235-1:[]) [BaseLuceneLock] Lock: write.lock acquired for index: entity.235 from AffinityTopologyChangeAsyncTest-NodeD-30445
21:04:17,849 TRACE (Hibernate Search: Index updates queue processor for index entity.235-1:[]) [InfinispanIndexOutput] Opened new IndexOutput for file:_1.fdt in index: entity.235
{code}
5) When {{NodeB}} finishes flushing the index started on 3), it removes the lock from the index, that was strangely held by {{NodeD}}
{code}
21:04:18,491 TRACE (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [BaseLuceneLock] Lock: write.lock removed for index: entity.235 from AffinityTopologyChangeAsyncTest-NodeB-33534 (was AffinityTopologyChangeAsyncTest-NodeD-30445)
21:04:18,491 TRACE (transport-thread-AffinityTopologyChangeAsyncTest-NodeB-p12-t3:[]) [IndexWriterHolder] IndexWriter closed
{code}
6) The Comit scheduler on {{NodeD}} starts to fail since it does not lock the lock anymore.
> AffinityIndexManager fails to index documents in async mode
> -----------------------------------------------------------
>
> Key: ISPN-6981
> URL: https://issues.jboss.org/browse/ISPN-6981
> Project: Infinispan
> Issue Type: Bug
> Components: Embedded Querying
> Affects Versions: 9.0.0.Alpha4
> Reporter: Gustavo Fernandes
> Assignee: Gustavo Fernandes
>
> During topology changes in async mode ("<index>.worker.execution" set to "async"), the {{AfinityIndexManager}} sometimes fails to index entries. Some of errors thrown:
> {noformat}
> 19:06:04,638 ERROR (Hibernate Search: Index updates queue processor for index entity.5-1) [LogErrorHandler] HSEARCH000058: Exception occurred
> org.apache.lucene.store.LockObtainFailedException: lock instance already assigned
> {noformat}
> {noformat}
> 18:53:59,553 ERROR (Hibernate Search: Index updates queue processor for index entity.2-1) [LuceneBackendQueueTask] HSEARCH000073: Error in
> backend
> org.apache.lucene.store.AlreadyClosedException: this IndexWriter is closed
> at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:720)
> at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:734)
> {noformat}
> {noformat}
> 18:55:31,328 ERROR (Hibernate Search: Commit Scheduler for index entity.143-1) [AffinityErrorHandler] HSEARCH000117: IOException
> on the IndexWriter
> java.io.IOException: This lock is no longer being held
> at org.infinispan.lucene.impl.BaseLuceneLock.ensureValid(BaseLuceneLock.java:89)
> at org.apache.lucene.store.LockValidatingDirectoryWrapper.createOutput(LockValidatingDirectoryWrapper.java:43)
> at org.apache.lucene.store.TrackingDirectoryWrapper.createOutput(TrackingDirectoryWrapper.java:43)
> at org.apache.lucene.codecs.lucene50.Lucene50PostingsWriter.<init>(Lucene50PostingsWriter.java:105)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.4.11#64026)
More information about the infinispan-issues
mailing list