I pushed a fix ... this was due to a concurrency bug with LUCENE-7302 where
the last indexed sequence number (as reported by IW) could increment before
an NRT reader refresh would see the change, and this made
ControlledRealTimeReopenThread angry.

Mike McCandless

http://blog.mikemccandless.com

On Sun, Jun 12, 2016 at 10:15 AM, Michael McCandless <
[email protected]> wrote:

> I'll dig.
>
> Mike McCandless
>
> http://blog.mikemccandless.com
>
> On Sun, Jun 12, 2016 at 8:25 AM, Policeman Jenkins Server <
> [email protected]> wrote:
>
>> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-master-Windows/5906/
>> Java: 32bit/jdk1.8.0_92 -server -XX:+UseG1GC
>>
>> 2 tests failed.
>> FAILED:
>> org.apache.lucene.search.TestControlledRealTimeReopenThread.testControlledRealTimeReopenThread
>>
>> Error Message:
>>
>>
>> Stack Trace:
>> java.lang.AssertionError
>>         at
>> __randomizedtesting.SeedInfo.seed([E94344495F00D8B7:16AA558AAC03F0BB]:0)
>>         at org.junit.Assert.fail(Assert.java:92)
>>         at org.junit.Assert.assertTrue(Assert.java:43)
>>         at org.junit.Assert.assertFalse(Assert.java:68)
>>         at org.junit.Assert.assertFalse(Assert.java:79)
>>         at
>> org.apache.lucene.index.ThreadedIndexingAndSearchingTestCase.runTest(ThreadedIndexingAndSearchingTestCase.java:629)
>>         at
>> org.apache.lucene.search.TestControlledRealTimeReopenThread.testControlledRealTimeReopenThread(TestControlledRealTimeReopenThread.java:68)
>>         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
>>         at
>> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
>>         at
>> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
>>         at java.lang.reflect.Method.invoke(Method.java:498)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
>>         at
>> org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
>>         at
>> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
>>         at
>> org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
>>         at
>> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
>>         at
>> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
>>         at
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>         at
>> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
>>         at
>> com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
>>         at
>> com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
>>         at
>> com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
>>         at
>> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
>>         at
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>         at
>> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
>>         at
>> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
>>         at
>> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
>>         at
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>         at
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>         at
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>         at
>> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
>>         at
>> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
>>         at
>> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
>>         at
>> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
>>         at
>> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
>>         at
>> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
>>         at java.lang.Thread.run(Thread.java:745)
>>
>>
>> FAILED:
>> junit.framework.TestSuite.org.apache.lucene.search.TestControlledRealTimeReopenThread
>>
>> Error Message:
>> 2 threads leaked from SUITE scope at
>> org.apache.lucene.search.TestControlledRealTimeReopenThread:     1)
>> Thread[id=320, name=NRTDeletes Reopen Thread, state=TIMED_WAITING,
>> group=TGRP-TestControlledRealTimeReopenThread]         at
>> sun.misc.Unsafe.park(Native Method)         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>    at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>        at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>   2) Thread[id=321, name=NRTNoDeletes Reopen Thread, state=TIMED_WAITING,
>> group=TGRP-TestControlledRealTimeReopenThread]         at
>> sun.misc.Unsafe.park(Native Method)         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>    at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>        at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>
>> Stack Trace:
>> com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from
>> SUITE scope at org.apache.lucene.search.TestControlledRealTimeReopenThread:
>>    1) Thread[id=320, name=NRTDeletes Reopen Thread, state=TIMED_WAITING,
>> group=TGRP-TestControlledRealTimeReopenThread]
>>         at sun.misc.Unsafe.park(Native Method)
>>         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>         at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>         at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>    2) Thread[id=321, name=NRTNoDeletes Reopen Thread,
>> state=TIMED_WAITING, group=TGRP-TestControlledRealTimeReopenThread]
>>         at sun.misc.Unsafe.park(Native Method)
>>         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>         at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>         at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>         at __randomizedtesting.SeedInfo.seed([E94344495F00D8B7]:0)
>>
>>
>>
>>
>> Build Log:
>> [...truncated 484 lines...]
>>    [junit4] Suite:
>> org.apache.lucene.search.TestControlledRealTimeReopenThread
>>    [junit4] IGNOR/A 0.00s J0 |
>> TestControlledRealTimeReopenThread.testCRTReopen
>>    [junit4]    > Assumption #1: 'awaitsfix' test group is disabled
>> (@AwaitsFix(bugUrl=https://issues.apache.org/jira/browse/LUCENE-5737))
>>    [junit4]   1> packID=0: expected 6 hits but got 0
>>    [junit4]   1> doc id=12 is not supposed to be deleted, but got
>> hitCount=0; delIDs=[]
>>    [junit4]   1> doc id=13 is not supposed to be deleted, but got
>> hitCount=0; delIDs=[]
>>    [junit4]   1> doc id=14 is not supposed to be deleted, but got
>> hitCount=0; delIDs=[]
>>    [junit4]   1> doc id=15 is not supposed to be deleted, but got
>> hitCount=0; delIDs=[]
>>    [junit4]   1> doc id=16 is not supposed to be deleted, but got
>> hitCount=0; delIDs=[]
>>    [junit4]   1> doc id=17 is not supposed to be deleted, but got
>> hitCount=0; delIDs=[]
>>    [junit4]   2> NOTE: reproduce with: ant test
>> -Dtestcase=TestControlledRealTimeReopenThread
>> -Dtests.method=testControlledRealTimeReopenThread
>> -Dtests.seed=E94344495F00D8B7 -Dtests.slow=true -Dtests.locale=hr-HR
>> -Dtests.timezone=Asia/Kamchatka -Dtests.asserts=true
>> -Dtests.file.encoding=Cp1252
>>    [junit4] FAILURE 1.11s J0 |
>> TestControlledRealTimeReopenThread.testControlledRealTimeReopenThread <<<
>>    [junit4]    > Throwable #1: java.lang.AssertionError
>>    [junit4]    >        at
>> __randomizedtesting.SeedInfo.seed([E94344495F00D8B7:16AA558AAC03F0BB]:0)
>>    [junit4]    >        at
>> org.apache.lucene.index.ThreadedIndexingAndSearchingTestCase.runTest(ThreadedIndexingAndSearchingTestCase.java:629)
>>    [junit4]    >        at
>> org.apache.lucene.search.TestControlledRealTimeReopenThread.testControlledRealTimeReopenThread(TestControlledRealTimeReopenThread.java:68)
>>    [junit4]    >        at java.lang.Thread.run(Thread.java:745)
>>    [junit4]   2> NOTE: leaving temporary files on disk at:
>> C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build\core\test\J0\temp\lucene.search.TestControlledRealTimeReopenThread_E94344495F00D8B7-001
>>    [junit4]   2> Jun 12, 2016 12:20:39 PM
>> com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
>>    [junit4]   2> WARNING: Will linger awaiting termination of 3 leaked
>> thread(s).
>>    [junit4]   2> Jun 12, 2016 12:20:59 PM
>> com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
>>    [junit4]   2> SEVERE: 2 threads leaked from SUITE scope at
>> org.apache.lucene.search.TestControlledRealTimeReopenThread:
>>    [junit4]   2>    1) Thread[id=320, name=NRTDeletes Reopen Thread,
>> state=TIMED_WAITING, group=TGRP-TestControlledRealTimeReopenThread]
>>    [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
>>    [junit4]   2>         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>    [junit4]   2>         at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>    [junit4]   2>         at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>    [junit4]   2>    2) Thread[id=321, name=NRTNoDeletes Reopen Thread,
>> state=TIMED_WAITING, group=TGRP-TestControlledRealTimeReopenThread]
>>    [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
>>    [junit4]   2>         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>    [junit4]   2>         at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>    [junit4]   2>         at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>    [junit4]   2> Jun 12, 2016 12:20:59 PM
>> com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
>>    [junit4]   2> INFO: Starting to interrupt leaked threads:
>>    [junit4]   2>    1) Thread[id=320, name=NRTDeletes Reopen Thread,
>> state=TIMED_WAITING, group=TGRP-TestControlledRealTimeReopenThread]
>>    [junit4]   2>    2) Thread[id=321, name=NRTNoDeletes Reopen Thread,
>> state=TIMED_WAITING, group=TGRP-TestControlledRealTimeReopenThread]
>>    [junit4]   2> Jun 12, 2016 12:20:59 PM
>> com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
>>    [junit4]   2> INFO: All leaked threads terminated.
>>    [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62):
>> {date=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
>> packID=FSTOrd50,
>> test=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
>> extra29=PostingsFormat(name=MockRandom),
>> docid=PostingsFormat(name=Asserting),
>> titleTokenized=PostingsFormat(name=MockRandom),
>> body=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))),
>> title=FSTOrd50}, docValues:{docid_intDV=DocValuesFormat(name=Asserting),
>> titleDV=DocValuesFormat(name=Lucene54)}, maxPointsInLeafNode=545,
>> maxMBSortInHeap=5.1444126460701405, sim=ClassicSimilarity, locale=hr-HR,
>> timezone=Asia/Kamchatka
>>    [junit4]   2> NOTE: Windows 10 10.0 x86/Oracle Corporation 1.8.0_92
>> (32-bit)/cpus=3,threads=1,free=189693504,total=306184192
>>    [junit4]   2> NOTE: All tests run in this JVM: [TestBinaryDocument,
>> TestIndexWriterForceMerge, TestDocValuesScoring, TestCollectionUtil,
>> TestSumDocFreq, TestMultiDocValues, TestStringHelper,
>> TestMultiTermQueryRewrites, FiniteStringsIteratorTest, Test2BPagedBytes,
>> TestQueryBuilder, TestSortedNumericSortField, TestOrdinalMap,
>> TestIndexWriterOnVMError, TestIndexWriterDeleteByQuery, TestDateSort,
>> TestMSBRadixSorter, TestBooleanCoord, TestPhrasePrefixQuery,
>> TestSpanNotQuery, TestPagedBytes, TestWildcardRandom, TestMinShouldMatch2,
>> TestBasics, TestClassicSimilarity, TestSimpleExplanationsWithFillerDocs,
>> TestRecyclingByteBlockAllocator, TestManyFields,
>> TestBinaryDocValuesUpdates, TestCheckIndex, TestMixedDocValuesUpdates,
>> TestMergePolicyWrapper, TestIOUtils, TestBlockPostingsFormat3,
>> TestSmallFloat, TestBoostQuery, TestRollingUpdates, TestSimilarityBase,
>> TestSetOnce, TestBinaryTerms, TestSimpleFSDirectory,
>> TestDeterminizeLexicon, TestNGramPhraseQuery, TestParallelTermEnum,
>> TestBagOfPositions, TestDocsAndPositions, TestTermsEnum,
>> TestAttributeSource, TestSortedSetSortField, TestSpanTermQuery,
>> TestLucene50TermVectorsFormat, TestRecyclingIntBlockAllocator,
>> TestSpanExplanationsOfNonMatches, Test2BPositions, TestBagOfPostings,
>> TestConstantScoreQuery, TestSpanExplanations,
>> TestControlledRealTimeReopenThread]
>>    [junit4]   2> NOTE: reproduce with: ant test
>> -Dtestcase=TestControlledRealTimeReopenThread -Dtests.seed=E94344495F00D8B7
>> -Dtests.slow=true -Dtests.locale=hr-HR -Dtests.timezone=Asia/Kamchatka
>> -Dtests.asserts=true -Dtests.file.encoding=Cp1252
>>    [junit4] ERROR   0.00s J0 | TestControlledRealTimeReopenThread (suite)
>> <<<
>>    [junit4]    > Throwable #1:
>> com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from
>> SUITE scope at org.apache.lucene.search.TestControlledRealTimeReopenThread:
>>    [junit4]    >    1) Thread[id=320, name=NRTDeletes Reopen Thread,
>> state=TIMED_WAITING, group=TGRP-TestControlledRealTimeReopenThread]
>>    [junit4]    >         at sun.misc.Unsafe.park(Native Method)
>>    [junit4]    >         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>    [junit4]    >         at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>    [junit4]    >         at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>    [junit4]    >    2) Thread[id=321, name=NRTNoDeletes Reopen Thread,
>> state=TIMED_WAITING, group=TGRP-TestControlledRealTimeReopenThread]
>>    [junit4]    >         at sun.misc.Unsafe.park(Native Method)
>>    [junit4]    >         at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
>>    [junit4]    >         at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
>>    [junit4]    >         at
>> org.apache.lucene.search.ControlledRealTimeReopenThread.run(ControlledRealTimeReopenThread.java:215)
>>    [junit4]    >        at
>> __randomizedtesting.SeedInfo.seed([E94344495F00D8B7]:0)
>>    [junit4] Completed [83/426 (1!)] on J0 in 21.28s, 5 tests, 1 failure,
>> 1 error, 1 skipped <<< FAILURES!
>>
>> [...truncated 1151 lines...]
>> BUILD FAILED
>> C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:740: The
>> following error occurred while executing this line:
>> C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:684: The
>> following error occurred while executing this line:
>> C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\build.xml:59: The
>> following error occurred while executing this line:
>> C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\build.xml:50:
>> The following error occurred while executing this line:
>> C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:1427:
>> The following error occurred while executing this line:
>> C:\Users\jenkins\workspace\Lucene-Solr-master-Windows\lucene\common-build.xml:984:
>> There were test failures: 426 suites (1 ignored), 3644 tests, 1 suite-level
>> error, 1 failure, 74 ignored (70 assumptions) [seed: E94344495F00D8B7]
>>
>> Total time: 6 minutes 53 seconds
>> Build step 'Invoke Ant' marked build as failure
>> Archiving artifacts
>> [WARNINGS] Skipping publisher since build result is FAILURE
>> Recording test results
>> Email was triggered for: Failure - Any
>> Sending email for trigger: Failure - Any
>>
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: [email protected]
>> For additional commands, e-mail: [email protected]
>>
>
>

Reply via email to