Adrien Grand created LUCENE-7945:
------------------------------------
Summary: TestMergeSchedulerExternal failure
Key: LUCENE-7945
URL: https://issues.apache.org/jira/browse/LUCENE-7945
Project: Lucene - Core
Issue Type: Bug
Reporter: Adrien Grand
Priority: Minor
I hit the following test failure:
{noformat}
[junit4] Suite: org.apache.lucene.TestMergeSchedulerExternal
[junit4] 1> TEST FAILED; IW infoStream output:
[junit4] 1> IFD 0 [2017-08-29T20:07:58.366Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
init: current segments file is "segments";
deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@147f4499
[junit4] 1> IFD 0 [2017-08-29T20:07:58.403Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "" [0 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.403Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IW 0 [2017-08-29T20:07:58.403Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
init: create=true
[junit4] 1> IW 0 [2017-08-29T20:07:58.403Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
[junit4] 1> dir=MockDirectoryWrapper(RAMDirectory@1ed52170
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76c21fb3)
[junit4] 1> index=
[junit4] 1> version=8.0.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=-1.0
[junit4] 1> maxBufferedDocs=2
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1>
delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=CREATE_OR_APPEND
[junit4] 1>
similarity=org.apache.lucene.search.similarities.RandomSimilarity
[junit4] 1> mergeScheduler=MyMergeScheduler: maxThreadCount=-1,
maxMergeCount=-1, ioThrottle=true
[junit4] 1> codec=CheapBastard
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[LogByteSizeMergePolicy: minMergeSize=1677721,
mergeFactor=13, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.810681051478346]
[junit4] 1>
indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@39b33696
[junit4] 1> readerPooling=false
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=true
[junit4] 1> commitOnClose=true
[junit4] 1> indexSort=null
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@14082bc1
[junit4] 1>
[junit4] 1> IW 0 [2017-08-29T20:07:58.403Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.409Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _0 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.409Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.409Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.409Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.422Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
13 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.448Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
25 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.456Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
8 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.456Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.456Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.456Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_0.tip, _0.fdx, _0.doc, _0.tim, _0.fdt, _0.fnm]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.456Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.464Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_0 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.465Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.552Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 143.37104 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _0(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=1 now completedDelGen=1
[junit4] 1> IW 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=1 seg=_0(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2" [1 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_0.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_0.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_0.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_0.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_0.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_0.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.553Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_0.tip, _0.fdx, _0.doc, _0.tim, _0.fdt, _0.fnm]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.554Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 1 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.554Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.554Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 1 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.554Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 0 [2017-08-29T20:07:58.554Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.554Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.554Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.559Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _1 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.559Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.559Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.559Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.563Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
3 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
12 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.578Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.578Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.578Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.578Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_1.doc, _1.tim, _1.tip, _1.fdx, _1.fnm, _1.fdt]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.578Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.578Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_1 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.579Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 44.222471 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _1(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=2 now completedDelGen=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=2 seg=_1(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2" [2 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_1.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_1.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_1.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_1.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_1.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_1.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.603Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_1.doc, _1.tim, _1.tip, _1.fdx, _1.fnm, _1.fdt]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.604Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 2 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.604Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.604Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.604Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 2 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.604Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.604Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.604Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.608Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _2 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.608Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.608Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.608Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.614Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
5 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.635Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
20 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.637Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.637Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.638Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.638Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_2.tip, _2.fdt, _2.fnm, _2.fdx, _2.doc, _2.tim]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.638Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.638Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_2 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.638Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.663Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 54.878877 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.663Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.663Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _2(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.663Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=3 now completedDelGen=3
[junit4] 1> IW 0 [2017-08-29T20:07:58.663Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=3 seg=_2(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.663Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2" [3 segments ; isCommit
= false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_2.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_2.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_2.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_2.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_2.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_2.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_2.tip, _2.fdt, _2.fnm, _2.fdx, _2.doc, _2.tim]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 3 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 3 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.664Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.666Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _3 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.666Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.666Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.666Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.671Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
4 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.681Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
10 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.686Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
4 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.686Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.686Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.686Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_3.tip, _3.fdx, _3.fnm, _3.fdt, _3.doc, _3.tim]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.686Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.686Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_3 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.687Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.720Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 53.831698 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.720Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.720Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _3(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.720Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=4 now completedDelGen=4
[junit4] 1> IW 0 [2017-08-29T20:07:58.720Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=4 seg=_3(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.720Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2" [4
segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_3.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_3.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_3.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_3.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_3.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_3.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_3.tip, _3.fdx, _3.fnm, _3.fdt, _3.doc, _3.tim]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.721Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 4 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_3(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 4 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.722Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.724Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _4 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.724Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.724Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.724Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.727Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.738Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
10 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.740Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.740Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.740Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.740Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_4.doc, _4.tim, _4.fdt, _4.fnm, _4.tip, _4.fdx]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.740Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.740Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_4 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.740Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 40.689396 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _4(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=5 now completedDelGen=5
[junit4] 1> IW 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=5 seg=_4(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2" [5 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_4.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_4.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_4.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_4.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_4.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_4.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_4.doc, _4.tim, _4.fdt, _4.fnm, _4.tip, _4.fdx]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 5 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.765Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_3(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.766Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_4(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.766Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 5 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.766Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.766Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.766Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.770Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _5 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.770Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.770Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.770Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.776Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
5 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.793Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
17 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.795Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.795Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.795Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.795Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_5.fnm, _5.fdt, _5.doc, _5.tim, _5.tip, _5.fdx]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.795Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.796Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_5 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.796Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 52.410376 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _5(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=6 now completedDelGen=6
[junit4] 1> IW 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=6 seg=_5(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2" [6 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_5.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_5.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_5.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_5.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_5.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_5.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.822Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_5.fnm, _5.fdt, _5.doc, _5.tim, _5.tip, _5.fdx]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 6 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_3(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_4(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_5(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 6 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2
_5(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.823Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.825Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _6 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.825Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.825Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.825Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.828Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.839Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
10 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.841Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.841Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.841Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.841Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_6.fdt, _6.fnm, _6.fdx, _6.tip, _6.doc, _6.tim]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.841Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.841Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_6 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.842Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 41.908027 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _6(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=7 now completedDelGen=7
[junit4] 1> IW 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=7 seg=_6(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2" [7 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_6.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_6.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_6.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_6.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_6.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_6.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.867Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_6.fdt, _6.fnm, _6.fdx, _6.tip, _6.doc, _6.tim]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 7 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_3(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_4(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_5(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_6(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 7 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2
_5(8.0.0):c2 _6(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.868Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.870Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _7 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.871Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.871Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.871Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.873Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.884Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
10 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.887Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.887Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.887Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.887Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_7.fnm, _7.tim, _7.fdt, _7.doc, _7.fdx, _7.tip]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.887Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.887Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_7 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.887Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.911Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 40.917889 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.911Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.911Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _7(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.911Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=8 now completedDelGen=8
[junit4] 1> IW 0 [2017-08-29T20:07:58.911Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=8 seg=_7(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2" [8 segments ; isCommit =
false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_7.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_7.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_7.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_7.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_7.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_7.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_7.fnm, _7.tim, _7.fdt, _7.doc, _7.fdx, _7.tip]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 8 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_3(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_4(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_5(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_6(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_7(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 8 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2
_5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.912Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.916Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _8 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.916Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.917Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.917Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.922Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
5 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.940Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
17 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:58.945Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
5 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.945Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.945Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.945Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_8.fdx, _8.doc, _8.fdt, _8.fnm, _8.tim, _8.tip]
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.945Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.945Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_8 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:58.945Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 54.30704 msec
[junit4] 1> DW 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _8(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=9 now completedDelGen=9
[junit4] 1> IW 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=9 seg=_8(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2" [9 segments ;
isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_8.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_8.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_8.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_8.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_8.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_8.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_8.fdx, _8.doc, _8.fdt, _8.fnm, _8.tim, _8.tip]
[junit4] 1> LMP 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 9 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:58.971Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_3(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_4(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_5(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_6(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_7(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_8(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 9 segments
[junit4] 1> MS 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2
_5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:58.972Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-08-29T20:07:58.974Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush postings as segment _9 numDocs=2
[junit4] 1> IW 0 [2017-08-29T20:07:58.974Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-08-29T20:07:58.974Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-08-29T20:07:58.974Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to write points
[junit4] 1> IW 0 [2017-08-29T20:07:58.980Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
5 msec to finish stored fields
[junit4] 1> IW 0 [2017-08-29T20:07:58.999Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
18 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-08-29T20:07:59.001Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
2 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-08-29T20:07:59.001Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-08-29T20:07:59.001Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-08-29T20:07:59.001Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushedFiles=[_9.fdx, _9.tip, _9.doc, _9.tim, _9.fdt, _9.fnm]
[junit4] 1> DWPT 0 [2017-08-29T20:07:59.001Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed codec=CheapBastard
[junit4] 1> DWPT 0 [2017-08-29T20:07:59.001Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flushed: segment=_9 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=3,603.354
[junit4] 1> IW 0 [2017-08-29T20:07:59.002Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
create compound file
[junit4] 1> DWPT 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
flush time 51.474967 msec
[junit4] 1> DW 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publishFlushedSegment _9(8.0.0):c2
[junit4] 1> BD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
finished packet delGen=10 now completedDelGen=10
[junit4] 1> IW 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
publish sets newSegment delGen=10 seg=_9(8.0.0):c2
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now checkpoint "_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2"
[10 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
0 msec to checkpoint
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_9.fdx"
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_9.tip"
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_9.doc"
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_9.tim"
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_9.fdt"
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
will delete new file "_9.fnm"
[junit4] 1> IFD 0 [2017-08-29T20:07:59.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
delete [_9.fdx, _9.tip, _9.doc, _9.tim, _9.fdt, _9.fnm]
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
findMerges: 10 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_0(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_1(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_2(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_3(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_4(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_5(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_6(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_7(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_8(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
seg=_9(8.0.0):c2 level=3.0891984 size=0.001 MB
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
level -1.0 to 3.0891984: 10 segments
[junit4] 1> LMP 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
add merge=_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2
_5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2 start=0 end=10
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
add merge to pendingMerges: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2
_3(8.0.0):c2 _4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2
_9(8.0.0):c2 [total 1 pending]
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge merging= []
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_0(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_1(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_2(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_3(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_4(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_5(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_6(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_7(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_8(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.027Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
registerMerge info=_9(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:59.028Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
now merge
[junit4] 1> MS 0 [2017-08-29T20:07:59.028Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
index: _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2
_5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:59.028Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
consider merge _0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2
[junit4] 1> MS 0 [2017-08-29T20:07:59.028Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
launch new thread [MyMergeThread]
[junit4] 1> MS 0 [2017-08-29T20:07:59.072Z; MyMergeThread]: merge
thread: start
[junit4] 1> BD 0 [2017-08-29T20:07:59.086Z; MyMergeThread]:
waitApplyForMerge: 0 packets, 10 merging segments
[junit4] 1> BD 0 [2017-08-29T20:07:59.086Z; MyMergeThread]: waitApply: no
deletes to apply
[junit4] 1> IW 0 [2017-08-29T20:07:59.086Z; MyMergeThread]: now apply
deletes for 10 merging segments
[junit4] 1> IW 0 [2017-08-29T20:07:59.086Z; MyMergeThread]: merge seg=_a
_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2 _5(8.0.0):c2
_6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.086Z; MyMergeThread]: now merge
[junit4] 1> merge=_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2
[junit4] 1> index=_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.086Z; MyMergeThread]: merging
_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2 _4(8.0.0):c2 _5(8.0.0):c2
_6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2
[junit4] 1> IW 0 [2017-08-29T20:07:59.087Z; MyMergeThread]: TEST: now
throw exc:
[junit4] 1> java.io.IOException: now failing during merge
[junit4] 1> at
org.apache.lucene.TestMergeSchedulerExternal$FailOnlyOnMerge.eval(TestMergeSchedulerExternal.java:95)
[junit4] 1> at
org.apache.lucene.store.MockDirectoryWrapper.maybeThrowDeterministicException(MockDirectoryWrapper.java:1022)
[junit4] 1> at
org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:743)
[junit4] 1> at
org.apache.lucene.store.Directory.openChecksumInput(Directory.java:119)
[junit4] 1> at
org.apache.lucene.store.MockDirectoryWrapper.openChecksumInput(MockDirectoryWrapper.java:1072)
[junit4] 1> at
org.apache.lucene.codecs.lucene50.Lucene50CompoundReader.readEntries(Lucene50CompoundReader.java:105)
[junit4] 1> at
org.apache.lucene.codecs.lucene50.Lucene50CompoundReader.<init>(Lucene50CompoundReader.java:69)
[junit4] 1> at
org.apache.lucene.codecs.lucene50.Lucene50CompoundFormat.getCompoundReader(Lucene50CompoundFormat.java:71)
[junit4] 1> at
org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:99)
[junit4] 1> at
org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:78)
[junit4] 1> at
org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:208)
[junit4] 1> at
org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:836)
[junit4] 1> at
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4360)
[junit4] 1> at
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4030)
[junit4] 1> at
org.apache.lucene.index.ConcurrentMergeScheduler.doMerge(ConcurrentMergeScheduler.java:624)
[junit4] 1> at
org.apache.lucene.TestMergeSchedulerExternal$MyMergeScheduler.doMerge(TestMergeSchedulerExternal.java:85)
[junit4] 1> at
org.apache.lucene.index.ConcurrentMergeScheduler$MergeThread.run(ConcurrentMergeScheduler.java:661)
[junit4] 1>
[junit4] 1> IW 0 [2017-08-29T20:07:59.087Z; MyMergeThread]:
handleMergeException: merge=_0(8.0.0):c2 _1(8.0.0):c2 _2(8.0.0):c2 _3(8.0.0):c2
_4(8.0.0):c2 _5(8.0.0):c2 _6(8.0.0):c2 _7(8.0.0):c2 _8(8.0.0):c2 _9(8.0.0):c2
exc=java.io.IOException: now failing during merge
[junit4] 1> IW 0 [2017-08-29T20:07:59.087Z; MyMergeThread]: hit exception
during merge
[junit4] 1> IW 0 [2017-08-29T20:07:59.087Z; MyMergeThread]: hit tragic
IOException inside merge
[junit4] 1> IW 0 [2017-08-29T20:07:59.087Z; MyMergeThread]: rollback
[junit4] 1> IW 0 [2017-08-29T20:07:59.087Z; MyMergeThread]: all running
merges have aborted
[junit4] 1> IW 0 [2017-08-29T20:07:59.087Z; MyMergeThread]: rollback: done
finish merges
[junit4] 1> MS 0 [2017-08-29T20:07:59.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
updateMergeThreads ioThrottle=true targetMBPerSec=20.0 MB/sec
[junit4] 1> merge thread MyMergeThread estSize=0.0 MB (written=0.0 MB)
runTime=0.0s (stopped=0.0s, paused=0.0s) rate=unlimited
[junit4] 1> leave running at Infinity MB/sec
[junit4] 1> MS 0 [2017-08-29T20:07:59.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[B944333784A66276]]:
no more merges pending; now return
[junit4] 1> DW 0 [2017-08-29T20:07:59.088Z; MyMergeThread]: abort
[junit4] 1> DW 0 [2017-08-29T20:07:59.088Z; MyMergeThread]: done abort
success=true
[junit4] 1> IW 0 [2017-08-29T20:07:59.088Z; MyMergeThread]: rollback:
infos=
[junit4] 1> IW 0 [2017-08-29T20:07:59.089Z; MyMergeThread]: TEST: now
handleMergeException
[junit4] 1> MS 0 [2017-08-29T20:07:59.089Z; 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=B944333784A66276 -Dtests.slow=true -Dtests.locale=et-EE
-Dtests.timezone=Etc/GMT+9 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 0.75s J1 |
TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler <<<
[junit4] > Throwable #1: java.lang.AssertionError
[junit4] > at
__randomizedtesting.SeedInfo.seed([B944333784A66276:3EC58E9A80861872]:0)
[junit4] > at
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler(TestMergeSchedulerExternal.java:147)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: test params are: codec=CheapBastard,
sim=RandomSimilarity(queryNorm=true): {}, locale=et-EE, timezone=Etc/GMT+9
[junit4] 2> NOTE: Linux 2.6.32-696.6.3.el6.x86_64 amd64/Oracle Corporation
1.8.0_141 (64-bit)/cpus=4,threads=1,free=239361936,total=253755392
[junit4] 2> NOTE: All tests run in this JVM:
[TestLucene50StoredFieldsFormat, TestCustomTermFreq, TestBooleanQuery,
TestComplexExplanations, TestGraphTokenizers, TestOmitPositions,
TestRecyclingIntBlockAllocator, TestLockFactory, TestMergeSchedulerExternal]
{noformat}
It does not reproduce and logs seem to indicate that {{handleMergeException}}
was actually called so this might be a race condition, ie. we check the value
of {{excCalled}} before it is set?
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
