Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/186/
3 tests failed. FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test Error Message: Captured an uncaught exception in thread: Thread[id=11454, name=collection4, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=11454, name=collection4, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest] Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: https://127.0.0.1:45246 at __randomizedtesting.SeedInfo.seed([78DB05D1F24CA4A1]:0) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:997) Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: https://127.0.0.1:45246 at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:604) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:262) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:251) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:435) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:387) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1292) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1062) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1004) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1599) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1620) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:987) Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at sun.security.ssl.InputRecord.readFully(InputRecord.java:465) at sun.security.ssl.InputRecord.read(InputRecord.java:503) at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:973) at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:930) at sun.security.ssl.AppInputStream.read(AppInputStream.java:105) at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160) at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84) at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283) at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251) at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:498) ... 11 more FAILED: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload Error Message: expected:<[{indexVersion=1477573304251,generation=2,filelist=[_3.fdt, _3.fdx, _3.fnm, _3.nvd, _3.nvm, _3.si, _3_LuceneFixedGap_0.doc, _3_LuceneFixedGap_0.tib, _3_LuceneFixedGap_0.tii, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, _6.cfe, _6.cfs, _6.si, segments_2]}]> but was:<[{indexVersion=1477573304251,generation=2,filelist=[_3.fdt, _3.fdx, _3.fnm, _3.nvd, _3.nvm, _3.si, _3_LuceneFixedGap_0.doc, _3_LuceneFixedGap_0.tib, _3_LuceneFixedGap_0.tii, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, _6.cfe, _6.cfs, _6.si, segments_2]}, {indexVersion=1477573304251,generation=3,filelist=[_3.fdt, _3.fdx, _3.fnm, _3.nvd, _3.nvm, _3.si, _3_LuceneFixedGap_0.doc, _3_LuceneFixedGap_0.tib, _3_LuceneFixedGap_0.tii, _7.cfe, _7.cfs, _7.si, segments_3]}]> Stack Trace: java.lang.AssertionError: expected:<[{indexVersion=1477573304251,generation=2,filelist=[_3.fdt, _3.fdx, _3.fnm, _3.nvd, _3.nvm, _3.si, _3_LuceneFixedGap_0.doc, _3_LuceneFixedGap_0.tib, _3_LuceneFixedGap_0.tii, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, _6.cfe, _6.cfs, _6.si, segments_2]}]> but was:<[{indexVersion=1477573304251,generation=2,filelist=[_3.fdt, _3.fdx, _3.fnm, _3.nvd, _3.nvm, _3.si, _3_LuceneFixedGap_0.doc, _3_LuceneFixedGap_0.tib, _3_LuceneFixedGap_0.tii, _4.cfe, _4.cfs, _4.si, _5.cfe, _5.cfs, _5.si, _6.cfe, _6.cfs, _6.si, segments_2]}, {indexVersion=1477573304251,generation=3,filelist=[_3.fdt, _3.fdx, _3.fnm, _3.nvd, _3.nvm, _3.si, _3_LuceneFixedGap_0.doc, _3_LuceneFixedGap_0.tib, _3_LuceneFixedGap_0.tii, _7.cfe, _7.cfs, _7.si, segments_3]}]> at __randomizedtesting.SeedInfo.seed([78DB05D1F24CA4A1:5D0C1EE18204AAA2]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.failNotEquals(Assert.java:647) at org.junit.Assert.assertEquals(Assert.java:128) at org.junit.Assert.assertEquals(Assert.java:147) at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1229) 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:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) 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:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) 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:367) at java.lang.Thread.run(Thread.java:745) FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test Error Message: Captured an uncaught exception in thread: Thread[id=8472, name=collection0, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Stack Trace: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=8472, name=collection0, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest] Caused by: java.lang.RuntimeException: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:57028 at __randomizedtesting.SeedInfo.seed([78DB05D1F24CA4A1]:0) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:997) Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:57028 at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:604) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:262) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:251) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:435) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:387) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1292) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1062) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1004) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1599) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1620) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:987) Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160) at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84) at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283) at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251) at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:685) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:487) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:498) ... 11 more Build Log: [...truncated 11420 lines...] [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/init-core-data-001 [junit4] 2> 284236 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[78DB05D1F24CA4A1]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) [junit4] 2> 284236 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[78DB05D1F24CA4A1]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: / [junit4] 2> 284242 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 284256 INFO (Thread-6504) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 284256 INFO (Thread-6504) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 284356 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ZkTestServer start zk server on port:54260 [junit4] 2> 284557 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 284560 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml [junit4] 2> 284562 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 284563 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 284565 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 284566 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 284567 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 284568 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 284570 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 284571 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 284572 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 284686 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/control-001/cores/collection1 [junit4] 2> 284688 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 284689 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@74409b0b{/,null,AVAILABLE} [junit4] 2> 284691 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.ServerConnector Started ServerConnector@246af9d6{HTTP/1.1,[http/1.1]}{127.0.0.1:40666} [junit4] 2> 284691 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server Started @287755ms [junit4] 2> 284691 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/tempDir-001/control/data, hostContext=/, hostPort=40666, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/control-001/cores} [junit4] 2> 284692 ERROR (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 284693 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.3.0 [junit4] 2> 284698 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 284698 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 284698 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-27T12:25:13.713Z [junit4] 2> 284703 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 284703 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/control-001/solr.xml [junit4] 2> 284712 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 284713 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54260/solr [junit4] 2> 284753 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:40666_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40666_ [junit4] 2> 284754 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:40666_ ] o.a.s.c.Overseer Overseer (id=96834100479393796-127.0.0.1:40666_-n_0000000000) starting [junit4] 2> 284766 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:40666_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40666_ [junit4] 2> 284768 INFO (zkCallback-372-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 284790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:40666_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/control-001/cores [junit4] 2> 284790 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:40666_ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 284794 INFO (OverseerStateUpdate-96834100479393796-127.0.0.1:40666_-n_0000000000) [n:127.0.0.1:40666_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 284812 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.3.0 [junit4] 2> 284826 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 284917 WARN (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 284919 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 284932 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection [junit4] 2> 284933 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/control-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/control-001/cores/collection1/data/] [junit4] 2> 284933 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@177a275e [junit4] 2> 284934 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@55efb9ab [junit4] 2> 284938 WARN (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}} [junit4] 2> 284947 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 284947 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 284947 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 284947 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 284948 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 284950 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@29f6a17[collection1] main] [junit4] 2> 284951 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 284952 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 284952 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 284952 INFO (searcherExecutor-1097-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@29f6a17[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 284952 INFO (coreLoadExecutor-1096-thread-1-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549345608399060992 [junit4] 2> 284968 INFO (coreZkRegister-1089-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 284968 INFO (coreZkRegister-1089-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 284968 INFO (coreZkRegister-1089-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40666/collection1/ [junit4] 2> 284968 INFO (coreZkRegister-1089-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 284968 INFO (coreZkRegister-1089-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:40666/collection1/ has no replicas [junit4] 2> 284981 INFO (coreZkRegister-1089-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:40666/collection1/ shard1 [junit4] 2> 285132 INFO (coreZkRegister-1089-thread-1-processing-n:127.0.0.1:40666_ x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:40666_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 285297 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 285298 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 285298 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2 [junit4] 2> 285416 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-1-001/cores/collection1 [junit4] 2> 285416 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-1-001 [junit4] 2> 285417 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 285420 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@a42a95d{/,null,AVAILABLE} [junit4] 2> 285420 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.ServerConnector Started ServerConnector@375ba0cd{HTTP/1.1,[http/1.1]}{127.0.0.1:47666} [junit4] 2> 285420 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server Started @288484ms [junit4] 2> 285420 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=47666, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-1-001/cores} [junit4] 2> 285421 ERROR (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 285422 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.3.0 [junit4] 2> 285422 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 285422 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 285422 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-27T12:25:14.437Z [junit4] 2> 285425 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 285425 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-1-001/solr.xml [junit4] 2> 285432 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 285432 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54260/solr [junit4] 2> 285445 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 285453 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47666_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47666_ [junit4] 2> 285455 INFO (zkCallback-376-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 285455 INFO (zkCallback-372-thread-2-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 285455 INFO (zkCallback-382-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 285465 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47666_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-1-001/cores [junit4] 2> 285466 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47666_ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 285468 INFO (OverseerStateUpdate-96834100479393796-127.0.0.1:40666_-n_0000000000) [n:127.0.0.1:40666_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 285572 INFO (zkCallback-382-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 286481 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.3.0 [junit4] 2> 286495 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 286594 WARN (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 286597 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 286613 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 286613 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-1-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-1-001/cores/collection1/data/] [junit4] 2> 286614 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@177a275e [junit4] 2> 286615 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@79861017 [junit4] 2> 286621 WARN (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}} [junit4] 2> 286632 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 286632 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 286633 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 286633 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 286633 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 286634 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@629037cd[collection1] main] [junit4] 2> 286635 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 286636 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 286636 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 286637 INFO (searcherExecutor-1108-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@629037cd[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 286637 INFO (coreLoadExecutor-1107-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549345610165911552 [junit4] 2> 286645 INFO (coreZkRegister-1102-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 286645 INFO (coreZkRegister-1102-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 286645 INFO (coreZkRegister-1102-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:47666/collection1/ [junit4] 2> 286645 INFO (coreZkRegister-1102-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 286645 INFO (coreZkRegister-1102-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:47666/collection1/ has no replicas [junit4] 2> 286650 INFO (coreZkRegister-1102-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:47666/collection1/ shard2 [junit4] 2> 286754 INFO (zkCallback-382-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 286801 INFO (coreZkRegister-1102-thread-1-processing-n:127.0.0.1:47666_ x:collection1 s:shard2 c:collection1 r:core_node1) [n:127.0.0.1:47666_ c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 286911 INFO (zkCallback-382-thread-1-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 287065 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-2-001/cores/collection1 [junit4] 2> 287066 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-2-001 [junit4] 2> 287067 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 287068 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3c49d173{/,null,AVAILABLE} [junit4] 2> 287069 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5375260b{HTTP/1.1,[http/1.1]}{127.0.0.1:43514} [junit4] 2> 287069 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server Started @290133ms [junit4] 2> 287069 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/, hostPort=43514, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-2-001/cores} [junit4] 2> 287070 ERROR (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 287070 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.3.0 [junit4] 2> 287070 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 287070 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 287070 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-27T12:25:16.085Z [junit4] 2> 287075 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 287075 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-2-001/solr.xml [junit4] 2> 287081 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 287082 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54260/solr [junit4] 2> 287096 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 287101 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:43514_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43514_ [junit4] 2> 287104 INFO (zkCallback-372-thread-4-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 287118 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 287121 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 287135 INFO (zkCallback-376-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 287139 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:43514_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-2-001/cores [junit4] 2> 287139 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:43514_ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 287150 INFO (OverseerStateUpdate-96834100479393796-127.0.0.1:40666_-n_0000000000) [n:127.0.0.1:40666_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 287254 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 287254 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 288163 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.3.0 [junit4] 2> 288187 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 288278 WARN (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 288280 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 288294 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 288294 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-2-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-2-001/cores/collection1/data/] [junit4] 2> 288294 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@177a275e [junit4] 2> 288296 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@e892078 [junit4] 2> 288301 WARN (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}} [junit4] 2> 288312 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 288312 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 288312 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 288312 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 288313 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 288314 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4e3c9a20[collection1] main] [junit4] 2> 288318 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 288318 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 288318 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 288319 INFO (coreLoadExecutor-1118-thread-1-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549345611929616384 [junit4] 2> 288321 INFO (searcherExecutor-1119-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4e3c9a20[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 288335 INFO (coreZkRegister-1113-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 288335 INFO (coreZkRegister-1113-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 288335 INFO (coreZkRegister-1113-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43514/collection1/ [junit4] 2> 288335 INFO (coreZkRegister-1113-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 288335 INFO (coreZkRegister-1113-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:43514/collection1/ has no replicas [junit4] 2> 288340 INFO (coreZkRegister-1113-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43514/collection1/ shard1 [junit4] 2> 288443 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 288443 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 288491 INFO (coreZkRegister-1113-thread-1-processing-n:127.0.0.1:43514_ x:collection1 s:shard1 c:collection1 r:core_node2) [n:127.0.0.1:43514_ c:collection1 s:shard1 r:core_node2 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 288598 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 288598 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 288758 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-3-001/cores/collection1 [junit4] 2> 288759 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-3-001 [junit4] 2> 288761 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 288763 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@698b8aad{/,null,AVAILABLE} [junit4] 2> 288763 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.ServerConnector Started ServerConnector@5cd184bb{HTTP/1.1,[http/1.1]}{127.0.0.1:47006} [junit4] 2> 288764 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server Started @291827ms [junit4] 2> 288764 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/tempDir-001/jetty3, solrconfig=solrconfig.xml, hostContext=/, hostPort=47006, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-3-001/cores} [junit4] 2> 288764 ERROR (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 288765 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.3.0 [junit4] 2> 288765 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 288765 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 288765 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-27T12:25:17.780Z [junit4] 2> 288776 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 288776 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-3-001/solr.xml [junit4] 2> 288782 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 288783 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54260/solr [junit4] 2> 288795 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47006_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 288802 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47006_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47006_ [junit4] 2> 288804 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 288804 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 288805 INFO (zkCallback-376-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 288805 INFO (zkCallback-372-thread-3-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 288806 INFO (zkCallback-394-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 288828 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47006_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-3-001/cores [junit4] 2> 288828 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:47006_ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 288831 INFO (OverseerStateUpdate-96834100479393796-127.0.0.1:40666_-n_0000000000) [n:127.0.0.1:40666_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 288934 INFO (zkCallback-394-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 288934 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 288934 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 289844 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.3.0 [junit4] 2> 289865 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 289961 WARN (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 289963 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 289991 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 289991 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-3-001/cores/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-3-001/cores/collection1/data/] [junit4] 2> 289992 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@177a275e [junit4] 2> 289993 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@47faa756 [junit4] 2> 289999 WARN (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,args = {defaults={a=A,b=B}}} [junit4] 2> 290010 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 290010 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 290011 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 290011 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 290015 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 290015 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@76680019[collection1] main] [junit4] 2> 290016 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 290016 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1 [junit4] 2> 290017 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 290018 INFO (searcherExecutor-1130-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@76680019[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 290018 INFO (coreLoadExecutor-1129-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549345613711147008 [junit4] 2> 290033 INFO (coreZkRegister-1124-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.ZkController Core needs to recover:collection1 [junit4] 2> 290042 INFO (updateExecutor-391-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 290053 INFO (recoveryExecutor-392-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 290054 INFO (recoveryExecutor-392-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]] [junit4] 2> 290054 INFO (recoveryExecutor-392-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1] [junit4] 2> 290054 INFO (recoveryExecutor-392-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 290054 INFO (recoveryExecutor-392-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:47666/collection1/] and I am [http://127.0.0.1:47006/collection1/] [junit4] 2> 290067 INFO (recoveryExecutor-392-thread-1-processing-n:127.0.0.1:47006_ x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:47006_ c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:47666]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:47006_&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true] [junit4] 2> 290081 INFO (qtp245026796-8217) [n:127.0.0.1:47666_ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 290081 INFO (qtp245026796-8217) [n:127.0.0.1:47666_ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard2 of collection1) have state: recovering [junit4] 2> 290082 INFO (qtp245026796-8217) [n:127.0.0.1:47666_ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:47006_, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:47006","node_name":"127.0.0.1:47006_","state":"down"} [junit4] 2> 290160 INFO (zkCallback-394-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 290160 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 290160 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 290487 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-4-001/cores/collection1 [junit4] 2> 290487 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-4-001 [junit4] 2> 290488 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 290490 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3a5f24a2{/,null,AVAILABLE} [junit4] 2> 290491 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.ServerConnector Started ServerConnector@41a65ba2{HTTP/1.1,[http/1.1]}{127.0.0.1:57028} [junit4] 2> 290491 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.Server Started @293554ms [junit4] 2> 290491 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/tempDir-001/jetty4, solrconfig=solrconfig.xml, hostContext=/, hostPort=57028, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-4-001/cores} [junit4] 2> 290491 ERROR (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 290495 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.3.0 [junit4] 2> 290495 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 290495 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 290495 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-27T12:25:19.510Z [junit4] 2> 290505 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 290505 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-4-001/solr.xml [junit4] 2> 290517 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 290518 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54260/solr [junit4] 2> 290545 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:57028_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 290552 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:57028_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57028_ [junit4] 2> 290555 INFO (zkCallback-376-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 290555 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 290555 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 290557 INFO (zkCallback-394-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 290557 INFO (zkCallback-372-thread-3-processing-n:127.0.0.1:40666_) [n:127.0.0.1:40666_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 290559 INFO (zkCallback-401-thread-1-processing-n:127.0.0.1:57028_) [n:127.0.0.1:57028_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 290576 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:57028_ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_78DB05D1F24CA4A1-001/shard-4-001/cores [junit4] 2> 290576 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[78DB05D1F24CA4A1]) [n:127.0.0.1:57028_ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 290579 INFO (OverseerStateUpdate-96834100479393796-127.0.0.1:40666_-n_0000000000) [n:127.0.0.1:40666_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 290682 INFO (zkCallback-394-thread-1-processing-n:127.0.0.1:47006_) [n:127.0.0.1:47006_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 290682 INFO (zkCallback-401-thread-1-processing-n:127.0.0.1:57028_) [n:127.0.0.1:57028_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 290682 INFO (zkCallback-382-thread-2-processing-n:127.0.0.1:47666_) [n:127.0.0.1:47666_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 290683 INFO (zkCallback-388-thread-2-processing-n:127.0.0.1:43514_) [n:127.0.0.1:43514_ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 291082 INFO (qtp245026796-8217) [n:127.0.0.1:47666_ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:47006_, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:47006","node_name":"127.0.0.1:47006_","state":"recovering"} [junit4] 2> 291082 INFO (qtp245026796-8217) [n:127.0.0.1:47666_ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds. [junit4] 2> 291082 INFO (qtp245026796-8217) [n:127.0.0.1:47666_ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:47006_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1001 [junit4] 2> 291599 INFO (coreLoadExecutor-1140-thread-1-processing-n:127.0.0.1:57028_) [n:127.0.0.1:57028_ c:collection1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.3.0 [junit4] 2> 291630 INFO (coreLoadExecutor-1140-thread-1-processing-n:127.0.0.1:57028_) [n:127.0.0.1:57028_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 291762 WARN (coreLoadExecutor-1140-thread-1-processing-n:127.0.0.1:57028_) [n:127.0.0.1:57028_ c:collection1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 291765 INFO (coreLoadExecutor-1140-thread-1-processing-n:127.0.0.1:57028_) [n:127.0.0.1:57028_ c:collection1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 291797 INFO (coreLoadExecutor-1140-thread-1-processing-n:127.0.0.1:57028_) [n:127.0.0.1:57028_ c:collection1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1 [junit4] 2> 29 [...truncated too long message...] unit4] 2> 2795302 INFO (Thread-15860) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=12.8916015625, floorSegmentMB=0.6455078125, forceMergeDeletesPctAllowed=12.798059564856853, segmentsPerTier=11.0, maxCFSSegmentSizeMB=0.291015625, noCFSRatio=0.13102173578962503 [junit4] 2> 2795303 INFO (Thread-15860) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2795304 INFO (Thread-15860) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2f99408[collection1] main] [junit4] 2> 2795304 INFO (searcherExecutor-10123-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2f99408[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_39(6.3.0):C39420) Uninverting(_3a(6.3.0):c459)))} [junit4] 2> 2795304 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher removing old index directory MockDirectoryWrapper(RAMDirectory@7cfbc2e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@60031fa0) [junit4] 2> 2795304 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=98.197265625, floorSegmentMB=0.564453125, forceMergeDeletesPctAllowed=1.163315092110938, segmentsPerTier=4.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2795305 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2795305 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@647f5528[collection1] main] [junit4] 2> 2795305 INFO (searcherExecutor-10123-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@647f5528[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_39(6.3.0):C39420) Uninverting(_3a(6.3.0):c459)))} [junit4] 2> 2795306 INFO (qtp1128341120-113016) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:57538/solr/collection1/replication&command=fetchindex} status=0 QTime=133 [junit4] 2> 2795306 INFO (qtp1128341120-113016) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@37453fd8 [junit4] 2> 2795309 INFO (qtp1128341120-113010) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 2795322 INFO (qtp1128341120-113014) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=39879 status=0 QTime=11 [junit4] 2> 2795322 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 39879 docs [junit4] 2> 2795324 INFO (qtp1665613473-113032) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 2795326 INFO (qtp1665613473-113027) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 2795328 INFO (qtp1128341120-113011) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 2795329 INFO (qtp1665613473-113034) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 2795331 INFO (qtp1128341120-113016) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 2795331 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestStressReplication [junit4] 2> 2795332 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@55f1cba2{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 2795332 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1222926890 [junit4] 2> 2795332 INFO (coreCloseExecutor-10127-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@153c484d [junit4] 2> 2795334 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@717f4b4e{/solr,null,UNAVAILABLE} [junit4] 2> 2795335 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@112721aa{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 2795335 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1958583178 [junit4] 2> 2795336 INFO (coreCloseExecutor-10129-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@4e7d9472 [junit4] 2> 2795337 INFO (TEST-TestReplicationHandler.doTestStressReplication-seed#[78DB05D1F24CA4A1]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4b3ac9b6{/solr,null,UNAVAILABLE} [junit4] 2> 2795339 INFO (SUITE-TestReplicationHandler-seed#[78DB05D1F24CA4A1]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_78DB05D1F24CA4A1-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {name=PostingsFormat(name=LuceneFixedGap), id=PostingsFormat(name=LuceneFixedGap), newname=PostingsFormat(name=LuceneFixedGap)}, docValues:{}, maxPointsInLeafNode=900, maxMBSortInHeap=7.5218494121809325, sim=ClassicSimilarity, locale=es-UY, timezone=Africa/Asmera [junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=4,threads=1,free=188926968,total=525336576 [junit4] 2> NOTE: All tests run in this JVM: [StandardRequestHandlerTest, TestSortingResponseWriter, TestMinMaxOnMultiValuedField, TestHighFrequencyDictionaryFactory, TestPHPSerializedResponseWriter, PathHierarchyTokenizerFactoryTest, LeaderElectionContextKeyTest, ExplicitHLLTest, AlternateDirectoryTest, UniqFieldsUpdateProcessorFactoryTest, ClusterStateTest, ResourceLoaderTest, DistributedVersionInfoTest, TestQuerySenderNoQuery, SharedFSAutoReplicaFailoverTest, TestFieldSortValues, TestPerFieldSimilarity, SolrRequestParserTest, ExternalFileFieldSortTest, CursorPagingTest, TestDistributedStatsComponentCardinality, DistribDocExpirationUpdateProcessorTest, LeaderElectionIntegrationTest, PolyFieldTest, CursorMarkTest, HdfsBasicDistributedZk2Test, HdfsChaosMonkeySafeLeaderTest, LeaderInitiatedRecoveryOnCommitTest, HdfsSyncSliceTest, TestHashQParserPlugin, TestSolrXml, TestStressUserVersions, ChangedSchemaMergeTest, CloneFieldUpdateProcessorFactoryTest, ReplicationFactorTest, CurrencyFieldOpenExchangeTest, TestManagedResourceStorage, TestSolrCoreProperties, TestFastWriter, HdfsUnloadDistributedZkTest, TestAuthenticationFramework, RequestLoggingTest, TestLeaderElectionWithEmptyReplica, TestSubQueryTransformerCrossCore, TestStressLucene, PeerSyncTest, CollectionTooManyReplicasTest, TestReplicaProperties, DataDrivenBlockJoinTest, TestLazyCores, TestUseDocValuesAsStored2, BasicZkTest, TestEmbeddedSolrServerConstructors, TestClusterStateMutator, TestSolrCLIRunExample, OutputWriterTest, TestRealTimeGet, TestStressLiveNodes, TestIntervalFaceting, ActionThrottleTest, OverseerStatusTest, TestCollationFieldDocValues, TestDynamicFieldCollectionResource, FastVectorHighlighterTest, DistributedDebugComponentTest, TestScoreJoinQPScore, TestManagedSchemaThreadSafety, XsltUpdateRequestHandlerTest, ReturnFieldsTest, TestRangeQuery, TestJoin, TestCodecSupport, FileBasedSpellCheckerTest, TestFaceting, DistributedSpellCheckComponentTest, RecoveryAfterSoftCommitTest, TestXmlQParserPlugin, TestHighlightDedupGrouping, DistributedFacetPivotLargeTest, HdfsDirectoryFactoryTest, TestSolr4Spatial2, TestSolrDeletionPolicy2, TestNumericTerms32, BlobRepositoryCloudTest, DistanceUnitsTest, TestSearcherReuse, TestLocalFSCloudBackupRestore, TestFastLRUCache, TestSchemaNameResource, EnumFieldTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestMissingGroups, MultiThreadedOCPTest, HLLUtilTest, TestRandomFlRTGCloud, CreateCollectionCleanupTest, TestCrossCoreJoin, TestFieldResource, TestSolrCloudWithDelegationTokens, TestOmitPositions, TestCollectionAPI, TestManagedSynonymFilterFactory, DistributedQueryComponentOptimizationTest, DateFieldTest, ParsingFieldUpdateProcessorsTest, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest, SyncSliceTest, ShardRoutingTest, TestReplicationHandler] [junit4] Completed [463/646 (3!)] on J0 in 685.79s, 15 tests, 1 failure, 1 skipped <<< FAILURES! [...truncated 60965 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
