Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-MacOSX/3039/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC

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

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([BE14B687580DC301:39950B2A5C2DB905]: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:126)
        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)




Build Log:
[...truncated 513 lines...]
   [junit4] Suite: org.apache.lucene.TestMergeSchedulerExternal
   [junit4]   1> TEST FAILED; IW infoStream output:
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.108Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 init: current segments file is "segments"; 
deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@4fd483a5
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.108Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.108Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> IW 100 [2016-02-18T08:41:26.108Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 init: create=true
   [junit4]   1> IW 100 [2016-02-18T08:41:26.108Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 
   [junit4]   1> dir=MockDirectoryWrapper(RAMDirectory@6f9049f8 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@785f410e)
   [junit4]   1> index=
   [junit4]   1> version=5.6.0
   [junit4]   1> analyzer=org.apache.lucene.analysis.MockAnalyzer
   [junit4]   1> ramBufferSizeMB=-1.0
   [junit4]   1> maxBufferedDocs=2
   [junit4]   1> maxBufferedDeleteTerms=-1
   [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.ClassicSimilarity
   [junit4]   1> mergeScheduler=MyMergeScheduler: maxThreadCount=-1, 
maxMergeCount=-1, ioThrottle=true
   [junit4]   1> default WRITE_LOCK_TIMEOUT=0
   [junit4]   1> writeLockTimeout=0
   [junit4]   1> codec=Asserting(Lucene54): {}, docValues:{}
   [junit4]   1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
   [junit4]   1> mergePolicy=[LogByteSizeMergePolicy: minMergeSize=1677721, 
mergeFactor=29, maxMergeSize=2147483648, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.0]
   [junit4]   1> 
indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@28a76779
   [junit4]   1> readerPooling=false
   [junit4]   1> perThreadHardLimitMB=1945
   [junit4]   1> useCompoundFile=false
   [junit4]   1> commitOnClose=true
   [junit4]   1> writer=org.apache.lucene.index.IndexWriter@4515341c
   [junit4]   1> 
   [junit4]   1> IW 100 [2016-02-18T08:41:26.108Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 MMapDirectory.UNMAP_SUPPORTED=true
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.12Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _0 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.12Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.12Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.124Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 4 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.153Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 28 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.157Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_0.fdx, _0_Asserting_0.doc, _0_Asserting_0.tim, _0.fdt, 
_0_Asserting_0.tip, _0.fnm]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.158Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.158Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_0 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=1 seg=_0(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2" [1 segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 1 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 1 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 initDynamicDefaults spins=false maxThreadCount=1 maxMergeCount=6
   [junit4]   1> MS 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.165Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.167Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _1 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.168Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.168Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.172Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 4 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.192Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 20 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.195Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.195Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.195Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.195Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_1_Asserting_0.tip, _1_Asserting_0.doc, _1_Asserting_0.tim, 
_1.fdx, _1.fnm, _1.fdt]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.195Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.197Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_1 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=2 seg=_1(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2" [2 segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 2 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 2 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.205Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.208Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _2 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.208Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.208Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.211Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.248Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 36 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.252Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.252Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.252Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.252Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_2.fdt, _2_Asserting_0.tip, _2.fnm, _2.fdx, _2_Asserting_0.doc, 
_2_Asserting_0.tim]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.252Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.275Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_2 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=3 seg=_2(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2" [3 segments ; isCommit 
= false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 3 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 3 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.282Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.285Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _3 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.285Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.285Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.289Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 4 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.313Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 23 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.325Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 12 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.325Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.325Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.325Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_3.fdx, _3_Asserting_0.doc, _3.fnm, _3_Asserting_0.tim, _3.fdt, 
_3_Asserting_0.tip]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.325Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.325Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_3 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=4 seg=_3(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2" [4 
segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 4 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_3(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 4 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.332Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.336Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _4 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.336Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.336Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.339Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.354Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 15 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.358Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.358Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.358Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.358Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_4.fdt, _4.fnm, _4_Asserting_0.doc, _4_Asserting_0.tim, 
_4_Asserting_0.tip, _4.fdx]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.358Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.358Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_4 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=5 seg=_4(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2" [5 segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 5 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_3(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_4(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 5 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.365Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.368Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _5 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.368Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.368Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.372Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.401Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 28 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.404Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.404Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.404Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.404Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_5.fnm, _5_Asserting_0.tip, _5.fdt, _5_Asserting_0.doc, 
_5_Asserting_0.tim, _5.fdx]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.404Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.404Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_5 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=6 seg=_5(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2" [6 segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 6 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_3(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.422Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_4(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.437Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_5(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.437Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 6 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.437Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.437Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 
_5(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.437Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.44Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _6 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.44Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.44Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.444Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.459Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 15 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.463Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.463Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.463Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.463Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_6_Asserting_0.doc, _6_Asserting_0.tim, _6.fdt, _6.fnm, _6.fdx, 
_6_Asserting_0.tip]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.463Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.463Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_6 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=7 seg=_6(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2" [7 segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 7 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_3(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_4(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.474Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_5(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.487Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_6(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.487Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 7 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.487Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.487Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 
_5(5.6.0):C2 _6(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.487Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.49Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _7 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.49Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.49Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.495Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 4 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.51Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 15 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.514Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 4 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.514Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.514Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.514Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_7_Asserting_0.tip, _7.fnm, _7_Asserting_0.doc, 
_7_Asserting_0.tim, _7.fdt, _7.fdx]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.514Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.514Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_7 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=8 seg=_7(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2" [8 segments ; isCommit = 
false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 8 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_3(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_4(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_5(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_6(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_7(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 8 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 
_5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.522Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.525Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _8 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.525Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.525Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.529Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.544Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 14 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.548Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 4 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.548Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.548Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.548Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_8_Asserting_0.doc, _8_Asserting_0.tim, _8.fdx, 
_8_Asserting_0.tip, _8.fdt, _8.fnm]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.548Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.548Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_8 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=9 seg=_8(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2" [9 segments ; 
isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 9 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_3(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_4(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_5(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_6(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_7(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_8(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 9 segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 
_5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.555Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.557Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flush postings as segment _9 numDocs=2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.557Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write norms
   [junit4]   1> IW 100 [2016-02-18T08:41:26.557Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to write docValues
   [junit4]   1> IW 100 [2016-02-18T08:41:26.562Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 4 msec to finish stored fields
   [junit4]   1> IW 100 [2016-02-18T08:41:26.577Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 15 msec to write postings and finish vectors
   [junit4]   1> IW 100 [2016-02-18T08:41:26.581Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 3 msec to write fieldInfos
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.581Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has 0 deleted docs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.581Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 new segment has no vectors; no norms; no docValues; no prox; no freqs
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.581Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushedFiles=[_9.fdx, _9.fdt, _9.fnm, _9_Asserting_0.doc, _9_Asserting_0.tim, 
_9_Asserting_0.tip]
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.581Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed codec=Asserting(Lucene54): {id=PostingsFormat(name=Asserting)}, 
docValues:{}
   [junit4]   1> DWPT 100 [2016-02-18T08:41:26.581Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 flushed: segment=_9 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,000.217
   [junit4]   1> DW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment seg-private updates=null
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publishFlushedSegment
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 publish sets newSegment delGen=10 seg=_9(5.6.0):C2
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now checkpoint "_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2" 
[10 segments ; isCommit = false]
   [junit4]   1> IFD 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 0 msec to checkpoint
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 findMerges: 10 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_0(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_1(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_2(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_3(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_4(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_5(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_6(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_7(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_8(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 seg=_9(5.6.0):C2 level=3.0503798 size=0.001 MB
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   level -1.0 to 3.0503798: 10 segments
   [junit4]   1> LMP 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   add merge=_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 
_5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2 start=0 end=10
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 add merge to pendingMerges: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 
_3(5.6.0):C2 _4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 
_9(5.6.0):C2 [total 1 pending]
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge merging= []
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_0(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_1(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_2(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_3(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_4(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_5(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_6(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_7(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_8(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 registerMerge info=_9(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 now merge
   [junit4]   1> MS 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   index: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 
_5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   consider merge _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2
   [junit4]   1> MS 100 [2016-02-18T08:41:26.586Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
     launch new thread [MyMergeThread]
   [junit4]   1> MS 100 [2016-02-18T08:41:26.59Z; MyMergeThread]:   merge 
thread: start
   [junit4]   1> IW 100 [2016-02-18T08:41:26.591Z; MyMergeThread]: now apply 
deletes for 10 merging segments
   [junit4]   1> MS 100 [2016-02-18T08:41:26.591Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
 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> BD 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: 
applyDeletes: open segment readers took 0 msec
   [junit4]   1> BD 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: 
applyDeletes: no segments; skipping
   [junit4]   1> BD 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: prune 
sis=segments: _0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 
_5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2 minGen=1 
packetCount=0
   [junit4]   1> IW 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: merge seg=_a 
_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 _5(5.6.0):C2 
_6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: now merge
   [junit4]   1>   merge=_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2
   [junit4]   1>   index=_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: merging 
_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 _4(5.6.0):C2 _5(5.6.0):C2 
_6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2
   [junit4]   1> IW 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: 
handleMergeException: merge=_0(5.6.0):C2 _1(5.6.0):C2 _2(5.6.0):C2 _3(5.6.0):C2 
_4(5.6.0):C2 _5(5.6.0):C2 _6(5.6.0):C2 _7(5.6.0):C2 _8(5.6.0):C2 _9(5.6.0):C2 
exc=java.io.IOException: now failing during merge
   [junit4]   1> IW 100 [2016-02-18T08:41:26.592Z; MyMergeThread]: hit 
exception during merge
   [junit4]   1> IW 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: hit tragic 
IOException inside merge
   [junit4]   1> IW 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: rollback
   [junit4]   1> IW 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: all running 
merges have aborted
   [junit4]   1> IW 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: rollback: 
done finish merges
   [junit4]   1> MS 100 [2016-02-18T08:41:26.593Z; 
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[BE14B687580DC301]]:
   no more merges pending; now return
   [junit4]   1> DW 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: abort
   [junit4]   1> DW 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: done abort 
success=true
   [junit4]   1> IW 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: rollback: 
infos=
   [junit4]   1> MS 100 [2016-02-18T08:41:26.593Z; MyMergeThread]: 
updateMergeThreads ioThrottle=true targetMBPerSec=20.0 MB/sec
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TestMergeSchedulerExternal 
-Dtests.method=testSubclassConcurrentMergeScheduler 
-Dtests.seed=BE14B687580DC301 -Dtests.slow=true -Dtests.locale=es-PR 
-Dtests.timezone=Asia/Phnom_Penh -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] FAILURE 0.55s J1 | 
TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([BE14B687580DC301:39950B2A5C2DB905]:0)
   [junit4]    >        at 
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler(TestMergeSchedulerExternal.java:126)
   [junit4]    >        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene54): 
{id=PostingsFormat(name=Asserting)}, docValues:{}, sim=DefaultSimilarity, 
locale=es-PR, timezone=Asia/Phnom_Penh
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_72 
(64-bit)/cpus=3,threads=1,free=101265472,total=218628096
   [junit4]   2> NOTE: All tests run in this JVM: [TestLongBitSet, 
TestSegmentTermEnum, TestSparseFixedBitSet, TestLucene50SegmentInfoFormat, 
TestSimpleExplanations, TestStressAdvance, TestExternalCodecs, 
TestNumericRangeQuery64, TestRegExp, TestIndexReaderClose, TestDirectory, 
TestFieldValueQuery, TestBitDocIdSetBuilder, TestSortedSetSortField, 
TestCachingWrapperFilter, TestCharFilter, TestSimilarity2, 
TestDocTermOrdsRewriteMethod, TestCodecs, TestSortedNumericSortField, 
TestRecyclingIntBlockAllocator, TestSpansAdvanced, TestIndexWriterMergePolicy, 
TestNRTCachingDirectory, TestBooleanOr, TestByteArrayDataInput, 
TestIndexWriterForceMerge, TestBinaryDocValuesUpdates, 
TestConsistentFieldNumbers, TestFilterSpans, TestLevenshteinAutomata, 
TestDocValues, TestBagOfPositions, TestSpanMultiTermQueryWrapper, 
TestSleepingLockWrapper, TestRamUsageEstimator, TestSearcherManager, 
TestFixedBitSet, TestSentinelIntSet, TestAutomaton, Test2BSortedDocValuesOrds, 
TestMergeSchedulerExternal]
   [junit4] Completed [95/421 (1!)] on J1 in 0.59s, 2 tests, 1 failure <<< 
FAILURES!

[...truncated 1060 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:750: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:694: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:59: The following 
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/lucene/build.xml:50: The 
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/lucene/common-build.xml:1477: 
The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/lucene/common-build.xml:1033: 
There were test failures: 421 suites (1 ignored), 3386 tests, 1 failure, 48 
ignored (44 assumptions) [seed: BE14B687580DC301]

Total time: 7 minutes 18 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