Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/3059/ Java: 64bit/jdk-9-ea+160 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed. FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI Error Message: Error from server at https://127.0.0.1:37839/solr/awhollynewcollection_0: Expected mime type application/octet-stream but got text/html. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 510 </title> </head> <body> <h2>HTTP ERROR: 510</h2> <p>Problem accessing /solr/awhollynewcollection_0/select. Reason: <pre> {metadata={error-class=org.apache.solr.common.SolrException,root-error-class=org.apache.solr.common.SolrException},msg={"awhollynewcollection_0":6},code=510}</pre></p> <hr /><a href="http://eclipse.org/jetty";>Powered by Jetty:// 9.3.14.v20161028</a><hr/> </body> </html> Stack Trace: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:37839/solr/awhollynewcollection_0: Expected mime type application/octet-stream but got text/html. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 510 </title> </head> <body> <h2>HTTP ERROR: 510</h2> <p>Problem accessing /solr/awhollynewcollection_0/select. Reason: <pre> {metadata={error-class=org.apache.solr.common.SolrException,root-error-class=org.apache.solr.common.SolrException},msg={"awhollynewcollection_0":6},code=510}</pre></p> <hr /><a href="http://eclipse.org/jetty";>Powered by Jetty:// 9.3.14.v20161028</a><hr/> </body> </html> at __randomizedtesting.SeedInfo.seed([27184E7E60C12F2F:6F6D3ACA66F200BA]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:578) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268) 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:1376) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1127) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1230) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1230) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1230) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1230) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1230) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1057) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:160) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:522) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:547) 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:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java: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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 11677 lines...] [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/init-core-data-001 [junit4] 2> 634675 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1 [junit4] 2> 634675 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields [junit4] 2> 634677 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0) [junit4] 2> 634678 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001 [junit4] 2> 634678 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 634679 INFO (Thread-1171) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 634679 INFO (Thread-1171) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 634779 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:40835 [junit4] 2> 634784 INFO (jetty-launcher-792-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 634784 INFO (jetty-launcher-792-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 634786 INFO (jetty-launcher-792-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@472c34be{/solr,null,AVAILABLE} [junit4] 2> 634786 INFO (jetty-launcher-792-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 634786 INFO (jetty-launcher-792-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 634786 INFO (jetty-launcher-792-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@744a287{/solr,null,AVAILABLE} [junit4] 2> 634787 INFO (jetty-launcher-792-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1dfcc1f5{/solr,null,AVAILABLE} [junit4] 2> 634787 INFO (jetty-launcher-792-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3c1633f7{/solr,null,AVAILABLE} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@499cacba{SSL,[ssl, http/1.1]}{127.0.0.1:37839} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@29432ab0{SSL,[ssl, http/1.1]}{127.0.0.1:34112} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@f4dd44f{SSL,[ssl, http/1.1]}{127.0.0.1:35244} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-3) [ ] o.e.j.s.Server Started @636706ms [junit4] 2> 634789 INFO (jetty-launcher-792-thread-1) [ ] o.e.j.s.Server Started @636706ms [junit4] 2> 634789 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34112} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35244} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-2) [ ] o.e.j.s.Server Started @636706ms [junit4] 2> 634789 INFO (jetty-launcher-792-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1f762ef4{SSL,[ssl, http/1.1]}{127.0.0.1:46011} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37839} [junit4] 2> 634789 INFO (jetty-launcher-792-thread-4) [ ] o.e.j.s.Server Started @636706ms [junit4] 2> 634789 ERROR (jetty-launcher-792-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 634790 ERROR (jetty-launcher-792-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 634790 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 634790 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 634790 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-14T18:27:24.849226Z [junit4] 2> 634790 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-14T18:27:24.849250Z [junit4] 2> 634790 ERROR (jetty-launcher-792-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 634790 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46011} [junit4] 2> 634790 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 634790 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-14T18:27:24.849459Z [junit4] 2> 634790 ERROR (jetty-launcher-792-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 634790 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0 [junit4] 2> 634790 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 634790 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-14T18:27:24.849730Z [junit4] 2> 634791 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 634791 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 634792 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 634792 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 634796 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 634798 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 634798 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 634801 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40835/solr [junit4] 2> 634802 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 634803 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40835/solr [junit4] 2> 634805 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40835/solr [junit4] 2> 634813 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40835/solr [junit4] 2> 634813 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 634814 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 634814 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35244_solr [junit4] 2> 634815 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46011_solr [junit4] 2> 634815 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.c.Overseer Overseer (id=97616923508080646-127.0.0.1:35244_solr-n_0000000000) starting [junit4] 2> 634816 INFO (zkCallback-808-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 634816 INFO (zkCallback-810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 634817 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 634818 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 634818 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 634819 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35244_solr [junit4] 2> 634819 INFO (zkCallback-808-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 634820 INFO (zkCallback-812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 634820 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 634820 INFO (zkCallback-810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 634820 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37839_solr [junit4] 2> 634828 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 634828 INFO (zkCallback-812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 634828 INFO (zkCallback-808-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 634831 INFO (zkCallback-810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 634834 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 634840 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34112_solr [junit4] 2> 634841 INFO (zkCallback-808-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 634841 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 634841 INFO (zkCallback-812-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 634841 INFO (zkCallback-810-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 634940 INFO (jetty-launcher-792-thread-4) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node4/. [junit4] 2> 634951 INFO (jetty-launcher-792-thread-1) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node1/. [junit4] 2> 634959 INFO (jetty-launcher-792-thread-3) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node3/. [junit4] 2> 634975 INFO (jetty-launcher-792-thread-2) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node2/. [junit4] 2> 635397 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 635397 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40835/solr ready [junit4] 2> 635434 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateShouldFailOnExistingCore [junit4] 2> 635435 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[27184E7E60C12F2F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 635488 INFO (qtp695883925-4931) [ ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-002&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker&wt=javabin&version=2 [junit4] 2> 635489 INFO (OverseerStateUpdate-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 636494 INFO (qtp695883925-4931) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 636499 INFO (qtp695883925-4931) [ ] o.a.s.s.IndexSchema [halfcollection_shard1_replica1] Schema name=minimal [junit4] 2> 636500 INFO (qtp695883925-4931) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 636501 INFO (qtp695883925-4931) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard1_replica1' using configuration from collection halfcollectionblocker [junit4] 2> 636501 INFO (qtp695883925-4931) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 636501 INFO (qtp695883925-4931) [ ] o.a.s.c.SolrCore [[halfcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node3/halfcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-002/] [junit4] 2> 636704 INFO (qtp695883925-4931) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 636704 INFO (qtp695883925-4931) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 636705 INFO (qtp695883925-4931) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 636705 INFO (qtp695883925-4931) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 636706 INFO (qtp695883925-4931) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@315e3918[halfcollection_shard1_replica1] main] [junit4] 2> 636706 INFO (qtp695883925-4931) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 636707 INFO (qtp695883925-4931) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 636707 INFO (qtp695883925-4931) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 636707 INFO (searcherExecutor-2180-thread-1) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] Registered new searcher Searcher@315e3918[halfcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 636707 INFO (qtp695883925-4931) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561870778253705216 [junit4] 2> 636710 INFO (qtp695883925-4931) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 636711 INFO (qtp695883925-4931) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 636711 INFO (qtp695883925-4931) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34112/solr/halfcollection_shard1_replica1/ [junit4] 2> 636711 INFO (qtp695883925-4931) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 636711 INFO (qtp695883925-4931) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:34112/solr/halfcollection_shard1_replica1/ has no replicas [junit4] 2> 636711 INFO (qtp695883925-4931) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 636712 INFO (qtp695883925-4931) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34112/solr/halfcollection_shard1_replica1/ shard1 [junit4] 2> 636863 INFO (qtp695883925-4931) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 636865 INFO (qtp695883925-4931) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-002&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker&wt=javabin&version=2} status=0 QTime=1378 [junit4] 2> 636917 INFO (qtp1337149954-4932) [ ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-003&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker2&wt=javabin&version=2 [junit4] 2> 636919 INFO (OverseerStateUpdate-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 637924 INFO (qtp1337149954-4932) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 637928 INFO (qtp1337149954-4932) [ ] o.a.s.s.IndexSchema [halfcollection_shard1_replica1] Schema name=minimal [junit4] 2> 637930 INFO (qtp1337149954-4932) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 637930 INFO (qtp1337149954-4932) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard1_replica1' using configuration from collection halfcollectionblocker2 [junit4] 2> 637930 INFO (qtp1337149954-4932) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 637931 INFO (qtp1337149954-4932) [ ] o.a.s.c.SolrCore [[halfcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node4/halfcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-003/] [junit4] 2> 638137 INFO (qtp1337149954-4932) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 638137 INFO (qtp1337149954-4932) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 638138 INFO (qtp1337149954-4932) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 638138 INFO (qtp1337149954-4932) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 638138 INFO (qtp1337149954-4932) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d0d0a42[halfcollection_shard1_replica1] main] [junit4] 2> 638139 INFO (qtp1337149954-4932) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 638139 INFO (qtp1337149954-4932) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 638139 INFO (qtp1337149954-4932) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 638140 INFO (searcherExecutor-2185-thread-1) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] Registered new searcher Searcher@1d0d0a42[halfcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 638140 INFO (qtp1337149954-4932) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561870779756314624 [junit4] 2> 638143 INFO (qtp1337149954-4932) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 638143 INFO (qtp1337149954-4932) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 638143 INFO (qtp1337149954-4932) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:46011/solr/halfcollection_shard1_replica1/ [junit4] 2> 638143 INFO (qtp1337149954-4932) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 638143 INFO (qtp1337149954-4932) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:46011/solr/halfcollection_shard1_replica1/ has no replicas [junit4] 2> 638143 INFO (qtp1337149954-4932) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 638145 INFO (qtp1337149954-4932) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:46011/solr/halfcollection_shard1_replica1/ shard1 [junit4] 2> 638296 INFO (qtp1337149954-4932) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 638297 INFO (qtp1337149954-4932) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-003&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker2&wt=javabin&version=2} status=0 QTime=1379 [junit4] 2> 638302 INFO (qtp695883925-4942) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfcollection&action=CREATE&numShards=2&createNodeSet=127.0.0.1:34112_solr,127.0.0.1:46011_solr&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 638303 INFO (OverseerThreadFactory-2171-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection halfcollection [junit4] 2> 638511 INFO (qtp1337149954-4944) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfcollection&shard=shard1&wt=javabin&version=2 [junit4] 2> 638511 INFO (qtp695883925-4935) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfcollection&shard=shard2&wt=javabin&version=2 [junit4] 2> 638511 WARN (qtp1337149954-4944) [ ] o.a.s.c.CoreContainer Creating a core with existing name is not allowed [junit4] 2> 638511 ERROR (qtp1337149954-4944) [ ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Core with name 'halfcollection_shard1_replica1' already exists. [junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:834) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:370) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174) [junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395) [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534) [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 638512 INFO (qtp1337149954-4944) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfcollection&shard=shard1&wt=javabin&version=2} status=500 QTime=1 [junit4] 2> 638512 ERROR (qtp1337149954-4944) [ ] o.a.s.s.HttpSolrCall null:org.apache.solr.common.SolrException: Core with name 'halfcollection_shard1_replica1' already exists. [junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:834) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:370) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174) [junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395) [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534) [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 638513 ERROR (OverseerThreadFactory-2171-thread-1) [ ] o.a.s.c.OverseerCollectionMessageHandler Error from shard: https://127.0.0.1:46011/solr [junit4] 2> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:46011/solr: Core with name 'halfcollection_shard1_replica1' already exists. [junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:610) [junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279) [junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268) [junit4] 2> at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) [junit4] 2> at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:163) [junit4] 2> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [junit4] 2> at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [junit4] 2> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [junit4] 2> at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1161) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 638613 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollection/state.json] for collection [halfcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 639518 INFO (qtp695883925-4935) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 639524 INFO (qtp695883925-4935) [ ] o.a.s.s.IndexSchema [halfcollection_shard2_replica1] Schema name=minimal [junit4] 2> 639526 INFO (qtp695883925-4935) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 639526 INFO (qtp695883925-4935) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard2_replica1' using configuration from collection halfcollection [junit4] 2> 639527 INFO (qtp695883925-4935) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 639527 INFO (qtp695883925-4935) [ ] o.a.s.c.SolrCore [[halfcollection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node3/halfcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node3/./halfcollection_shard2_replica1/data/] [junit4] 2> 639886 INFO (qtp695883925-4935) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 639886 INFO (qtp695883925-4935) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 639890 INFO (qtp695883925-4935) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 639890 INFO (qtp695883925-4935) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 639890 INFO (qtp695883925-4935) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2332aa16[halfcollection_shard2_replica1] main] [junit4] 2> 639891 INFO (qtp695883925-4935) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 639891 INFO (qtp695883925-4935) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 639891 INFO (qtp695883925-4935) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 639892 INFO (searcherExecutor-2190-thread-1) [ ] o.a.s.c.SolrCore [halfcollection_shard2_replica1] Registered new searcher Searcher@2332aa16[halfcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 639892 INFO (qtp695883925-4935) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561870781593419776 [junit4] 2> 639895 INFO (qtp695883925-4935) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 639895 INFO (qtp695883925-4935) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 639895 INFO (qtp695883925-4935) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34112/solr/halfcollection_shard2_replica1/ [junit4] 2> 639895 INFO (qtp695883925-4935) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 639895 INFO (qtp695883925-4935) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:34112/solr/halfcollection_shard2_replica1/ has no replicas [junit4] 2> 639895 INFO (qtp695883925-4935) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 639897 INFO (qtp695883925-4935) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34112/solr/halfcollection_shard2_replica1/ shard2 [junit4] 2> 639998 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollection/state.json] for collection [halfcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 640048 INFO (qtp695883925-4935) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 640050 INFO (qtp695883925-4935) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=1539 [junit4] 2> 640050 ERROR (OverseerThreadFactory-2171-thread-1) [ ] o.a.s.c.OverseerCollectionMessageHandler Cleaning up collection [halfcollection]. [junit4] 2> 640050 INFO (OverseerThreadFactory-2171-thread-1) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 640053 INFO (qtp695883925-4931) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection.shard2.replica1 [junit4] 2> 640053 INFO (qtp695883925-4931) [ ] o.a.s.c.SolrCore [halfcollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@60d68514 [junit4] 2> 640054 INFO (qtp695883925-4931) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection.shard2.replica1 [junit4] 2> 640059 INFO (qtp695883925-4931) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfcollection_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=6 [junit4] 2> 640760 INFO (OverseerThreadFactory-2171-thread-1) [ ] o.a.s.c.CreateCollectionCmd Cleaned up artifacts for failed create collection for [halfcollection] [junit4] 2> 640762 INFO (qtp695883925-4942) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 642304 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 670765 ERROR (qtp695883925-4942) [ ] o.a.s.h.a.CollectionsHandler Timed out waiting for new collection's replicas to become ACTIVE with timeout=30 [junit4] 2> 670765 INFO (qtp695883925-4942) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfcollection&action=CREATE&numShards=2&createNodeSet=127.0.0.1:34112_solr,127.0.0.1:46011_solr&wt=javabin&version=2} status=0 QTime=32462 [junit4] 2> 670765 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreateShouldFailOnExistingCore [junit4] 2> 670778 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSpecificConfigsets [junit4] 2> 670778 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[27184E7E60C12F2F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 670780 INFO (qtp695883925-4933) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfcollectionblocker2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 670781 INFO (OverseerThreadFactory-2171-thread-2) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 670785 INFO (qtp1337149954-4936) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 670785 INFO (qtp1337149954-4936) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@5a46d2a2 [junit4] 2> 670786 INFO (qtp1337149954-4936) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 670787 INFO (qtp1337149954-4936) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=2 [junit4] 2> 671490 INFO (qtp695883925-4933) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfcollectionblocker2&action=DELETE&wt=javabin&version=2} status=0 QTime=710 [junit4] 2> 671492 INFO (qtp695883925-4935) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfcollectionblocker&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 671493 INFO (OverseerThreadFactory-2171-thread-3) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 671493 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 671497 INFO (qtp695883925-4940) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 671498 INFO (qtp695883925-4940) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@7fe15fe1 [junit4] 2> 671498 INFO (qtp695883925-4940) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 671501 INFO (qtp695883925-4940) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 672203 INFO (qtp695883925-4935) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfcollectionblocker&action=DELETE&wt=javabin&version=2} status=0 QTime=710 [junit4] 2> 672205 INFO (qtp695883925-4931) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 672206 INFO (OverseerThreadFactory-2171-thread-4) [ ] o.a.s.c.CreateCollectionCmd Create collection withconfigset2 [junit4] 2> 672206 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 672453 INFO (qtp49170951-4912) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2 [junit4] 2> 672556 INFO (zkCallback-812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4]) [junit4] 2> 673458 INFO (qtp49170951-4912) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 673477 INFO (qtp49170951-4912) [ ] o.a.s.s.IndexSchema [withconfigset2_shard1_replica1] Schema name=minimal [junit4] 2> 673478 INFO (qtp49170951-4912) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 673478 INFO (qtp49170951-4912) [ ] o.a.s.c.CoreContainer Creating SolrCore 'withconfigset2_shard1_replica1' using configuration from collection withconfigset2 [junit4] 2> 673479 INFO (qtp49170951-4912) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 673479 INFO (qtp49170951-4912) [ ] o.a.s.c.SolrCore [[withconfigset2_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node2/withconfigset2_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node2/./withconfigset2_shard1_replica1/data/] [junit4] 2> 673479 INFO (qtp49170951-4912) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@209fbad1 [junit4] 2> 673656 INFO (qtp49170951-4912) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 673656 INFO (qtp49170951-4912) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 673658 INFO (qtp49170951-4912) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 673658 INFO (qtp49170951-4912) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 673659 INFO (qtp49170951-4912) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@34fe66d3[withconfigset2_shard1_replica1] main] [junit4] 2> 673660 INFO (qtp49170951-4912) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2 [junit4] 2> 673660 INFO (qtp49170951-4912) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2 [junit4] 2> 673660 INFO (qtp49170951-4912) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 673660 INFO (searcherExecutor-2195-thread-1) [ ] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] Registered new searcher Searcher@34fe66d3[withconfigset2_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 673660 INFO (qtp49170951-4912) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561870817001734144 [junit4] 2> 673664 INFO (qtp49170951-4912) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 673664 INFO (qtp49170951-4912) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 673664 INFO (qtp49170951-4912) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:37839/solr/withconfigset2_shard1_replica1/ [junit4] 2> 673664 INFO (qtp49170951-4912) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 673664 INFO (qtp49170951-4912) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:37839/solr/withconfigset2_shard1_replica1/ has no replicas [junit4] 2> 673664 INFO (qtp49170951-4912) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 673665 INFO (qtp49170951-4912) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:37839/solr/withconfigset2_shard1_replica1/ shard1 [junit4] 2> 673767 INFO (zkCallback-812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4]) [junit4] 2> 673816 INFO (qtp49170951-4912) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 673817 INFO (qtp49170951-4912) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2} status=0 QTime=1364 [junit4] 2> 673818 INFO (qtp695883925-4931) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 673917 INFO (zkCallback-812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4]) [junit4] 2> 674207 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 674819 INFO (qtp695883925-4931) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2614 [junit4] 2> 674819 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSpecificConfigsets [junit4] 2> 674836 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas [junit4] 2> 674836 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[27184E7E60C12F2F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 674838 INFO (qtp695883925-4937) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=withconfigset2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 674840 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 674842 INFO (qtp49170951-4922) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.withconfigset2.shard1.replica1 [junit4] 2> 674842 INFO (qtp49170951-4922) [ ] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@64b0b493 [junit4] 2> 674860 INFO (qtp49170951-4922) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.withconfigset2.shard1.replica1 [junit4] 2> 674864 INFO (qtp49170951-4922) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=withconfigset2_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=21 [junit4] 2> 675566 INFO (qtp695883925-4937) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=withconfigset2&action=DELETE&wt=javabin&version=2} status=0 QTime=727 [junit4] 2> 675569 INFO (qtp695883925-4940) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 675570 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection collection [junit4] 2> 675570 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 675570 WARN (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.CreateCollectionCmd Specified replicationFactor of 10 on collection collection is higher than or equal to the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance. [junit4] 2> 675570 ERROR (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2 and value of replicationFactor is 10. This requires 20 shards to be created (higher than the allowed number) [junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1161) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 675572 INFO (qtp695883925-4940) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=3 [junit4] 2> 675572 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas [junit4] 2> 675589 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testZeroNumShards [junit4] 2> 675589 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[27184E7E60C12F2F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 675592 INFO (qtp695883925-4935) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 675593 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection acollection [junit4] 2> 675593 ERROR (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards must be > 0 [junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:124) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1161) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 675593 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000010 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 675595 INFO (qtp695883925-4935) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2} status=400 QTime=2 [junit4] 2> 675595 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testZeroNumShards [junit4] 2> 675619 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard [junit4] 2> 675620 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[27184E7E60C12F2F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 675623 INFO (qtp695883925-4931) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=oversharded&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 675625 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection oversharded [junit4] 2> 675625 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000012 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 675625 ERROR (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: oversharded operation: create failed:org.apache.solr.common.SolrException: Cannot create collection oversharded. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 3 and value of replicationFactor is 2. This requires 6 shards to be created (higher than the allowed number) [junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1161) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 675628 INFO (qtp695883925-4931) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=oversharded&action=CREATE&numShards=3&wt=javabin&version=2} status=400 QTime=4 [junit4] 2> 675628 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMaxNodesPerShard [junit4] 2> 675651 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreationAndDeletion [junit4] 2> 675651 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[27184E7E60C12F2F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 675654 INFO (qtp695883925-4937) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=created_and_deleted&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 675655 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection created_and_deleted [junit4] 2> 675656 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000014 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 675861 INFO (qtp695883925-4942) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=created_and_deleted_shard1_replica1&action=CREATE&numShards=1&collection=created_and_deleted&shard=shard1&wt=javabin&version=2 [junit4] 2> 675963 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/created_and_deleted/state.json] for collection [created_and_deleted] has occurred - updating... (live nodes size: [4]) [junit4] 2> 676879 INFO (qtp695883925-4942) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 676886 INFO (qtp695883925-4942) [ ] o.a.s.s.IndexSchema [created_and_deleted_shard1_replica1] Schema name=minimal [junit4] 2> 676888 INFO (qtp695883925-4942) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 676889 INFO (qtp695883925-4942) [ ] o.a.s.c.CoreContainer Creating SolrCore 'created_and_deleted_shard1_replica1' using configuration from collection created_and_deleted [junit4] 2> 676889 INFO (qtp695883925-4942) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 676889 INFO (qtp695883925-4942) [ ] o.a.s.c.SolrCore [[created_and_deleted_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node3/created_and_deleted_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node3/./created_and_deleted_shard1_replica1/data/] [junit4] 2> 677095 INFO (qtp695883925-4942) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 677095 INFO (qtp695883925-4942) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 677097 INFO (qtp695883925-4942) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 677097 INFO (qtp695883925-4942) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 677097 INFO (qtp695883925-4942) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@60d7af4b[created_and_deleted_shard1_replica1] main] [junit4] 2> 677098 INFO (qtp695883925-4942) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 677098 INFO (qtp695883925-4942) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 677098 INFO (qtp695883925-4942) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 677098 INFO (searcherExecutor-2200-thread-1) [ ] o.a.s.c.SolrCore [created_and_deleted_shard1_replica1] Registered new searcher Searcher@60d7af4b[created_and_deleted_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 677099 INFO (qtp695883925-4942) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561870820607787008 [junit4] 2> 677102 INFO (qtp695883925-4942) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 677102 INFO (qtp695883925-4942) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 677102 INFO (qtp695883925-4942) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34112/solr/created_and_deleted_shard1_replica1/ [junit4] 2> 677102 INFO (qtp695883925-4942) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 677102 INFO (qtp695883925-4942) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:34112/solr/created_and_deleted_shard1_replica1/ has no replicas [junit4] 2> 677102 INFO (qtp695883925-4942) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 677104 INFO (qtp695883925-4942) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34112/solr/created_and_deleted_shard1_replica1/ shard1 [junit4] 2> 677205 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/created_and_deleted/state.json] for collection [created_and_deleted] has occurred - updating... (live nodes size: [4]) [junit4] 2> 677255 INFO (qtp695883925-4942) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 677257 INFO (qtp695883925-4942) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=created_and_deleted_shard1_replica1&action=CREATE&numShards=1&collection=created_and_deleted&shard=shard1&wt=javabin&version=2} status=0 QTime=1396 [junit4] 2> 677258 INFO (qtp695883925-4937) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 677358 INFO (zkCallback-816-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/created_and_deleted/state.json] for collection [created_and_deleted] has occurred - updating... (live nodes size: [4]) [junit4] 2> 677657 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000016 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 678258 INFO (qtp695883925-4937) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=created_and_deleted&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2604 [junit4] 2> 678260 INFO (qtp695883925-4940) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 678260 INFO (qtp695883925-4940) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 678262 INFO (qtp695883925-4931) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=created_and_deleted&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 678263 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 678265 INFO (qtp695883925-4935) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.created_and_deleted.shard1.replica1 [junit4] 2> 678265 INFO (qtp695883925-4935) [ ] o.a.s.c.SolrCore [created_and_deleted_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@19a424c1 [junit4] 2> 678267 INFO (qtp695883925-4935) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.created_and_deleted.shard1.replica1 [junit4] 2> 678271 INFO (qtp695883925-4935) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=created_and_deleted_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=6 [junit4] 2> 678974 INFO (qtp695883925-4931) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=created_and_deleted&action=DELETE&wt=javabin&version=2} status=0 QTime=711 [junit4] 2> 678975 INFO (qtp695883925-4942) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 678976 INFO (qtp695883925-4942) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 678976 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreationAndDeletion [junit4] 2> 678993 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[27184E7E60C12F2F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection [junit4] 2> 678994 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[27184E7E60C12F2F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 678996 INFO (qtp695883925-4940) [ ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-004&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2 [junit4] 2> 678997 INFO (OverseerStateUpdate-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 680002 INFO (qtp695883925-4940) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 680007 INFO (qtp695883925-4940) [ ] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal [junit4] 2> 680009 INFO (qtp695883925-4940) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 680009 INFO (qtp695883925-4940) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection [junit4] 2> 680009 INFO (qtp695883925-4940) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 680009 INFO (qtp695883925-4940) [ ] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-001/node3/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-004/] [junit4] 2> 680186 INFO (qtp695883925-4940) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 680186 INFO (qtp695883925-4940) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 680187 INFO (qtp695883925-4940) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 680187 INFO (qtp695883925-4940) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 680188 INFO (qtp695883925-4940) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@76c454c[halfdeletedcollection_shard1_replica1] main] [junit4] 2> 680189 INFO (qtp695883925-4940) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 680189 INFO (qtp695883925-4940) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 680189 INFO (qtp695883925-4940) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 680189 INFO (searcherExecutor-2205-thread-1) [ ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@76c454c[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 680189 INFO (qtp695883925-4940) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561870823847886848 [junit4] 2> 680193 INFO (qtp695883925-4940) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 680193 INFO (qtp695883925-4940) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 680193 INFO (qtp695883925-4940) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34112/solr/halfdeletedcollection_shard1_replica1/ [junit4] 2> 680193 INFO (qtp695883925-4940) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 680193 INFO (qtp695883925-4940) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:34112/solr/halfdeletedcollection_shard1_replica1/ has no replicas [junit4] 2> 680193 INFO (qtp695883925-4940) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 680194 INFO (qtp695883925-4940) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34112/solr/halfdeletedcollection_shard1_replica1/ shard2 [junit4] 2> 680264 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000018 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 680345 INFO (qtp695883925-4940) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 680346 INFO (qtp695883925-4940) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001/tempDir-004&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2} status=0 QTime=1350 [junit4] 2> 680348 INFO (qtp695883925-4935) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 680349 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 680360 INFO (qtp695883925-4937) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1 [junit4] 2> 680360 INFO (qtp695883925-4937) [ ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@573a063c [junit4] 2> 680361 INFO (qtp695883925-4937) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1 [junit4] 2> 680363 INFO (qtp695883925-4937) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=12 [junit4] 2> 681065 INFO (qtp695883925-4935) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=716 [junit4] 2> 681067 INFO (qtp695883925-4931) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 681067 INFO (qtp695883925-4931) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 681068 INFO (qtp695883925-4940) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 681070 INFO (OverseerThreadFactory-2171-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection halfdeletedcollection [junit4] 2> 681070 INFO (OverseerCollectionConfigSetProcessor-97616923508080646-127.0.0.1:35244_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000020 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 681277 INFO (qtp49170951-4926) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2 [junit4] 2> 681321 INFO (qtp1896940592-4911) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2 [junit4] 2> 681423 INFO (zkCallback-812-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 681423 INFO (zkCallback-808-thread-7) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4]) [junit4] 2> 682282 INFO (qtp49170951-4926) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0 [junit4] 2> 682289 INFO (qtp49170951-4926) [ ] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal [junit4] 2> 682290 INFO (qtp49170951-4926) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 682291 INFO (qtp49170951-4926) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection [junit4] [...truncated too long message...] nager Closing metric reporters for: solr.node [junit4] 2> 742624 INFO (jetty-closer-793-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1dfcc1f5{/solr,null,UNAVAILABLE} [junit4] 2> 743354 ERROR (qtp1896940592-4917) [ ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Solr is shutting down [junit4] 2> at org.apache.solr.handler.admin.PrepRecoveryOp.execute(PrepRecoveryOp.java:183) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:370) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174) [junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:462) [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534) [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) [junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 743354 INFO (qtp1896940592-4917) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:37839_solr&onlyIfLeaderActive=true&core=addReplicaColl_shard1_replica2&coreNodeName=core_node7&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=400 QTime=8004 [junit4] 2> 744122 WARN (zkCallback-810-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 744123 WARN (zkCallback-841-thread-5) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 744123 INFO (jetty-closer-793-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 744123 INFO (jetty-closer-793-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 744123 INFO (jetty-closer-793-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3c1633f7{/solr,null,UNAVAILABLE} [junit4] 2> 744123 INFO (jetty-closer-793-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1a013526{/solr,null,UNAVAILABLE} [junit4] 2> 744124 WARN (zkCallback-808-thread-4) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 744124 INFO (jetty-closer-793-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 744124 INFO (jetty-closer-793-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@472c34be{/solr,null,UNAVAILABLE} [junit4] 2> 744125 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40835 40835 [junit4] 2> 744146 INFO (Thread-1220) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40835 40835 [junit4] 2> 744146 WARN (Thread-1220) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 11 /solr/configs/conf [junit4] 2> 6 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 132 /solr/clusterstate.json [junit4] 2> 6 /solr/clusterprops.json [junit4] 2> 4 /solr/collections/nodes_used_collection/state.json [junit4] 2> 4 /solr/collections/addReplicaColl/state.json [junit4] 2> 2 /solr/collections/onlyinzk/state.json [junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard2/election/97616923508080652-core_node2-n_0000000000 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 241 /solr/collections [junit4] 2> 39 /solr/overseer/queue [junit4] 2> 6 /solr/live_nodes [junit4] 2> 6 /solr/overseer/collection-queue-work [junit4] 2> 6 /solr/overseer/queue-work [junit4] 2> [junit4] 2> 744146 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[27184E7E60C12F2F]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_27184E7E60C12F2F-001 [junit4] 2> Mar 14, 2017 6:29:14 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Lucene62, sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=de-LU, timezone=America/Indiana/Knox [junit4] 2> NOTE: Linux 4.4.0-66-generic amd64/Oracle Corporation 9-ea (64-bit)/cpus=12,threads=1,free=200244608,total=518979584 [junit4] 2> NOTE: All tests run in this JVM: [IndexSchemaRuntimeFieldTest, TestSolrXml, BlockJoinFacetRandomTest, TestStandardQParsers, SolrCmdDistributorTest, SSLMigrationTest, ShardRoutingCustomTest, ClassificationUpdateProcessorFactoryTest, RequestLoggingTest, SolrGraphiteReporterTest, SpellCheckComponentTest, SpellingQueryConverterTest, HdfsRecoveryZkTest, TestSolrCloudWithDelegationTokens, VersionInfoTest, TestCloudSchemaless, ConnectionManagerTest, UUIDUpdateProcessorFallbackTest, ResponseHeaderTest, TestStressVersions, OverseerStatusTest, DistributedQueueTest, V2ApiIntegrationTest, SearchHandlerTest, HighlighterTest, TestSolrIndexConfig, BadCopyFieldTest, TestComplexPhraseLeadingWildcard, SolrInfoMBeanTest, TestMissingGroups, CoreSorterTest, SliceStateTest, SpatialFilterTest, URLClassifyProcessorTest, TestFieldCacheVsDocValues, TriLevelCompositeIdRoutingTest, EchoParamsTest, TestApiFramework, IndexBasedSpellCheckerTest, TestFuzzyAnalyzedSuggestions, TestQueryTypes, TestPivotHelperCode, TestCharFilters, ZkCLITest, DistributedQueryComponentCustomSortTest, TestRandomRequestDistribution, HighlighterMaxOffsetTest, MultiThreadedOCPTest, HdfsDirectoryFactoryTest, TestLRUStatsCache, JSONWriterTest, TestFastOutputStream, TestLRUCache, TestCustomDocTransformer, ManagedSchemaRoundRobinCloudTest, TestXmlQParser, TestSearchPerf, SolrIndexSplitterTest, TestHighFrequencyDictionaryFactory, TemplateUpdateProcessorTest, DistributedMLTComponentTest, TestBulkSchemaConcurrent, TestSegmentSorting, ClusterStateUpdateTest, TestReRankQParserPlugin, SharedFSAutoReplicaFailoverTest, TestSchemaResource, TestMiniSolrCloudClusterSSL, TestShardHandlerFactory, TestSchemaManager, CollectionsAPIDistributedZkTest] [junit4] Completed [243/698 (1!)] on J1 in 110.49s, 20 tests, 1 error <<< FAILURES! [...truncated 53211 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
