Lucene - Core
  1. Lucene - Core
  2. LUCENE-3028

IW.getReader() returns inconsistent reader on RT Branch

    Details

    • Type: Bug Bug
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: Realtime Branch
    • Fix Version/s: Realtime Branch
    • Component/s: core/index
    • Labels:
      None
    • Lucene Fields:
      New, Patch Available

      Description

      I extended the testcase TestRollingUpdates#testUpdateSameDoc to pull a NRT reader after each update and asserted that is always sees only one document. Yet, this fails with current branch since there is a problem in how we flush in the getReader() case. What happens here is that we flush all threads and then release the lock (letting other flushes which came in after we entered the flushAllThread context, continue) so that we could concurrently get a new segment that transports global deletes without the corresponding add. They sneak in while we continue to open the NRT reader which in turn sees inconsistent results.

      I will upload a patch soon

      1. realtime-1.txt
        47 kB
        selckin
      2. LUCENE-3028.patch
        22 kB
        Simon Willnauer
      3. LUCENE-3028.patch
        22 kB
        Simon Willnauer

        Issue Links

          Activity

          Simon Willnauer created issue -
          Simon Willnauer made changes -
          Field Original Value New Value
          Attachment LUCENE-3028.patch [ 12476321 ]
          Simon Willnauer made changes -
          Comment [ here is a first patch ]
          Simon Willnauer made changes -
          Attachment LUCENE-3028.patch [ 12476321 ]
          Hide
          Simon Willnauer added a comment -

          here is a first patch

          Show
          Simon Willnauer added a comment - here is a first patch
          Simon Willnauer made changes -
          Attachment LUCENE-3028.patch [ 12476322 ]
          Hide
          Simon Willnauer added a comment -

          next iteration, edited some asserts in DW

          Show
          Simon Willnauer added a comment - next iteration, edited some asserts in DW
          Simon Willnauer made changes -
          Attachment LUCENE-3028.patch [ 12476325 ]
          Simon Willnauer made changes -
          Link This issue blocks LUCENE-2324 [ LUCENE-2324 ]
          Hide
          Simon Willnauer added a comment -

          I will commit this latest patch to the branch we can still iterates but since we have jenkins running builds I want to let that sink a bit too....

          simon

          Show
          Simon Willnauer added a comment - I will commit this latest patch to the branch we can still iterates but since we have jenkins running builds I want to let that sink a bit too.... simon
          Hide
          selckin added a comment -

          Seems to fail once every 6-8 runs quite consistently (at least i think this is the issue)

          brachnes/realtime_search r1092329

          {{
          [junit] Testsuite: org.apache.lucene.index.TestRollingUpdates
          [junit] Testcase: testUpdateSameDoc(org.apache.lucene.index.TestRollingUpdates): Caused an ERROR
          [junit] MockDirectoryWrapper: cannot close: there are still open files: {_ho.fdt=1, _ho.prx=1, _ho.fdx=1, _ho.nrm=1, _j0.fdt=1, _ho.tis=1, _j0.fdx=1, _j0.tis=1, _j0.prx=1, _ho.frq=1, _ho.tvx=1, _ho.tvd=1, _j0.nrm=1, _ho.tvf=1, _j0.frq=1, _j0.tvf=1, _j0.tvd=1, _j0.tvx=1}
          [junit] java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still open files: {_ho.fdt=1, _ho.prx=1, _ho.fdx=1, _ho.nrm=1, _j0.fdt=1, _ho.tis=1, _j0.fdx=1, _j0.tis=1, _j0.prx=1, _ho.frq=1, _ho.tvx=1, _ho.tvd=1, _j0.nrm=1, _ho.tvf=1, _j0.frq=1, _j0.tvf=1
          , _j0.tvd=1, _j0.tvx=1}
          [junit] at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:414)
          [junit] at org.apache.lucene.index.TestRollingUpdates.testUpdateSameDoc(TestRollingUpdates.java:104)
          [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1226)
          [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1154)
          [junit] Caused by: java.lang.RuntimeException: unclosed IndexInput
          [junit] at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:369)
          [junit] at org.apache.lucene.store.Directory.openInput(Directory.java:122)
          [junit] at org.apache.lucene.index.TermVectorsReader.<init>(TermVectorsReader.java:86)
          [junit] at org.apache.lucene.index.SegmentReader$CoreReaders.openDocStores(SegmentReader.java:236)
          [junit] at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:495)
          [junit] at org.apache.lucene.index.IndexWriter$ReaderPool.get(IndexWriter.java:629)
          [junit] at org.apache.lucene.index.IndexWriter$ReaderPool.getReadOnlyClone(IndexWriter.java:587)
          [junit] at org.apache.lucene.index.DirectoryReader.<init>(DirectoryReader.java:172)
          [junit] at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:377)
          [junit] at org.apache.lucene.index.DirectoryReader.doReopenFromWriter(DirectoryReader.java:419)
          [junit] at org.apache.lucene.index.DirectoryReader.doReopen(DirectoryReader.java:432)
          [junit] at org.apache.lucene.index.DirectoryReader.reopen(DirectoryReader.java:392)
          [junit] at org.apache.lucene.index.TestRollingUpdates$IndexingThread.run(TestRollingUpdates.java:129)
          [junit]
          [junit]
          [junit] Testcase: testUpdateSameDoc(org.apache.lucene.index.TestRollingUpdates): FAILED
          [junit] Some threads threw uncaught exceptions!
          [junit] junit.framework.AssertionFailedError: Some threads threw uncaught exceptions!
          [junit] at org.apache.lucene.util.LuceneTestCase.tearDown(LuceneTestCase.java:521)
          [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1226)
          [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1154)
          [junit]
          [junit]
          [junit] Tests run: 2, Failures: 1, Errors: 1, Time elapsed: 6.649 sec
          [junit]
          [junit] ------------- Standard Error -----------------
          [junit] NOTE: reproduce with: ant test -Dtestcase=TestRollingUpdates -Dtestmethod=testUpdateSameDoc -Dtests.seed=-4094951767438954769:-1203905293622856057
          [junit] NOTE: reproduce with: ant test -Dtestcase=TestRollingUpdates -Dtestmethod=testUpdateSameDoc -Dtests.seed=-4094951767438954769:-1203905293622856057
          [junit] The following exceptions were thrown by threads:
          [junit] *** Thread: Thread-103 ***
          [junit] java.lang.AssertionError: expected: org.apache.lucene.index.DocumentsWriterDeleteQueue@18635827but was: org.apache.lucene.index.DocumentsWriterDeleteQueue@223074f3 false
          [junit] at org.apache.lucene.index.DocumentsWriter.doFlush(DocumentsWriter.java:359)
          [junit] at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:346)
          [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1367)
          [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1339)
          [junit] at org.apache.lucene.index.TestRollingUpdates$IndexingThread.run(TestRollingUpdates.java:125)
          [junit] *** Thread: Thread-106 ***
          [junit] java.lang.AssertionError: expected: org.apache.lucene.index.DocumentsWriterDeleteQueue@18635827but was: org.apache.lucene.index.DocumentsWriterDeleteQueue@223074f3 false
          [junit] at org.apache.lucene.index.DocumentsWriter.doFlush(DocumentsWriter.java:359)
          [junit] at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:346)
          [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1367)
          [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1339)
          [junit] at org.apache.lucene.index.TestRollingUpdates$IndexingThread.run(TestRollingUpdates.java:125)
          [junit] NOTE: test params are: codec=PreFlex, locale=th, timezone=America/St_Kitts
          [junit] NOTE: all tests run in this JVM:
          [junit] [TestSearch, TestCharTermAttributeImpl, TestCheckIndex, TestConsistentFieldNumbers, TestCrash, TestDeletionPolicy, TestDocumentWriter, TestIndexReaderCloneNorms, TestLongPostings, TestPayloads, TestPerFieldCodecSupport, TestRollingUpdates]
          [junit] NOTE: Linux 2.6.37-gentoo amd64/Sun Microsystems Inc. 1.6.0_24 (64-bit)/cpus=8,threads=1,free=45768760,total=246743040
          [junit] ------------- ---------------- ---------------
          [junit] TEST org.apache.lucene.index.TestRollingUpdates FAILED
          }}

          Show
          selckin added a comment - Seems to fail once every 6-8 runs quite consistently (at least i think this is the issue) brachnes/realtime_search r1092329 {{ [junit] Testsuite: org.apache.lucene.index.TestRollingUpdates [junit] Testcase: testUpdateSameDoc(org.apache.lucene.index.TestRollingUpdates): Caused an ERROR [junit] MockDirectoryWrapper: cannot close: there are still open files: {_ho.fdt=1, _ho.prx=1, _ho.fdx=1, _ho.nrm=1, _j0.fdt=1, _ho.tis=1, _j0.fdx=1, _j0.tis=1, _j0.prx=1, _ho.frq=1, _ho.tvx=1, _ho.tvd=1, _j0.nrm=1, _ho.tvf=1, _j0.frq=1, _j0.tvf=1, _j0.tvd=1, _j0.tvx=1} [junit] java.lang.RuntimeException: MockDirectoryWrapper: cannot close: there are still open files: {_ho.fdt=1, _ho.prx=1, _ho.fdx=1, _ho.nrm=1, _j0.fdt=1, _ho.tis=1, _j0.fdx=1, _j0.tis=1, _j0.prx=1, _ho.frq=1, _ho.tvx=1, _ho.tvd=1, _j0.nrm=1, _ho.tvf=1, _j0.frq=1, _j0.tvf=1 , _j0.tvd=1, _j0.tvx=1} [junit] at org.apache.lucene.store.MockDirectoryWrapper.close(MockDirectoryWrapper.java:414) [junit] at org.apache.lucene.index.TestRollingUpdates.testUpdateSameDoc(TestRollingUpdates.java:104) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1226) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1154) [junit] Caused by: java.lang.RuntimeException: unclosed IndexInput [junit] at org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:369) [junit] at org.apache.lucene.store.Directory.openInput(Directory.java:122) [junit] at org.apache.lucene.index.TermVectorsReader.<init>(TermVectorsReader.java:86) [junit] at org.apache.lucene.index.SegmentReader$CoreReaders.openDocStores(SegmentReader.java:236) [junit] at org.apache.lucene.index.SegmentReader.get(SegmentReader.java:495) [junit] at org.apache.lucene.index.IndexWriter$ReaderPool.get(IndexWriter.java:629) [junit] at org.apache.lucene.index.IndexWriter$ReaderPool.getReadOnlyClone(IndexWriter.java:587) [junit] at org.apache.lucene.index.DirectoryReader.<init>(DirectoryReader.java:172) [junit] at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:377) [junit] at org.apache.lucene.index.DirectoryReader.doReopenFromWriter(DirectoryReader.java:419) [junit] at org.apache.lucene.index.DirectoryReader.doReopen(DirectoryReader.java:432) [junit] at org.apache.lucene.index.DirectoryReader.reopen(DirectoryReader.java:392) [junit] at org.apache.lucene.index.TestRollingUpdates$IndexingThread.run(TestRollingUpdates.java:129) [junit] [junit] [junit] Testcase: testUpdateSameDoc(org.apache.lucene.index.TestRollingUpdates): FAILED [junit] Some threads threw uncaught exceptions! [junit] junit.framework.AssertionFailedError: Some threads threw uncaught exceptions! [junit] at org.apache.lucene.util.LuceneTestCase.tearDown(LuceneTestCase.java:521) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1226) [junit] at org.apache.lucene.util.LuceneTestCase$LuceneTestCaseRunner.runChild(LuceneTestCase.java:1154) [junit] [junit] [junit] Tests run: 2, Failures: 1, Errors: 1, Time elapsed: 6.649 sec [junit] [junit] ------------- Standard Error ----------------- [junit] NOTE: reproduce with: ant test -Dtestcase=TestRollingUpdates -Dtestmethod=testUpdateSameDoc -Dtests.seed=-4094951767438954769:-1203905293622856057 [junit] NOTE: reproduce with: ant test -Dtestcase=TestRollingUpdates -Dtestmethod=testUpdateSameDoc -Dtests.seed=-4094951767438954769:-1203905293622856057 [junit] The following exceptions were thrown by threads: [junit] *** Thread: Thread-103 *** [junit] java.lang.AssertionError: expected: org.apache.lucene.index.DocumentsWriterDeleteQueue@18635827but was: org.apache.lucene.index.DocumentsWriterDeleteQueue@223074f3 false [junit] at org.apache.lucene.index.DocumentsWriter.doFlush(DocumentsWriter.java:359) [junit] at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:346) [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1367) [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1339) [junit] at org.apache.lucene.index.TestRollingUpdates$IndexingThread.run(TestRollingUpdates.java:125) [junit] *** Thread: Thread-106 *** [junit] java.lang.AssertionError: expected: org.apache.lucene.index.DocumentsWriterDeleteQueue@18635827but was: org.apache.lucene.index.DocumentsWriterDeleteQueue@223074f3 false [junit] at org.apache.lucene.index.DocumentsWriter.doFlush(DocumentsWriter.java:359) [junit] at org.apache.lucene.index.DocumentsWriter.updateDocument(DocumentsWriter.java:346) [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1367) [junit] at org.apache.lucene.index.IndexWriter.updateDocument(IndexWriter.java:1339) [junit] at org.apache.lucene.index.TestRollingUpdates$IndexingThread.run(TestRollingUpdates.java:125) [junit] NOTE: test params are: codec=PreFlex, locale=th, timezone=America/St_Kitts [junit] NOTE: all tests run in this JVM: [junit] [TestSearch, TestCharTermAttributeImpl, TestCheckIndex, TestConsistentFieldNumbers, TestCrash, TestDeletionPolicy, TestDocumentWriter, TestIndexReaderCloneNorms, TestLongPostings, TestPayloads, TestPerFieldCodecSupport, TestRollingUpdates] [junit] NOTE: Linux 2.6.37-gentoo amd64/Sun Microsystems Inc. 1.6.0_24 (64-bit)/cpus=8,threads=1,free=45768760,total=246743040 [junit] ------------- ---------------- --------------- [junit] TEST org.apache.lucene.index.TestRollingUpdates FAILED }}
          Hide
          Simon Willnauer added a comment -

          hmm I can't even after 1k runs

          Show
          Simon Willnauer added a comment - hmm I can't even after 1k runs
          selckin made changes -
          Attachment realtime-1.txt [ 12476369 ]
          Hide
          Simon Willnauer added a comment -

          I just committed a fix for this - seems like the assert which resets the current flushing queue was at the wrong position.

          Show
          Simon Willnauer added a comment - I just committed a fix for this - seems like the assert which resets the current flushing queue was at the wrong position.
          Hide
          selckin added a comment -

          hasn't failed since above fix

          Show
          selckin added a comment - hasn't failed since above fix
          Hide
          Simon Willnauer added a comment -

          hasn't failed since above fix

          thanks for reporting back, the failure you reported was due to a reset call at the wrong position. I was allowing blocked flushed to continue before I reset the the var that ensures that the blocked flushes continue before a full flush finished.

          Show
          Simon Willnauer added a comment - hasn't failed since above fix thanks for reporting back, the failure you reported was due to a reset call at the wrong position. I was allowing blocked flushed to continue before I reset the the var that ensures that the blocked flushes continue before a full flush finished.
          Hide
          Simon Willnauer added a comment -

          fixed in RT

          Show
          Simon Willnauer added a comment - fixed in RT
          Simon Willnauer made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Resolution Fixed [ 1 ]
          Transition Time In Source Status Execution Times Last Executer Last Execution Date
          Open Open Resolved Resolved
          19d 5h 16m 1 Simon Willnauer 03/May/11 16:47

            People

            • Assignee:
              Simon Willnauer
              Reporter:
              Simon Willnauer
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development