Uploaded image for project: 'Lucene - Core'
  1. Lucene - Core
  2. LUCENE-9473

TestIndexWriterDelete#testDeleteAllNoDeadLock fails sometimes on nightly

Details

    • Test
    • Status: Closed
    • Major
    • Resolution: Fixed
    • None
    • 9.0, 8.7
    • None
    • None
    • New

    Description

      2> NOTE: reproduce with: ant test  -Dtestcase=TestIndexWriterDelete -Dtests.method=testDeleteAllNoDeadLock -Dtests.seed=E595F5BCCD45156B -Dtests.nightly=true -Dtests.slow=true -Dtests.badapples=true -Dtests.linedocsfile=/l/simon/lucene/test-framework/src/resources/org/apache/lucene/util/2000mb.txt.gz -Dtests.locale=da-DK -Dtests.timezone=SST -Dtests.asserts=true -Dtests.file.encoding=UTF-8
        2> aug. 19, 2020 8:24:20 PM com.carrotsearch.randomizedtesting.RandomizedRunner$QueueUncaughtExceptionsHandler uncaughtException
        2> WARNING: Uncaught exception in thread: Thread[Thread-8,5,TGRP-TestIndexWriterDelete]
        2> java.lang.RuntimeException: org.apache.lucene.store.AlreadyClosedException: this DocumentsWriter is closed
        2> 	at __randomizedtesting.SeedInfo.seed([E595F5BCCD45156B]:0)
        2> 	at org.apache.lucene.index.TestIndexWriterDelete$1.run(TestIndexWriterDelete.java:332)
        2> Caused by: org.apache.lucene.store.AlreadyClosedException: this DocumentsWriter is closed
        2> 	at org.apache.lucene.index.DocumentsWriter.ensureOpen(DocumentsWriter.java:202)
        2> 	at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:416)
        2> 	at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1470)
        2> 	at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1756)
        2> 	at org.apache.lucene.index.IndexWriter.addDocument(IndexWriter.java:1399)
        2> 	at org.apache.lucene.index.RandomIndexWriter.addDocument(RandomIndexWriter.java:193)
        2> 	at org.apache.lucene.index.TestIndexWriterDelete$1.run(TestIndexWriterDelete.java:326)
        2> 
        2> aug. 19, 2020 8:24:20 PM com.carrotsearch.randomizedtesting.RandomizedRunner$QueueUncaughtExceptionsHandler uncaughtException
        2> WARNING: Uncaught exception in thread: Thread[Thread-7,5,TGRP-TestIndexWriterDelete]
        2> java.lang.RuntimeException: org.apache.lucene.store.AlreadyClosedException: DWPTPool is already closed
        2> 	at __randomizedtesting.SeedInfo.seed([E595F5BCCD45156B]:0)
        2> 	at org.apache.lucene.index.TestIndexWriterDelete$1.run(TestIndexWriterDelete.java:332)
        2> Caused by: org.apache.lucene.store.AlreadyClosedException: DWPTPool is already closed
        2> 	at org.apache.lucene.index.DocumentsWriterPerThreadPool.ensureOpen(DocumentsWriterPerThreadPool.java:134)
        2> 	at org.apache.lucene.index.DocumentsWriterPerThreadPool.newWriter(DocumentsWriterPerThreadPool.java:102)
        2> 	at org.apache.lucene.index.DocumentsWriterPerThreadPool.getAndLock(DocumentsWriterPerThreadPool.java:128)
        2> 	at org.apache.lucene.index.DocumentsWriterFlushControl.obtainAndLock(DocumentsWriterFlushControl.java:445)
        2> 	at org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:409)
        2> 	at org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1470)
        2> 	at org.apache.lucene.index.IndexWriter.addDocuments(IndexWriter.java:1443)
        2> 	at org.apache.lucene.index.RandomIndexWriter.addDocument(RandomIndexWriter.java:163)
        2> 	at org.apache.lucene.index.TestIndexWriterDelete$1.run(TestIndexWriterDelete.java:326)
        2> 
        2> aug. 19, 2020 8:24:20 PM com.carrotsearch.randomizedtesting.RandomizedRunner$QueueUncaughtExceptionsHandler uncaughtException
        2> WARNING: Uncaught exception in thread: Thread[Lucene Merge Thread #9,5,TGRP-TestIndexWriterDelete]
        2> org.apache.lucene.index.MergePolicy$MergeException: org.apache.lucene.index.CorruptIndexException: Problem reading index. (resource=_di.cfe)
        2> 	at __randomizedtesting.SeedInfo.seed([E595F5BCCD45156B]:0)
        2> 	at org.apache.lucene.index.ConcurrentMergeScheduler.handleMergeException(ConcurrentMergeScheduler.java:703)
        2> 	at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:694)
        2> Caused by: org.apache.lucene.index.CorruptIndexException: Problem reading index. (resource=_di.cfe)
        2> 	at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:144)
        2> 	at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:83)
        2> 	at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:171)
        2> 	at org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:714)
        2> 	at org.apache.lucene.index.IndexWriter.lambda$mergeMiddle$16(IndexWriter.java:4672)
        2> 	at org.apache.lucene.index.MergePolicy$OneMerge.initMergeReaders(MergePolicy.java:438)
        2> 	at org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4669)
        2> 	at org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4329)
        2> 	at org.apache.lucene.index.IndexWriter$IndexWriterMergeSource.merge(IndexWriter.java:5880)
        2> 	at org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:624)
        2> 	at org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:682)
        2> Caused by: java.nio.file.NoSuchFileException: _di.cfe
        2> 	at org.apache.lucene.store.ByteBuffersDirectory.openInput(ByteBuffersDirectory.java:222)
        2> 	at org.apache.lucene.store.Directory.openChecksumInput(Directory.java:157)
        2> 	at org.apache.lucene.store.RawDirectoryWrapper.openChecksumInput(RawDirectoryWrapper.java:41)
        2> 	at org.apache.lucene.codecs.lucene50.Lucene50CompoundReader.readEntries(Lucene50CompoundReader.java:104)
        2> 	at org.apache.lucene.codecs.lucene50.Lucene50CompoundReader.<init>(Lucene50CompoundReader.java:68)
        2> 	at org.apache.lucene.codecs.lucene50.Lucene50CompoundFormat.getCompoundReader(Lucene50CompoundFormat.java:71)
        2> 	at org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:101)
        2> 	... 10 more
      
      

      I have a good idea of what's happening here and I can reproduce in 1 out of 10 iterations with a forced MockRandomMP. It seems like I introduced this race in LUCENE-9309

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              simonw Simon Willnauer
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 50m
                  50m