It failed again, and the verbosity I added makes it look more and more
like a strange Java bug where the "catch" clause doesn't run.

But I added yet more verbosity ... and we wait again.

Mike McCandless

http://blog.mikemccandless.com


On Mon, Feb 22, 2016 at 1:41 AM, Policeman Jenkins Server
<[email protected]> wrote:
> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.5-MacOSX/3/
> 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([A2BDF226D5BAFBA8:253C4F8BD19A81AC]: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:144)
>         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 1056 lines...]
>    [junit4] Suite: org.apache.lucene.TestMergeSchedulerExternal
>    [junit4]   1> TEST FAILED; IW infoStream output:
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.348Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  init: current segments file is "segments"; 
> deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@162cfd3e
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.348Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "" [0 segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.348Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.348Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  init: create=true
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.348Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    [junit4]   1> dir=MockDirectoryWrapper(RAMDirectory@8c7547a 
> lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1308524f)
>    [junit4]   1> index=
>    [junit4]   1> version=5.5.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.RandomSimilarity
>    [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=30, maxMergeSize=2147483648, 
> maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
> maxMergeDocs=2147483647, maxCFSSegmentSizeMB=0.9658203125, noCFSRatio=1.0]
>    [junit4]   1> 
> indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@585a706a
>    [junit4]   1> readerPooling=true
>    [junit4]   1> perThreadHardLimitMB=1945
>    [junit4]   1> useCompoundFile=false
>    [junit4]   1> commitOnClose=true
>    [junit4]   1> writer=org.apache.lucene.index.IndexWriter@6a0c8b9f
>    [junit4]   1>
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.348Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  MMapDirectory.UNMAP_SUPPORTED=true
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.354Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _0 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.354Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.354Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.362Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  7 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.399Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  36 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.407Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  8 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.407Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.407Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.407Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_0.fdx, _0_BlockTreeOrds_0.tio, _0_BlockTreeOrds_0.doc, 
> _0.fdt, _0_BlockTreeOrds_0.tipo, _0.fnm]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.407Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.413Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_0 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.447Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.447Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.447Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=1 seg=_0(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.447Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2" [1 segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.447Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.447Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 1 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.451Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.451Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 1 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.451Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.451Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.451Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.451Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.459Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _1 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.459Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.459Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.468Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  8 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.509Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  41 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.521Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  12 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.521Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.521Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.521Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_1_BlockTreeOrds_0.tipo, _1.fdx, _1_BlockTreeOrds_0.doc, 
> _1.fnm, _1_BlockTreeOrds_0.tio, _1.fdt]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.521Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.521Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_1 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.542Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.542Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.542Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=2 seg=_1(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.542Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2" [2 segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.542Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.542Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 2 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.542Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.543Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.543Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 2 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.543Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.543Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.543Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.548Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _2 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.548Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.548Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.556Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  7 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.586Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  29 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.592Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  6 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.592Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.592Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.592Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_2_BlockTreeOrds_0.doc, _2_BlockTreeOrds_0.tio, _2.fdt, 
> _2_BlockTreeOrds_0.tipo, _2.fnm, _2.fdx]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.592Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.593Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_2 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=3 seg=_2(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2" [3 segments ; 
> isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 3 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.607Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.609Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.609Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 3 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.609Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.609Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.609Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.614Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _3 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.614Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.614Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.622Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  7 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.652Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  29 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.664Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  12 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.664Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.664Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.664Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_3.fdx, _3_BlockTreeOrds_0.tipo, _3.fnm, _3.fdt, 
> _3_BlockTreeOrds_0.tio, _3_BlockTreeOrds_0.doc]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.664Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.666Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_3 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.684Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.684Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.684Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=4 seg=_3(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.684Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2" [4 
> segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.684Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.684Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 4 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.685Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.685Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.685Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.69Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_3(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.69Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 4 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.69Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.69Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.69Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.696Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _4 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.696Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.696Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.703Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  7 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.738Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  30 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.746Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  7 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.746Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.746Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.746Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_4.fdt, _4.fnm, _4_BlockTreeOrds_0.doc, 
> _4_BlockTreeOrds_0.tipo, _4_BlockTreeOrds_0.tio, _4.fdx]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.746Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.746Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_4 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.754Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.754Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.754Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=5 seg=_4(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.754Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2" [5 segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.755Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.755Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 5 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.755Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.755Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.755Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.755Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_3(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.762Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_4(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.762Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 5 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.762Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.762Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.762Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.766Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _5 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.766Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.766Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.77Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  4 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.79Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  19 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.797Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  6 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.797Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.797Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.797Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_5.fnm, _5.fdt, _5_BlockTreeOrds_0.tio, 
> _5_BlockTreeOrds_0.tipo, _5_BlockTreeOrds_0.doc, _5.fdx]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.797Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.799Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_5 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.812Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.812Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.812Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=6 seg=_5(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.812Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2" [6 segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.813Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.813Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 6 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.813Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.813Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.813Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.813Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_3(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.813Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_4(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.815Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_5(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.815Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 6 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.815Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.815Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 
> _5(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.815Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.821Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _6 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.821Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.821Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.828Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  7 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.858Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  29 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.866Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  7 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.866Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.866Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.866Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_6.fdt, _6.fnm, _6.fdx, _6_BlockTreeOrds_0.tipo, 
> _6_BlockTreeOrds_0.doc, _6_BlockTreeOrds_0.tio]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.866Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.875Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_6 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.894Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.894Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.894Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=7 seg=_6(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2" [7 segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 7 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_3(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_4(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_5(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_6(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 7 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 
> _5(5.5.0):C2 _6(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.895Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.898Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _7 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.898Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.898Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.907Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  8 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.932Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  25 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.937Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  4 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.937Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.937Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.937Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_7_BlockTreeOrds_0.tio, _7.fnm, _7_BlockTreeOrds_0.doc, 
> _7.fdt, _7.fdx, _7_BlockTreeOrds_0.tipo]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.937Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.937Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_7 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=8 seg=_7(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2" [8 segments ; isCommit = 
> false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 8 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_3(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_4(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_5(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_6(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_7(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 8 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 
> _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.944Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.948Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _8 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.948Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.948Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.952Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  4 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.969Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  16 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.973Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  4 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.973Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.973Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.973Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_8_BlockTreeOrds_0.tipo, _8.fdx, _8.fdt, _8.fnm, 
> _8_BlockTreeOrds_0.tio, _8_BlockTreeOrds_0.doc]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.973Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.974Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_8 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=9 seg=_8(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2" [9 segments 
> ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 9 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_3(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_4(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_5(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_6(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.981Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_7(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.982Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_8(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:21.982Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 9 segments
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.982Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.982Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 
> _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:21.982Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:21.985Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flush postings as segment _9 numDocs=2
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.986Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write norms
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.986Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to write docValues
>    [junit4]   1> IW 100 [2016-02-22T06:39:21.99Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  4 msec to finish stored fields
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.008Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  18 msec to write postings and finish vectors
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.013Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  4 msec to write fieldInfos
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:22.013Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has 0 deleted docs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:22.013Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  new segment has no vectors; no norms; no docValues; no prox; no freqs
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:22.013Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushedFiles=[_9.fdx, _9.fdt, _9.fnm, _9_BlockTreeOrds_0.tipo, 
> _9_BlockTreeOrds_0.doc, _9_BlockTreeOrds_0.tio]
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:22.013Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed codec=Asserting(Lucene54): {id=BlockTreeOrds(blocksize=128)}, 
> docValues:{}
>    [junit4]   1> DWPT 100 [2016-02-22T06:39:22.015Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  flushed: segment=_9 ramUsed=0.071 MB newFlushedSize=0.001 MB 
> docs/MB=2,884.666
>    [junit4]   1> DW 100 [2016-02-22T06:39:22.044Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment seg-private updates=null
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.044Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publishFlushedSegment
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.044Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  publish sets newSegment delGen=10 seg=_9(5.5.0):C2
>    [junit4]   1> IFD 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now checkpoint "_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 
> _9(5.5.0):C2" [10 segments ; isCommit = false]
>    [junit4]   1> IFD 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  0 msec to checkpoint
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  findMerges: 10 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_0(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_1(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_2(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_3(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_4(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_5(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_6(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_7(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.045Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_8(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.077Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  seg=_9(5.5.0):C2 level=3.0659528 size=0.001 MB
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.077Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    level -1.0 to 3.0659528: 10 segments
>    [junit4]   1> LMP 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    add merge=_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 
> _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2 start=0 
> end=10
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  add merge to pendingMerges: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 
> _3(5.5.0):C2 _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 
> _9(5.5.0):C2 [total 1 pending]
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge merging= []
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_0(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_1(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_2(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_3(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_4(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_5(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_6(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_7(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_8(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  registerMerge info=_9(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  now merge
>    [junit4]   1> MS 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    index: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 
> _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    consider merge _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2
>    [junit4]   1> MS 100 [2016-02-22T06:39:22.078Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>      launch new thread [MyMergeThread]
>    [junit4]   1> MS 100 [2016-02-22T06:39:22.088Z; MyMergeThread]:   merge 
> thread: start
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.096Z; MyMergeThread]: now apply 
> deletes for 10 merging segments
>    [junit4]   1> BD 100 [2016-02-22T06:39:22.096Z; MyMergeThread]: 
> applyDeletes: open segment readers took 0 msec
>    [junit4]   1> BD 100 [2016-02-22T06:39:22.096Z; MyMergeThread]: 
> applyDeletes: no segments; skipping
>    [junit4]   1> BD 100 [2016-02-22T06:39:22.096Z; MyMergeThread]: prune 
> sis=segments: _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2 
> minGen=1 packetCount=0
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.096Z; MyMergeThread]: merge 
> seg=_a _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 
> _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.096Z; MyMergeThread]: now merge
>    [junit4]   1>   merge=_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2
>    [junit4]   1>   index=_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 
> _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.096Z; MyMergeThread]: merging 
> _0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 _3(5.5.0):C2 _4(5.5.0):C2 _5(5.5.0):C2 
> _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 _9(5.5.0):C2
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.096Z; 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:92)
>    [junit4]   1>        at 
> org.apache.lucene.store.MockDirectoryWrapper.maybeThrowDeterministicException(MockDirectoryWrapper.java:958)
>    [junit4]   1>        at 
> org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:633)
>    [junit4]   1>        at 
> org.apache.lucene.store.Directory.openChecksumInput(Directory.java:109)
>    [junit4]   1>        at 
> org.apache.lucene.store.MockDirectoryWrapper.openChecksumInput(MockDirectoryWrapper.java:1009)
>    [junit4]   1>        at 
> org.apache.lucene.codecs.lucene50.Lucene50FieldInfosFormat.read(Lucene50FieldInfosFormat.java:111)
>    [junit4]   1>        at 
> org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:99)
>    [junit4]   1>        at 
> org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:65)
>    [junit4]   1>        at 
> org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:145)
>    [junit4]   1>        at 
> org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:617)
>    [junit4]   1>        at 
> org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4008)
>    [junit4]   1>        at 
> org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:3655)
>    [junit4]   1>        at 
> org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:588)
>    [junit4]   1>        at 
> org.apache.lucene.TestMergeSchedulerExternal$MyMergeScheduler.doMerge(TestMergeSchedulerExternal.java:82)
>    [junit4]   1>        at 
> org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:626)
>    [junit4]   1>
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.097Z; MyMergeThread]: 
> handleMergeException: merge=_0(5.5.0):C2 _1(5.5.0):C2 _2(5.5.0):C2 
> _3(5.5.0):C2 _4(5.5.0):C2 _5(5.5.0):C2 _6(5.5.0):C2 _7(5.5.0):C2 _8(5.5.0):C2 
> _9(5.5.0):C2 exc=java.io.IOException: now failing during merge
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.097Z; MyMergeThread]: hit 
> exception during merge
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.097Z; MyMergeThread]: hit tragic 
> IOException inside merge
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.097Z; MyMergeThread]: rollback
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.097Z; MyMergeThread]: all 
> running merges have aborted
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.097Z; MyMergeThread]: rollback: 
> done finish merges
>    [junit4]   1> MS 100 [2016-02-22T06:39:22.099Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>  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 100 [2016-02-22T06:39:22.099Z; 
> TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[A2BDF226D5BAFBA8]]:
>    no more merges pending; now return
>    [junit4]   1> DW 100 [2016-02-22T06:39:22.099Z; MyMergeThread]: abort
>    [junit4]   1> DW 100 [2016-02-22T06:39:22.099Z; MyMergeThread]: done abort 
> success=true
>    [junit4]   1> IW 100 [2016-02-22T06:39:22.099Z; MyMergeThread]: rollback: 
> infos=
>    [junit4]   1> MS 100 [2016-02-22T06:39:22.099Z; 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=A2BDF226D5BAFBA8 -Dtests.slow=true -Dtests.locale=he 
> -Dtests.timezone=America/Port-au-Prince -Dtests.asserts=true 
> -Dtests.file.encoding=ISO-8859-1
>    [junit4] FAILURE 0.80s J0 | 
> TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler <<<
>    [junit4]    > Throwable #1: java.lang.AssertionError
>    [junit4]    >        at 
> __randomizedtesting.SeedInfo.seed([A2BDF226D5BAFBA8:253C4F8BD19A81AC]:0)
>    [junit4]    >        at 
> org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler(TestMergeSchedulerExternal.java:144)
>    [junit4]    >        at java.lang.Thread.run(Thread.java:745)
>    [junit4]   2> NOTE: test params are: codec=Asserting(Lucene54): 
> {id=BlockTreeOrds(blocksize=128)}, docValues:{}, 
> sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=he, 
> timezone=America/Port-au-Prince
>    [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_72 
> (64-bit)/cpus=3,threads=1,free=120793000,total=258473984
>    [junit4]   2> NOTE: All tests run in this JVM: [TestDeterminizeLexicon, 
> TestIndexWriterDeleteByQuery, TestSameScoresWithThreads, 
> TestSpanSearchEquivalence, TestReaderClosed, TestIndexWriterLockRelease, 
> TestNativeFSLockFactory, TestUTF32ToUTF8, TestTransactionRollback, 
> TestDirectoryReader, TestSimpleExplanationsOfNonMatches, TestIndexWriter, 
> TestAllFilesCheckIndexHeader, TestDocIdSet, TestLogMergePolicy, 
> TestPerFieldPostingsFormat, TestStressIndexing2, TestWildcardRandom, 
> TestTermRangeFilter, TestDeletionPolicy, TestSloppyPhraseQuery2, 
> TestPerFieldPostingsFormat2, TestNoMergeScheduler, 
> TestSparseFixedBitDocIdSet, TestMinimize, TestAttributeSource, 
> TestTermdocPerf, TestIndexWriterConfig, TestMergeRateLimiter, 
> TestSimpleAttributeImpl, TestNorms, TestDirectPacked, 
> TestLucene50TermVectorsFormat, TestBlockPostingsFormat2, TestFieldsReader, 
> TestFuzzyQuery, TestRollingBuffer, TestPositiveScoresOnlyCollector, 
> TestFilterLeafReader, TestOmitPositions, TestSpanNotQuery, 
> TestFieldValueFilter, TestSpanTermQuery, TestIndexWriterExceptions, 
> TestByteBlockPool, TestScoreCachingWrappingScorer, TestVersion, 
> TestArrayUtil, TestRollback, TestMathUtil, TestIndexWriterThreadsToSegments, 
> TestLazyProxSkipping, TestParallelTermEnum, TestTermsEnum2, 
> TestComplexExplanations, TestSpanFirstQuery, TestBooleanScorer, 
> TestIndexableField, TestBufferedIndexInput, TestCustomNorms, 
> TestPrefixInBooleanQuery, TestMaxPosition, TestForceMergeForever, 
> TestIntBlockPool, TestLucene50StoredFieldsFormat, TestTermScorer, 
> TestDocumentsWriterDeleteQueue, TestConstantScoreQuery, 
> TestIndexWriterOnVMError, TestCachingCollector, TestUniqueTermCount, 
> TestMinShouldMatch2, TestBufferedChecksum, TestIndexSearcher, 
> TestTransactions, TestPrefixCodedTerms, TestReadOnlyIndex, 
> TestCachingWrapperQuery, FuzzyTermOnShortTermsTest, 
> TestMultiThreadTermVectors, TestSwappedIndexFiles, TestNumericTokenStream, 
> TestTrackingDirectoryWrapper, TestIndexWriterUnicode, TestHugeRamFile, 
> TestIndexWriterMerging, TestRegexpQuery, TestIndexInput, TestBooleanRewrites, 
> TestBytesRefArray, TestForUtil, TestIntArrayDocIdSet, 
> TestIndexWriterWithThreads, TestOperations, TestIndexWriterOnJRECrash, 
> TestSegmentInfos, TestComplexExplanationsOfNonMatches, TestDocIdSetBuilder, 
> TestAtomicUpdate, TestCloseableThreadLocal, TestLiveFieldValues, 
> TestShardSearching, TestPerSegmentDeletes, TestSpanContainQuery, 
> TestWeakIdentityMap, TestFSTs, TestNumericRangeQuery64, TestBytesStore, 
> TestNumericRangeQuery32, TestAddIndexes, TestBasics, 
> TestFlushByRamOrCountsPolicy, TestIndexWriterDelete, 
> TestIndexWriterMergePolicy, TestNRTThreads, TestDuelingCodecs, TestBoolean2, 
> TestPersistentSnapshotDeletionPolicy, TestIndexWriterCommit, 
> TestDirectoryReaderReopen, TestTimeLimitingCollector, TestSearchWithThreads, 
> TestConcurrentMergeScheduler, TestDocumentsWriterStallControl, 
> TestTieredMergePolicy, TestTermsEnum, TestNRTCachingDirectory, 
> TestSegmentReader, TestFastDecompressionMode, TestSort, 
> TestSimpleSearchEquivalence, TestDocValuesIndexing, TestSimilarityBase, 
> TestPostingsOffsets, TestMixedCodecs, TestFastCompressionMode, 
> TestMultiPhraseQuery, TestDocsAndPositions, TestMergeSchedulerExternal]
>    [junit4] Completed [263/421 (1!)] on J0 in 0.84s, 2 tests, 1 failure <<< 
> FAILURES!
>
> [...truncated 522 lines...]
> BUILD FAILED
> /Users/jenkins/workspace/Lucene-Solr-5.5-MacOSX/build.xml:750: The following 
> error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-5.5-MacOSX/build.xml:694: The following 
> error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-5.5-MacOSX/build.xml:59: The following 
> error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-5.5-MacOSX/lucene/build.xml:50: The 
> following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-5.5-MacOSX/lucene/common-build.xml:1477: 
> The following error occurred while executing this line:
> /Users/jenkins/workspace/Lucene-Solr-5.5-MacOSX/lucene/common-build.xml:1033: 
> There were test failures: 421 suites (1 ignored), 3386 tests, 1 failure, 48 
> ignored (44 assumptions) [seed: A2BDF226D5BAFBA8]
>
> Total time: 6 minutes 44 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]

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to