Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/510/

1 tests failed.
FAILED:  
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([26CD22D4A2A7ACB8:A14C9F79A687D6BC]:0)
        at org.junit.Assert.fail(Assert.java:92)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at org.junit.Assert.assertTrue(Assert.java:54)
        at 
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler(TestMergeSchedulerExternal.java:147)
        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:1737)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
        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:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
        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:368)
        at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 398 lines...]
   [junit4] Suite: org.apache.lucene.TestMergeSchedulerExternal
   [junit4]   1> TEST FAILED; IW infoStream output:
   [junit4]   1> IFD 0 [2018-03-16T20:27:24.158Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 init: current segments file is "segments"; 
deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@668b20b6
   [junit4]   1> IFD 0 [2018-03-16T20:27:24.328Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:24.328Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> IW 0 [2018-03-16T20:27:24.328Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 init: create=true
   [junit4]   1> IW 0 [2018-03-16T20:27:24.328Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 
   [junit4]   1> dir=MockDirectoryWrapper(RAMDirectory@74fbcb1 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@242c9cde)
   [junit4]   1> index=
   [junit4]   1> version=7.4.0
   [junit4]   1> analyzer=org.apache.lucene.analysis.MockAnalyzer
   [junit4]   1> ramBufferSizeMB=-1.0
   [junit4]   1> maxBufferedDocs=2
   [junit4]   1> mergedSegmentWarmer=null
   [junit4]   1> 
delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
   [junit4]   1> commit=null
   [junit4]   1> openMode=CREATE_OR_APPEND
   [junit4]   1> 
similarity=org.apache.lucene.search.similarities.RandomSimilarity
   [junit4]   1> mergeScheduler=MyMergeScheduler: maxThreadCount=-1, 
maxMergeCount=-1, ioThrottle=true
   [junit4]   1> codec=Asserting(Lucene70)
   [junit4]   1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
   [junit4]   1> mergePolicy=[LogByteSizeMergePolicy: minMergeSize=1677721, 
mergeFactor=28, maxMergeSize=2147483648, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.22845321531545065]
   [junit4]   1> 
indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@6617be42
   [junit4]   1> readerPooling=false
   [junit4]   1> perThreadHardLimitMB=1945
   [junit4]   1> useCompoundFile=false
   [junit4]   1> commitOnClose=true
   [junit4]   1> indexSort=null
   [junit4]   1> checkPendingFlushOnUpdate=true
   [junit4]   1> writer=org.apache.lucene.index.IndexWriter@718450f
   [junit4]   1> 
   [junit4]   1> IW 0 [2018-03-16T20:27:24.328Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 MMapDirectory.UNMAP_SUPPORTED=true
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.440Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _0 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:24.440Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:24.440Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:24.440Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:24.477Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 36 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:24.693Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 216 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:24.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 41 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_0.fdx, _0_Asserting_0.doc, _0_Asserting_0.tim, _0.fdt, 
_0_Asserting_0.tip, _0.fnm]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.749Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_0 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.789Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 348.898532 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:24.789Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:24.789Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _0(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:24.789Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=1 now completedDelGen=1
   [junit4]   1> IW 0 [2018-03-16T20:27:24.789Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=1 seg=_0(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:24.789Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2" [1 segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:24.789Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:24.790Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 1 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:24.790Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:24.822Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 1 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:24.823Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 initDynamicDefaults spins=false maxThreadCount=1 maxMergeCount=6
   [junit4]   1> MS 0 [2018-03-16T20:27:24.823Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:24.823Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:24.823Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:24.825Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _1 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:24.825Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:24.825Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:24.825Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:24.861Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 35 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:24.997Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 135 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:25.016Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 19 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.016Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.016Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.016Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_1_Asserting_0.tip, _1_Asserting_0.doc, _1_Asserting_0.tim, 
_1.fdx, _1.fnm, _1.fdt]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.016Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.016Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_1 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 264.685392 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _1(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=2 now completedDelGen=2
   [junit4]   1> IW 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=2 seg=_1(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2" [2 segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 2 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.090Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.123Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.123Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 2 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:25.123Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:25.123Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:25.123Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.125Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _2 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:25.125Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:25.125Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:25.125Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:25.141Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 15 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:25.324Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 182 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:25.415Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 91 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.415Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.416Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.416Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_2.fdt, _2_Asserting_0.tip, _2.fnm, _2.fdx, _2_Asserting_0.doc, 
_2_Asserting_0.tim]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.416Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.598Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_2 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.705Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 580.168371 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:25.706Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:25.706Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _2(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:25.706Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=3 now completedDelGen=3
   [junit4]   1> IW 0 [2018-03-16T20:27:25.706Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=3 seg=_2(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:25.706Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2" [3 segments ; isCommit 
= false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:25.706Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.706Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 3 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.707Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.707Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.707Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.707Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 3 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:25.707Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:25.707Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:25.707Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.726Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _3 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:25.726Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:25.726Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:25.726Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:25.741Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 15 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:25.853Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 111 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:25.888Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 35 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.889Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.889Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.889Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_3.fdx, _3_Asserting_0.doc, _3.fnm, _3_Asserting_0.tim, _3.fdt, 
_3_Asserting_0.tip]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.889Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.889Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_3 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.961Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 235.387988 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:25.961Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:25.961Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _3(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:25.961Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=4 now completedDelGen=4
   [junit4]   1> IW 0 [2018-03-16T20:27:25.961Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=4 seg=_3(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:25.961Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2" [4 
segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:25.979Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 17 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.979Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 4 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_3(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 4 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:25.980Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:25.983Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _4 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:25.983Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:25.983Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:25.983Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:26.053Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 69 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:26.215Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 161 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:26.218Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 2 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.218Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.218Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.218Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_4.fdt, _4.fnm, _4_Asserting_0.doc, _4_Asserting_0.tim, 
_4_Asserting_0.tip, _4.fdx]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.218Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.218Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_4 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 286.766592 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _4(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=5 now completedDelGen=5
   [junit4]   1> IW 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=5 seg=_4(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2" [5 segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 5 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.270Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_3(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.271Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_4(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.271Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 5 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:26.271Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:26.271Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:26.271Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.290Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _5 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:26.290Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:26.290Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:26.290Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:26.305Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 15 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:26.488Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 183 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:26.508Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 19 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.508Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.508Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.508Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_5.fnm, _5_Asserting_0.tip, _5.fdt, _5_Asserting_0.doc, 
_5_Asserting_0.tim, _5.fdx]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.508Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.508Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_5 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.526Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 236.814004 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:26.526Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:26.526Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _5(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=6 now completedDelGen=6
   [junit4]   1> IW 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=6 seg=_5(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2" [6 segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 6 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.527Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_3(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.572Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_4(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.572Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_5(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.573Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 6 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:26.573Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:26.573Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 
_5(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:26.573Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.575Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _6 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:26.575Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:26.575Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:26.575Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:26.590Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 15 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:26.701Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 110 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:26.734Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 33 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_6_Asserting_0.doc, _6_Asserting_0.tim, _6.fdt, _6.fnm, _6.fdx, 
_6_Asserting_0.tip]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.735Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_6 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.757Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 182.629689 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:26.758Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:26.758Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _6(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:26.758Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=7 now completedDelGen=7
   [junit4]   1> IW 0 [2018-03-16T20:27:26.758Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=7 seg=_6(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.758Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2" [7 segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.758Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.758Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 7 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.773Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.773Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.773Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.773Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_3(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.773Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_4(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.773Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_5(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.773Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_6(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.774Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 7 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:26.774Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:26.774Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 
_5(7.4.0):C2 _6(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:26.774Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.808Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _7 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:26.808Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:26.808Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:26.808Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:26.811Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 3 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:26.867Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 56 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:26.883Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 15 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.883Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.883Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.883Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_7_Asserting_0.tip, _7.fnm, _7_Asserting_0.doc, 
_7_Asserting_0.tim, _7.fdt, _7.fdx]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.883Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.883Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_7 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.918Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 110.029186 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:26.918Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:26.918Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _7(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:26.918Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=8 now completedDelGen=8
   [junit4]   1> IW 0 [2018-03-16T20:27:26.918Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=8 seg=_7(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.918Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2" [8 segments ; isCommit = 
false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:26.920Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 1 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.920Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 8 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.920Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.920Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.920Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.920Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_3(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.937Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_4(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.937Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_5(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.937Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_6(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.937Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_7(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:26.938Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 8 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:26.938Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:26.938Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 
_5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:26.938Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:26.940Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _8 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:26.940Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:26.940Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:26.940Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:26.957Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 16 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:27.030Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 73 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:27.086Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 55 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.086Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.086Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.086Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_8_Asserting_0.doc, _8_Asserting_0.tim, _8.fdx, 
_8_Asserting_0.tip, _8.fdt, _8.fnm]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.086Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.099Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_8 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.139Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 198.72116 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:27.139Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:27.139Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _8(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:27.139Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=9 now completedDelGen=9
   [junit4]   1> IW 0 [2018-03-16T20:27:27.139Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=9 seg=_8(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:27.139Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2" [9 segments ; 
isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:27.139Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 9 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_3(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_4(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_5(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_6(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_7(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_8(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 9 segments
   [junit4]   1> MS 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 
_5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:27.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.159Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush postings as segment _9 numDocs=2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.160Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write norms
   [junit4]   1> IW 0 [2018-03-16T20:27:27.160Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write docValues
   [junit4]   1> IW 0 [2018-03-16T20:27:27.160Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to write points
   [junit4]   1> IW 0 [2018-03-16T20:27:27.191Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 31 msec to finish stored fields
   [junit4]   1> IW 0 [2018-03-16T20:27:27.248Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 56 msec to write postings and finish vectors
   [junit4]   1> IW 0 [2018-03-16T20:27:27.267Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 19 msec to write fieldInfos
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.267Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.267Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.267Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushedFiles=[_9.fdx, _9.fdt, _9.fnm, _9_Asserting_0.doc, _9_Asserting_0.tim, 
_9_Asserting_0.tip]
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.267Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed codec=Asserting(Lucene70)
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.267Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flushed: segment=_9 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,004.516
   [junit4]   1> DWPT 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 flush time 139.097118 msec
   [junit4]   1> DW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publishFlushedSegment _9(7.4.0):C2
   [junit4]   1> BD 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 finished packet delGen=10 now completedDelGen=10
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 publish sets newSegment delGen=10 seg=_9(7.4.0):C2
   [junit4]   1> IFD 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now checkpoint "_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2" 
[10 segments ; isCommit = false]
   [junit4]   1> IFD 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 0 msec to checkpoint
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 findMerges: 10 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_0(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_1(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_2(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_3(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_4(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_5(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_6(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_7(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_8(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 seg=_9(7.4.0):C2 level=3.0591846 size=0.001 MB
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   level -1.0 to 3.0591846: 10 segments
   [junit4]   1> LMP 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   add merge=_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 
_5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2 start=0 end=10
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 add merge to pendingMerges: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 
_3(7.4.0):C2 _4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 
_9(7.4.0):C2 [total 1 pending]
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge merging= []
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_0(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_1(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_2(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_3(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_4(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_5(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.299Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_6(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.300Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_7(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.300Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_8(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.300Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 registerMerge info=_9(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:27.300Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 now merge
   [junit4]   1> MS 0 [2018-03-16T20:27:27.300Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   index: _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 
_5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:27.300Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   consider merge _0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2
   [junit4]   1> MS 0 [2018-03-16T20:27:27.300Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
     launch new thread [MyMergeThread]
   [junit4]   1> MS 0 [2018-03-16T20:27:27.320Z; MyMergeThread]:   merge 
thread: start
   [junit4]   1> BD 0 [2018-03-16T20:27:27.336Z; MyMergeThread]: 
waitApplyForMerge: 0 packets, 10 merging segments
   [junit4]   1> BD 0 [2018-03-16T20:27:27.336Z; MyMergeThread]: waitApply: no 
deletes to apply
   [junit4]   1> IW 0 [2018-03-16T20:27:27.336Z; MyMergeThread]: now apply 
deletes for 10 merging segments
   [junit4]   1> IW 0 [2018-03-16T20:27:27.337Z; MyMergeThread]: merge seg=_a 
_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 _5(7.4.0):C2 
_6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.337Z; MyMergeThread]: now merge
   [junit4]   1>   merge=_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2
   [junit4]   1>   index=_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.337Z; MyMergeThread]: merging 
_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 _4(7.4.0):C2 _5(7.4.0):C2 
_6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2
   [junit4]   1> IW 0 [2018-03-16T20:27:27.338Z; MyMergeThread]: TEST: now 
throw exc:
   [junit4]   1> java.io.IOException: now failing during merge
   [junit4]   1>        at 
org.apache.lucene.TestMergeSchedulerExternal$FailOnlyOnMerge.eval(TestMergeSchedulerExternal.java:95)
   [junit4]   1>        at 
org.apache.lucene.store.MockDirectoryWrapper.maybeThrowDeterministicException(MockDirectoryWrapper.java:1022)
   [junit4]   1>        at 
org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:743)
   [junit4]   1>        at 
org.apache.lucene.store.Directory.openChecksumInput(Directory.java:119)
   [junit4]   1>        at 
org.apache.lucene.store.MockDirectoryWrapper.openChecksumInput(MockDirectoryWrapper.java:1072)
   [junit4]   1>        at 
org.apache.lucene.codecs.lucene60.Lucene60FieldInfosFormat.read(Lucene60FieldInfosFormat.java:113)
   [junit4]   1>        at 
org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:107)
   [junit4]   1>        at 
org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:78)
   [junit4]   1>        at 
org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:208)
   [junit4]   1>        at 
org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:831)
   [junit4]   1>        at 
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4487)
   [junit4]   1>        at 
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4156)
   [junit4]   1>        at 
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:624)
   [junit4]   1>        at 
org.apache.lucene.TestMergeSchedulerExternal$MyMergeScheduler.doMerge(TestMergeSchedulerExternal.java:85)
   [junit4]   1>        at 
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:661)
   [junit4]   1> 
   [junit4]   1> IW 0 [2018-03-16T20:27:27.338Z; MyMergeThread]: 
handleMergeException: merge=_0(7.4.0):C2 _1(7.4.0):C2 _2(7.4.0):C2 _3(7.4.0):C2 
_4(7.4.0):C2 _5(7.4.0):C2 _6(7.4.0):C2 _7(7.4.0):C2 _8(7.4.0):C2 _9(7.4.0):C2 
exc=java.io.IOException: now failing during merge
   [junit4]   1> IW 0 [2018-03-16T20:27:27.338Z; MyMergeThread]: hit exception 
during merge
   [junit4]   1> IW 0 [2018-03-16T20:27:27.338Z; MyMergeThread]: hit tragic 
IOException inside merge
   [junit4]   1> IW 0 [2018-03-16T20:27:27.338Z; MyMergeThread]: rollback
   [junit4]   1> IW 0 [2018-03-16T20:27:27.338Z; MyMergeThread]: all running 
merges have aborted
   [junit4]   1> IW 0 [2018-03-16T20:27:27.338Z; MyMergeThread]: rollback: done 
finish merges
   [junit4]   1> MS 0 [2018-03-16T20:27:27.375Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
 updateMergeThreads ioThrottle=true targetMBPerSec=20.0 MB/sec
   [junit4]   1> merge thread MyMergeThread estSize=0.0 MB (written=0.0 MB) 
runTime=0.0s (stopped=0.0s, paused=0.0s) rate=unlimited
   [junit4]   1>   leave running at Infinity MB/sec
   [junit4]   1> MS 0 [2018-03-16T20:27:27.375Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[26CD22D4A2A7ACB8]]:
   no more merges pending; now return
   [junit4]   1> DW 0 [2018-03-16T20:27:27.375Z; MyMergeThread]: abort
   [junit4]   1> DW 0 [2018-03-16T20:27:27.375Z; MyMergeThread]: done abort 
success=true
   [junit4]   1> IW 0 [2018-03-16T20:27:27.392Z; MyMergeThread]: rollback: 
infos=
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TestMergeSchedulerExternal 
-Dtests.method=testSubclassConcurrentMergeScheduler 
-Dtests.seed=26CD22D4A2A7ACB8 -Dtests.multiplier=2 -Dtests.slow=true 
-Dtests.locale=es-PA -Dtests.timezone=Africa/Luanda -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] FAILURE 3.51s J1 | 
TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([26CD22D4A2A7ACB8:A14C9F79A687D6BC]:0)
   [junit4]    >        at 
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler(TestMergeSchedulerExternal.java:147)
   [junit4]    >        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70), 
sim=RandomSimilarity(queryNorm=false): {}, locale=es-PA, timezone=Africa/Luanda
   [junit4]   2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 
1.8.0_152 (64-bit)/cpus=4,threads=1,free=197155896,total=318767104
   [junit4]   2> NOTE: All tests run in this JVM: [TestPerFieldDocValuesFormat, 
TestMergeSchedulerExternal]
   [junit4] Completed [46/466 (1!)] on J1 in 4.29s, 2 tests, 1 failure <<< 
FAILURES!

[...truncated 1378 lines...]
   [junit4] JVM J0: stdout was not empty, see: 
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/lucene/build/core/test/temp/junit4-J0-20180316_202527_2317600412058213441667.sysout
   [junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
   [junit4] codec: HighCompressionCompressingStoredFields, pf: BloomFilter, 
dvf: Asserting
   [junit4] <<< JVM J0: EOF ----

[...truncated 62654 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to