Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/222/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED:
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler
Error Message:
Stack Trace:
java.lang.AssertionError
at
__randomizedtesting.SeedInfo.seed([D853AFC32C37680:8A04875136E30C84]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertTrue(Assert.java:54)
at
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler(TestMergeSchedulerExternal.java:147)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED:
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Error from server at
http://127.0.0.1:53192/solr/awhollynewcollection_0_shard2_replica_n2:
ClusterState says we are the leader
(http://127.0.0.1:53192/solr/awhollynewcollection_0_shard2_replica_n2), but
locally we don't think so. Request came from null
Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from
server at http://127.0.0.1:53192/solr/awhollynewcollection_0_shard2_replica_n2:
ClusterState says we are the leader
(http://127.0.0.1:53192/solr/awhollynewcollection_0_shard2_replica_n2), but
locally we don't think so. Request came from null
at
__randomizedtesting.SeedInfo.seed([AC327EC2E4BDF7B2:E4470A76E28ED827]:0)
at
org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:539)
at
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:993)
at
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
at
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
at
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
at
org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
at
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:459)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Caused by:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error
from server at
http://127.0.0.1:53192/solr/awhollynewcollection_0_shard2_replica_n2:
ClusterState says we are the leader
(http://127.0.0.1:53192/solr/awhollynewcollection_0_shard2_replica_n2), but
locally we don't think so. Request came from null
at
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:627)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
at
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
at
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
at
org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:516)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
... 1 more
Build Log:
[...truncated 249 lines...]
[junit4] Suite: org.apache.lucene.TestMergeSchedulerExternal
[junit4] 1> TEST FAILED; IW infoStream output:
[junit4] 1> IFD 0 [2017-10-02T11:05:00.424Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
init: current segments file is "segments";
deletionPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy@6a5ba0f4
[junit4] 1> IFD 0 [2017-10-02T11:05:00.437Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "" [0 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:00.437Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> IW 0 [2017-10-02T11:05:00.437Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
init: create=true
[junit4] 1> IW 0 [2017-10-02T11:05:00.437Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
[junit4] 1> dir=MockDirectoryWrapper(RAMDirectory@659905c5
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@749590d1)
[junit4] 1> index=
[junit4] 1> version=7.1.0
[junit4] 1> analyzer=org.apache.lucene.analysis.MockAnalyzer
[junit4] 1> ramBufferSizeMB=-1.0
[junit4] 1> maxBufferedDocs=2
[junit4] 1> mergedSegmentWarmer=null
[junit4] 1>
delPolicy=org.apache.lucene.index.KeepOnlyLastCommitDeletionPolicy
[junit4] 1> commit=null
[junit4] 1> openMode=CREATE_OR_APPEND
[junit4] 1>
similarity=org.apache.lucene.search.similarities.RandomSimilarity
[junit4] 1> mergeScheduler=MyMergeScheduler: maxThreadCount=-1,
maxMergeCount=-1, ioThrottle=true
[junit4] 1> codec=Asserting(Lucene70): {}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> infoStream=org.apache.lucene.util.PrintStreamInfoStream
[junit4] 1> mergePolicy=[LogByteSizeMergePolicy: minMergeSize=1677721,
mergeFactor=42, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.0]
[junit4] 1>
indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@40128d59
[junit4] 1> readerPooling=true
[junit4] 1> perThreadHardLimitMB=1945
[junit4] 1> useCompoundFile=false
[junit4] 1> commitOnClose=true
[junit4] 1> indexSort=null
[junit4] 1> writer=org.apache.lucene.index.IndexWriter@13b29a56
[junit4] 1>
[junit4] 1> IW 0 [2017-10-02T11:05:00.437Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
MMapDirectory.UNMAP_SUPPORTED=true
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.441Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _0 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:00.441Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:00.441Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:00.441Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:00.447Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
5 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:00.465Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
18 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:00.490Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
24 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.490Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.490Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.490Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_0_LuceneVarGapDocFreqInterval_0.tiv,
_0_LuceneVarGapDocFreqInterval_0.tib, _0.fdx, _0.fdt,
_0_LuceneVarGapDocFreqInterval_0.doc, _0.fnm]
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.490Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.531Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_0 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.575Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 134.286437 msec
[junit4] 1> DW 0 [2017-10-02T11:05:00.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:00.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _0(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:00.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=1 now completedDelGen=1
[junit4] 1> IW 0 [2017-10-02T11:05:00.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=1 seg=_0(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:00.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2" [1 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:00.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:00.576Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 1 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:00.642Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:00.642Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 1 segments
[junit4] 1> MS 0 [2017-10-02T11:05:00.643Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
initDynamicDefaults spins=false maxThreadCount=1 maxMergeCount=6
[junit4] 1> MS 0 [2017-10-02T11:05:00.643Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:00.643Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:00.643Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.649Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _1 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:00.649Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:00.649Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:00.649Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:00.654Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:00.681Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
27 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:00.705Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
23 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.705Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.705Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.705Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_1_LuceneVarGapDocFreqInterval_0.tib,
_1_LuceneVarGapDocFreqInterval_0.doc, _1.fdx,
_1_LuceneVarGapDocFreqInterval_0.tiv, _1.fnm, _1.fdt]
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.705Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.726Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_1 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 83.845435 msec
[junit4] 1> DW 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _1(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=2 now completedDelGen=2
[junit4] 1> IW 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=2 seg=_1(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2" [2 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 2 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:00.733Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:00.779Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:00.779Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 2 segments
[junit4] 1> MS 0 [2017-10-02T11:05:00.779Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:00.779Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:00.779Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.793Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _2 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:00.793Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:00.793Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:00.793Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:00.797Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:00.848Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
50 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:00.852Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.852Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.852Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.852Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_2_LuceneVarGapDocFreqInterval_0.tiv,
_2_LuceneVarGapDocFreqInterval_0.tib, _2.fdt, _2.fnm, _2.fdx,
_2_LuceneVarGapDocFreqInterval_0.doc]
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.852Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.877Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_2 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 132.096039 msec
[junit4] 1> DW 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _2(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=3 now completedDelGen=3
[junit4] 1> IW 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=3 seg=_2(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2" [3 segments ; isCommit
= false]
[junit4] 1> IFD 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 3 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:00.925Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:00.947Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:00.947Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 3 segments
[junit4] 1> MS 0 [2017-10-02T11:05:00.947Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:00.947Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:00.947Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.953Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _3 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:00.953Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:00.953Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:00.953Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:00.957Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:00.981Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
23 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:00.991Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
10 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.991Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.991Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.991Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_3.fdx, _3_LuceneVarGapDocFreqInterval_0.tib,
_3_LuceneVarGapDocFreqInterval_0.tiv, _3.fnm,
_3_LuceneVarGapDocFreqInterval_0.doc, _3.fdt]
[junit4] 1> DWPT 0 [2017-10-02T11:05:00.991Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.004Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_3 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.009Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 56.830786 msec
[junit4] 1> DW 0 [2017-10-02T11:05:01.009Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _3(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=4 now completedDelGen=4
[junit4] 1> IW 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=4 seg=_3(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2" [4
segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 4 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.010Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.013Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_3(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.013Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 4 segments
[junit4] 1> MS 0 [2017-10-02T11:05:01.013Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:01.013Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.013Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _4 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:01.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:01.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:01.026Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:01.041Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
14 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:01.073Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
31 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:01.081Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
7 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.081Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.081Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.081Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_4.fdt, _4.fnm, _4_LuceneVarGapDocFreqInterval_0.doc,
_4_LuceneVarGapDocFreqInterval_0.tib, _4.fdx,
_4_LuceneVarGapDocFreqInterval_0.tiv]
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.081Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.081Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_4 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 61.461512 msec
[junit4] 1> DW 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _4(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=5 now completedDelGen=5
[junit4] 1> IW 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=5 seg=_4(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2" [5 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 5 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.088Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_3(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.089Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_4(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.089Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 5 segments
[junit4] 1> MS 0 [2017-10-02T11:05:01.089Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:01.089Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.089Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.091Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _5 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:01.091Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:01.091Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:01.091Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:01.094Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
2 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:01.122Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
27 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:01.127Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.127Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.127Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.127Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_5.fnm, _5_LuceneVarGapDocFreqInterval_0.tib, _5.fdt,
_5_LuceneVarGapDocFreqInterval_0.tiv, _5_LuceneVarGapDocFreqInterval_0.doc,
_5.fdx]
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.127Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.130Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_5 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 46.314564 msec
[junit4] 1> DW 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _5(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=6 now completedDelGen=6
[junit4] 1> IW 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=6 seg=_5(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2" [6 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 6 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_3(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.138Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_4(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.140Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_5(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.140Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 6 segments
[junit4] 1> MS 0 [2017-10-02T11:05:01.140Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:01.140Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2
_5(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.140Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.143Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _6 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:01.143Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:01.143Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:01.143Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:01.149Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
6 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:01.169Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
20 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:01.174Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
5 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.175Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.175Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.175Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_6_LuceneVarGapDocFreqInterval_0.tiv, _6.fdt,
_6_LuceneVarGapDocFreqInterval_0.doc, _6.fnm, _6.fdx,
_6_LuceneVarGapDocFreqInterval_0.tib]
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.175Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.189Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_6 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.198Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 55.443249 msec
[junit4] 1> DW 0 [2017-10-02T11:05:01.198Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:01.198Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _6(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:01.198Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=7 now completedDelGen=7
[junit4] 1> IW 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=7 seg=_6(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2" [7 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 7 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_3(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_4(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.199Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_5(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.205Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_6(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.205Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 7 segments
[junit4] 1> MS 0 [2017-10-02T11:05:01.205Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:01.205Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2
_5(7.1.0):C2 _6(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.205Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.209Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _7 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:01.209Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:01.209Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:01.209Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:01.213Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:01.232Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
18 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:01.236Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.236Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.236Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.236Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_7_LuceneVarGapDocFreqInterval_0.doc,
_7_LuceneVarGapDocFreqInterval_0.tib, _7.fnm, _7.fdt,
_7_LuceneVarGapDocFreqInterval_0.tiv, _7.fdx]
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.236Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.236Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_7 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.245Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 36.610553 msec
[junit4] 1> DW 0 [2017-10-02T11:05:01.245Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:01.245Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _7(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:01.245Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=8 now completedDelGen=8
[junit4] 1> IW 0 [2017-10-02T11:05:01.245Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=8 seg=_7(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2" [8 segments ; isCommit =
false]
[junit4] 1> IFD 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 8 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_3(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_4(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_5(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.246Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_6(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.252Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_7(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.252Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 8 segments
[junit4] 1> MS 0 [2017-10-02T11:05:01.252Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:01.252Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2
_5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.252Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.257Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _8 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:01.257Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:01.257Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:01.257Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:01.261Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:01.275Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
13 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:01.280Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.280Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.280Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.280Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_8.fdx, _8.fdt, _8_LuceneVarGapDocFreqInterval_0.tiv, _8.fnm,
_8_LuceneVarGapDocFreqInterval_0.tib, _8_LuceneVarGapDocFreqInterval_0.doc]
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.280Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.280Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_8 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 28.973195 msec
[junit4] 1> DW 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _8(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=9 now completedDelGen=9
[junit4] 1> IW 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=9 seg=_8(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2" [9 segments ;
isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 9 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_3(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_4(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_5(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_6(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.286Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_7(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.287Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_8(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.287Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 9 segments
[junit4] 1> MS 0 [2017-10-02T11:05:01.287Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:01.288Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2
_5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.288Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.291Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush postings as segment _9 numDocs=2
[junit4] 1> IW 0 [2017-10-02T11:05:01.291Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write norms
[junit4] 1> IW 0 [2017-10-02T11:05:01.291Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write docValues
[junit4] 1> IW 0 [2017-10-02T11:05:01.291Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to write points
[junit4] 1> IW 0 [2017-10-02T11:05:01.295Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
4 msec to finish stored fields
[junit4] 1> IW 0 [2017-10-02T11:05:01.316Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
20 msec to write postings and finish vectors
[junit4] 1> IW 0 [2017-10-02T11:05:01.321Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
5 msec to write fieldInfos
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.321Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has 0 deleted docs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.321Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
new segment has no vectors; no norms; no docValues; no prox; no freqs
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.321Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushedFiles=[_9.fdx, _9_LuceneVarGapDocFreqInterval_0.tib, _9.fdt,
_9_LuceneVarGapDocFreqInterval_0.doc, _9.fnm,
_9_LuceneVarGapDocFreqInterval_0.tiv]
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.321Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.324Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flushed: segment=_9 ramUsed=0.071 MB newFlushedSize=0.001 MB docs/MB=2,661.36
[junit4] 1> DWPT 0 [2017-10-02T11:05:01.339Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
flush time 48.731388 msec
[junit4] 1> DW 0 [2017-10-02T11:05:01.339Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment seg-private updates=null
[junit4] 1> IW 0 [2017-10-02T11:05:01.339Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publishFlushedSegment _9(7.1.0):C2
[junit4] 1> BD 0 [2017-10-02T11:05:01.339Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
finished packet delGen=10 now completedDelGen=10
[junit4] 1> IW 0 [2017-10-02T11:05:01.339Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
publish sets newSegment delGen=10 seg=_9(7.1.0):C2
[junit4] 1> IFD 0 [2017-10-02T11:05:01.339Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now checkpoint "_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2"
[10 segments ; isCommit = false]
[junit4] 1> IFD 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
0 msec to checkpoint
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
findMerges: 10 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_0(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_1(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_2(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_3(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_4(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_5(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_6(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_7(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.340Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_8(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.343Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
seg=_9(7.1.0):C2 level=3.1085649 size=0.001 MB
[junit4] 1> LMP 0 [2017-10-02T11:05:01.343Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
level -1.0 to 3.1085649: 10 segments
[junit4] 1> LMP 0 [2017-10-02T11:05:01.344Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
add merge=_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2
_5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2 start=0 end=10
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
add merge to pendingMerges: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2
_3(7.1.0):C2 _4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2
_9(7.1.0):C2 [total 1 pending]
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge merging= []
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_0(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_1(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_2(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_3(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_4(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_5(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_6(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_7(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_8(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
registerMerge info=_9(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
now merge
[junit4] 1> MS 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
index: _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2
_5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.346Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
consider merge _0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2
[junit4] 1> MS 0 [2017-10-02T11:05:01.348Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
launch new thread [MyMergeThread]
[junit4] 1> MS 0 [2017-10-02T11:05:01.348Z; MyMergeThread]: merge
thread: start
[junit4] 1> BD 0 [2017-10-02T11:05:01.349Z; MyMergeThread]:
waitApplyForMerge: 0 packets, 10 merging segments
[junit4] 1> BD 0 [2017-10-02T11:05:01.349Z; MyMergeThread]: waitApply: no
deletes to apply
[junit4] 1> IW 0 [2017-10-02T11:05:01.349Z; MyMergeThread]: now apply
deletes for 10 merging segments
[junit4] 1> IW 0 [2017-10-02T11:05:01.350Z; MyMergeThread]: merge seg=_a
_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2 _5(7.1.0):C2
_6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.350Z; MyMergeThread]: now merge
[junit4] 1> merge=_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2
[junit4] 1> index=_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.351Z; MyMergeThread]: merging
_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2 _4(7.1.0):C2 _5(7.1.0):C2
_6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2
[junit4] 1> IW 0 [2017-10-02T11:05:01.351Z; MyMergeThread]: TEST: now
throw exc:
[junit4] 1> java.io.IOException: now failing during merge
[junit4] 1> at
org.apache.lucene.TestMergeSchedulerExternal$FailOnlyOnMerge.eval(TestMergeSchedulerExternal.java:95)
[junit4] 1> at
org.apache.lucene.store.MockDirectoryWrapper.maybeThrowDeterministicException(MockDirectoryWrapper.java:1022)
[junit4] 1> at
org.apache.lucene.store.MockDirectoryWrapper.openInput(MockDirectoryWrapper.java:743)
[junit4] 1> at
org.apache.lucene.store.Directory.openChecksumInput(Directory.java:119)
[junit4] 1> at
org.apache.lucene.store.MockDirectoryWrapper.openChecksumInput(MockDirectoryWrapper.java:1072)
[junit4] 1> at
org.apache.lucene.codecs.lucene60.Lucene60FieldInfosFormat.read(Lucene60FieldInfosFormat.java:113)
[junit4] 1> at
org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:107)
[junit4] 1> at
org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:78)
[junit4] 1> at
org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:208)
[junit4] 1> at
org.apache.lucene.index.ReadersAndUpdates.getReaderForMerge(ReadersAndUpdates.java:836)
[junit4] 1> at
org.apache.lucene.index.IndexWriter.mergeMiddle(IndexWriter.java:4362)
[junit4] 1> at
org.apache.lucene.index.IndexWriter.merge(IndexWriter.java:4032)
[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-10-02T11:05:01.352Z; MyMergeThread]:
handleMergeException: merge=_0(7.1.0):C2 _1(7.1.0):C2 _2(7.1.0):C2 _3(7.1.0):C2
_4(7.1.0):C2 _5(7.1.0):C2 _6(7.1.0):C2 _7(7.1.0):C2 _8(7.1.0):C2 _9(7.1.0):C2
exc=java.io.IOException: now failing during merge
[junit4] 1> IW 0 [2017-10-02T11:05:01.352Z; MyMergeThread]: hit exception
during merge
[junit4] 1> IW 0 [2017-10-02T11:05:01.352Z; MyMergeThread]: hit tragic
IOException inside merge
[junit4] 1> IW 0 [2017-10-02T11:05:01.352Z; MyMergeThread]: rollback
[junit4] 1> IW 0 [2017-10-02T11:05:01.352Z; MyMergeThread]: all running
merges have aborted
[junit4] 1> IW 0 [2017-10-02T11:05:01.352Z; MyMergeThread]: rollback: done
finish merges
[junit4] 1> MS 0 [2017-10-02T11:05:01.355Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
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-10-02T11:05:01.355Z;
TEST-TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler-seed#[D853AFC32C37680]]:
no more merges pending; now return
[junit4] 1> DW 0 [2017-10-02T11:05:01.355Z; MyMergeThread]: abort
[junit4] 1> DW 0 [2017-10-02T11:05:01.355Z; MyMergeThread]: done abort
success=true
[junit4] 1> IW 0 [2017-10-02T11:05:01.355Z; MyMergeThread]: rollback:
infos=
[junit4] 1> IW 0 [2017-10-02T11:05:01.356Z; MyMergeThread]: TEST: now
handleMergeException
[junit4] 1> MS 0 [2017-10-02T11:05:01.356Z; 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=D853AFC32C37680 -Dtests.slow=true -Dtests.locale=zh-HK
-Dtests.timezone=America/Buenos_Aires -Dtests.asserts=true
-Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 1.01s J1 |
TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler <<<
[junit4] > Throwable #1: java.lang.AssertionError
[junit4] > at
__randomizedtesting.SeedInfo.seed([D853AFC32C37680:8A04875136E30C84]:0)
[junit4] > at
org.apache.lucene.TestMergeSchedulerExternal.testSubclassConcurrentMergeScheduler(TestMergeSchedulerExternal.java:147)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70):
{id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{},
maxPointsInLeafNode=1073, maxMBSortInHeap=7.924571263640305,
sim=RandomSimilarity(queryNorm=false): {}, locale=zh-HK,
timezone=America/Buenos_Aires
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144
(64-bit)/cpus=3,threads=1,free=42243016,total=54788096
[junit4] 2> NOTE: All tests run in this JVM:
[TestSpanMultiTermQueryWrapper, TestSimilarityBase, TestMergeSchedulerExternal]
[junit4] Completed [9/454 (1!)] on J1 in 1.09s, 2 tests, 1 failure <<<
FAILURES!
[...truncated 11806 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_AC327EC2E4BDF7B2-001/init-core-data-001
[junit4] 2> 481465 INFO
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 481466 INFO
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
w/ MAC_OS_X supressed clientAuth
[junit4] 2> 481466 INFO
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 481468 INFO
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_AC327EC2E4BDF7B2-001/tempDir-001
[junit4] 2> 481468 INFO
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 481469 INFO (Thread-1432) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 481469 INFO (Thread-1432) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 481475 ERROR (Thread-1432) [ ] o.a.z.s.ZooKeeperServer
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action
on ERROR or SHUTDOWN server state changes
[junit4] 2> 481579 INFO
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:53187
[junit4] 2> 481614 INFO (jetty-launcher-908-thread-1) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 481615 INFO (jetty-launcher-908-thread-2) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 481619 INFO (jetty-launcher-908-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@225d159a{/solr,null,AVAILABLE}
[junit4] 2> 481621 INFO (jetty-launcher-908-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6faa5c79{/solr,null,AVAILABLE}
[junit4] 2> 481623 INFO (jetty-launcher-908-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@69231d33{HTTP/1.1,[http/1.1]}{127.0.0.1:53190}
[junit4] 2> 481623 INFO (jetty-launcher-908-thread-2) [ ]
o.e.j.s.Server Started @484820ms
[junit4] 2> 481623 INFO (jetty-launcher-908-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53190}
[junit4] 2> 481623 ERROR (jetty-launcher-908-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 481623 INFO (jetty-launcher-908-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.1.0
[junit4] 2> 481623 INFO (jetty-launcher-908-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 481623 INFO (jetty-launcher-908-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 481623 INFO (jetty-launcher-908-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-02T11:29:09.681Z
[junit4] 2> 481624 INFO (jetty-launcher-908-thread-3) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 481625 INFO (jetty-launcher-908-thread-4) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 481626 INFO (jetty-launcher-908-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1276359a{HTTP/1.1,[http/1.1]}{127.0.0.1:53189}
[junit4] 2> 481626 INFO (jetty-launcher-908-thread-1) [ ]
o.e.j.s.Server Started @484823ms
[junit4] 2> 481626 INFO (jetty-launcher-908-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53189}
[junit4] 2> 481626 ERROR (jetty-launcher-908-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 481626 INFO (jetty-launcher-908-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.1.0
[junit4] 2> 481628 INFO (jetty-launcher-908-thread-4) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@d13a587{/solr,null,AVAILABLE}
[junit4] 2> 481628 INFO (jetty-launcher-908-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-02T11:29:09.687Z
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-4) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@7241fba5{HTTP/1.1,[http/1.1]}{127.0.0.1:53192}
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-4) [ ]
o.e.j.s.Server Started @484826ms
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-4) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53192}
[junit4] 2> 481629 ERROR (jetty-launcher-908-thread-4) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-4) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.1.0
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-4) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-4) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-4) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-02T11:29:09.687Z
[junit4] 2> 481629 INFO (jetty-launcher-908-thread-3) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@538b75f0{/solr,null,AVAILABLE}
[junit4] 2> 481630 INFO (jetty-launcher-908-thread-3) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@267e8b0d{HTTP/1.1,[http/1.1]}{127.0.0.1:53193}
[junit4] 2> 481630 INFO (jetty-launcher-908-thread-3) [ ]
o.e.j.s.Server Started @484826ms
[junit4] 2> 481630 INFO (jetty-launcher-908-thread-3) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=53193}
[junit4] 2> 481630 ERROR (jetty-launcher-908-thread-3) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 481630 INFO (jetty-launcher-908-thread-3) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
7.1.0
[junit4] 2> 481630 INFO (jetty-launcher-908-thread-3) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 481630 INFO (jetty-launcher-908-thread-3) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config
dir: null
[junit4] 2> 481630 INFO (jetty-launcher-908-thread-3) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2017-10-02T11:29:09.688Z
[junit4] 2> 481631 INFO (jetty-launcher-908-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 481634 INFO (jetty-launcher-908-thread-4) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 481634 INFO (jetty-launcher-908-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 481634 INFO (jetty-launcher-908-thread-3) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 481658 INFO (jetty-launcher-908-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53187/solr
[junit4] 2> 481658 INFO (jetty-launcher-908-thread-3) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53187/solr
[junit4] 2> 481659 INFO (jetty-launcher-908-thread-4) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53187/solr
[junit4] 2> 481660 INFO (jetty-launcher-908-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:53187/solr
[junit4] 2> 481834 INFO (jetty-launcher-908-thread-1)
[n:127.0.0.1:53189_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 481834 INFO (jetty-launcher-908-thread-2)
[n:127.0.0.1:53190_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 481834 INFO (jetty-launcher-908-thread-4)
[n:127.0.0.1:53192_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 481834 INFO (jetty-launcher-908-thread-3)
[n:127.0.0.1:53193_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 481835 INFO (jetty-launcher-908-thread-4)
[n:127.0.0.1:53192_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:53192_solr
[junit4] 2> 481835 INFO (jetty-launcher-908-thread-1)
[n:127.0.0.1:53189_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:53189_solr
[junit4] 2> 481835 INFO (jetty-launcher-908-thread-2)
[n:127.0.0.1:53190_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:53190_solr
[junit4] 2> 481836 INFO (jetty-launcher-908-thread-3)
[n:127.0.0.1:53193_solr ] o.a
[...truncated too long message...]
lrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 564259 INFO (jetty-closer-909-thread-4) [ ]
o.a.s.c.Overseer Overseer
(id=98759065569198092-127.0.0.1:53189_solr-n_0000000001) closing
[junit4] 2> 564259 INFO
(OverseerStateUpdate-98759065569198092-127.0.0.1:53189_solr-n_0000000001)
[n:127.0.0.1:53189_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:53189_solr
[junit4] 2> 564259 INFO (jetty-closer-909-thread-1) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 564260 INFO (jetty-closer-909-thread-2) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 564263 INFO
(zkCallback-929-thread-5-processing-n:127.0.0.1:53193_solr)
[n:127.0.0.1:53193_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (2)
[junit4] 2> 564263 INFO
(zkCallback-930-thread-5-processing-n:127.0.0.1:53189_solr)
[n:127.0.0.1:53189_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (2)
[junit4] 2> 564266 INFO
(zkCallback-929-thread-2-processing-n:127.0.0.1:53193_solr)
[n:127.0.0.1:53193_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 564266 INFO
(zkCallback-929-thread-5-processing-n:127.0.0.1:53193_solr)
[n:127.0.0.1:53193_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:53193_solr
[junit4] 2> 564267 WARN
(zkCallback-929-thread-2-processing-n:127.0.0.1:53193_solr)
[n:127.0.0.1:53193_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 565766 WARN
(zkCallback-944-thread-2-processing-n:127.0.0.1:53192_solr)
[n:127.0.0.1:53192_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 565766 WARN
(zkCallback-927-thread-4-processing-n:127.0.0.1:53190_solr)
[n:127.0.0.1:53190_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 565766 WARN
(zkCallback-930-thread-5-processing-n:127.0.0.1:53189_solr)
[n:127.0.0.1:53189_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 565766 INFO (jetty-closer-909-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@48b7342b{/solr,null,UNAVAILABLE}
[junit4] 2> 565766 INFO (jetty-closer-909-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@6faa5c79{/solr,null,UNAVAILABLE}
[junit4] 2> 565767 INFO (jetty-closer-909-thread-4) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@225d159a{/solr,null,UNAVAILABLE}
[junit4] 2> 565776 INFO (jetty-closer-909-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@538b75f0{/solr,null,UNAVAILABLE}
[junit4] 2> 565778 ERROR
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper
server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 565778 INFO
(SUITE-CollectionsAPIDistributedZkTest-seed#[AC327EC2E4BDF7B2]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:53187 53187
[junit4] 2> 565779 INFO (Thread-1478) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:53187 53187
[junit4] 2> 565894 WARN (Thread-1478) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/configs/conf
[junit4] 2> 18 /solr/aliases.json
[junit4] 2> 18 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 52 /solr/collections/addReplicaColl/state.json
[junit4] 2> 24
/solr/collections/nodes_used_collection/state.json
[junit4] 2> 24 /solr/collections/reloaded_collection/state.json
[junit4] 2> 18 /solr/clusterstate.json
[junit4] 2> 15
/solr/collections/acollectionafterbaddelete/state.json
[junit4] 2> 14
/solr/collections/halfdeletedcollection/state.json
[junit4] 2> 10 /solr/collections/onlyinzk/state.json
[junit4] 2> 6
/solr/collections/awhollynewcollection_0/state.json
[junit4] 2> 5
/solr/collections/halfcollectionblocker/state.json
[junit4] 2> 5 /solr/collections/created_and_deleted/state.json
[junit4] 2> 5
/solr/collections/halfcollectionblocker2/state.json
[junit4] 2> 5 /solr/collections/withconfigset2/state.json
[junit4] 2> 4 /solr/collections/halfcollection/state.json
[junit4] 2> 2
/solr/collections/addReplicaColl/leader_elect/shard1/election/98759065569198089-core_node10-n_0000000002
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 358 /solr/collections
[junit4] 2> 18 /solr/live_nodes
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_AC327EC2E4BDF7B2-001
[junit4] 2> Oct 02, 2017 11:30:33 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard,
sim=RandomSimilarity(queryNorm=true): {}, locale=lt-LT, timezone=Asia/Sakhalin
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144
(64-bit)/cpus=3,threads=1,free=288788872,total=429363200
[junit4] 2> NOTE: All tests run in this JVM: [OverseerRolesTest,
TestCoreDiscovery, MoreLikeThisHandlerTest, CoreMergeIndexesAdminHandlerTest,
TestLegacyTerms, JavabinLoaderTest, TestZkChroot, TestJoin,
SimpleMLTQParserTest, TestSQLHandlerNonCloud, DataDrivenBlockJoinTest,
CoreAdminCreateDiscoverTest, MultiThreadedOCPTest, TestTrie,
BigEndianAscendingWordDeserializerTest,
StatelessScriptUpdateProcessorFactoryTest, TestChildDocTransformer,
TemplateUpdateProcessorTest, ShardRoutingCustomTest, BasicFunctionalityTest,
TestCopyFieldCollectionResource, TestSolrCLIRunExample, DeleteNodeTest,
ImplicitSnitchTest, LeaderInitiatedRecoveryOnShardRestartTest, SampleTest,
TestRandomCollapseQParserPlugin, TestRestoreCore,
SharedFSAutoReplicaFailoverUtilsTest, SolrCoreCheckLockOnStartupTest,
TestStressUserVersions, TestConfigReload, TestAuthorizationFramework,
ZkNodePropsTest, TermVectorComponentDistributedTest,
FieldMutatingUpdateProcessorTest, SolrCmdDistributorTest,
TestPostingsSolrHighlighter, ChangedSchemaMergeTest,
TestSimpleTrackingShardHandler, TestCoreAdminApis, TestReload,
OutOfBoxZkACLAndCredentialsProvidersTest, TestCharFilters,
TestManagedSchemaThreadSafety, TestLegacyFieldReuse,
HdfsCollectionsAPIDistributedZkTest, SpatialHeatmapFacetsTest,
HdfsUnloadDistributedZkTest, MBeansHandlerTest, TestSolrJ, TestCollationField,
TestCollationFieldDocValues, TestRandomFaceting, SearchHandlerTest,
TestPartialUpdateDeduplication, TestFieldCacheWithThreads, TestRecovery,
TestPivotHelperCode, DistributedQueryElevationComponentTest, BasicZkTest,
TestFileDictionaryLookup, TestOverriddenPrefixQueryForCustomFieldType,
TestConfigSetImmutable, TestLeaderElectionZkExpiry, DateRangeFieldTest,
DistributedFacetPivotWhiteBoxTest, CursorMarkTest,
DistributedFacetPivotSmallAdvancedTest, TestCloudManagedSchema,
TestCollapseQParserPlugin, SolrIndexMetricsTest, TestCloudPseudoReturnFields,
TestCollectionAPIs, SolrRequestParserTest, TermsComponentTest,
TestPayloadScoreQParserPlugin, TestLMJelinekMercerSimilarityFactory,
TestFieldTypeResource, TestJsonRequest, AutoCommitTest,
OverseerCollectionConfigSetProcessorTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [161/733 (1!)] on J1 in 84.70s, 19 tests, 1 error <<<
FAILURES!
[...truncated 39115 lines...]
-documentation-lint:
[echo] checking for broken html...
[jtidy] Checking for broken html (such as invalid tags)...
[delete] Deleting directory
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/build/jtidy_tmp
[echo] Checking for broken links...
[exec]
[exec] Crawl/parse...
[exec]
[exec] Verify...
[exec]
[exec]
file:///build/docs/sandbox/org/apache/lucene/document/FloatPointNearestNeighbor.html
[exec] BROKEN LINK:
file:///build/docs/core/org/apache/lucene/document/FloatPointNearestNeighbor.NearestHit.html
[exec] BROKEN LINK:
file:///build/docs/core/org/apache/lucene/document/FloatPointNearestNeighbor.NearestHit.html
[exec]
[exec] Broken javadocs links were found! Common root causes:
[exec] * A typo of some sort for manually created links.
[exec] * Public methods referencing non-public classes in their signature.
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/build.xml:826: The following
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/build.xml:101: The following
error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/build.xml:142: The
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/build.xml:155: The
following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/lucene/common-build.xml:2570:
exec returned: 1
Total time: 80 minutes 56 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]
