Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/2532/ Java: 64bit/jdk-9-ea+147 -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:41295/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":5},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:41295/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":5},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([31FBC57DD31D8ED4:798EB1C9D52EA141]: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:1344) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1095) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1198) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1198) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1198) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1198) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1198) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1037) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:149) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:516) 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:538) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at java.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 12046 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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/init-core-data-001 [junit4] 2> 822391 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0) [junit4] 2> 822394 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001 [junit4] 2> 822395 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 822396 INFO (Thread-1773) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 822396 INFO (Thread-1773) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 822496 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:45571 [junit4] 2> 822503 INFO (jetty-launcher-968-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 822503 INFO (jetty-launcher-968-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 822503 INFO (jetty-launcher-968-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 822507 INFO (jetty-launcher-968-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5c52e370{/solr,null,AVAILABLE} [junit4] 2> 822508 INFO (jetty-launcher-968-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@50c5d095{/solr,null,AVAILABLE} [junit4] 2> 822509 INFO (jetty-launcher-968-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@17acff7{/solr,null,AVAILABLE} [junit4] 2> 822509 INFO (jetty-launcher-968-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@76dc7d2e{SSL,[ssl, http/1.1]}{127.0.0.1:41295} [junit4] 2> 822509 INFO (jetty-launcher-968-thread-2) [ ] o.e.j.s.Server Started @824354ms [junit4] 2> 822509 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41295} [junit4] 2> 822509 INFO (jetty-launcher-968-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@45c81631{SSL,[ssl, http/1.1]}{127.0.0.1:41014} [junit4] 2> 822509 INFO (jetty-launcher-968-thread-1) [ ] o.e.j.s.Server Started @824354ms [junit4] 2> 822509 ERROR (jetty-launcher-968-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 822509 INFO (jetty-launcher-968-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@424d2774{SSL,[ssl, http/1.1]}{127.0.0.1:40949} [junit4] 2> 822509 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41014} [junit4] 2> 822511 INFO (jetty-launcher-968-thread-3) [ ] o.e.j.s.Server Started @824356ms [junit4] 2> 822511 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40949} [junit4] 2> 822511 ERROR (jetty-launcher-968-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 822511 ERROR (jetty-launcher-968-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 822511 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0 [junit4] 2> 822511 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0 [junit4] 2> 822511 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 822511 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 822511 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 822512 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 822512 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-28T14:23:38.258027Z [junit4] 2> 822512 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-28T14:23:38.258069Z [junit4] 2> 822512 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0 [junit4] 2> 822512 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 822512 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 822513 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-28T14:23:38.259Z [junit4] 2> 822514 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 822515 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 822515 INFO (jetty-launcher-968-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 822521 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 822522 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 822522 INFO (jetty-launcher-968-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5109db7a{/solr,null,AVAILABLE} [junit4] 2> 822523 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45571/solr [junit4] 2> 822523 INFO (jetty-launcher-968-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@41e88ea7{SSL,[ssl, http/1.1]}{127.0.0.1:44735} [junit4] 2> 822523 INFO (jetty-launcher-968-thread-4) [ ] o.e.j.s.Server Started @824368ms [junit4] 2> 822523 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44735} [junit4] 2> 822524 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 822525 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45571/solr [junit4] 2> 822525 ERROR (jetty-launcher-968-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 822526 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.4.0 [junit4] 2> 822526 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 822526 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 822526 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-28T14:23:38.272447Z [junit4] 2> 822528 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 822535 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 822537 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45571/solr [junit4] 2> 822539 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15945d0a2a30006, likely client has closed socket [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228) [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 822541 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true [junit4] 2> 822543 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45571/solr [junit4] 2> 822550 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40949_solr [junit4] 2> 822558 INFO (jetty-launcher-968-thread-1) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41014_solr [junit4] 2> 822558 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.c.Overseer Overseer (id=97185629349281799-127.0.0.1:40949_solr-n_0000000000) starting [junit4] 2> 822559 INFO (zkCallback-981-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 822560 INFO (zkCallback-980-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 822561 INFO (zkCallback-985-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 822561 INFO (zkCallback-991-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 822563 INFO (jetty-launcher-968-thread-2) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41295_solr [junit4] 2> 822563 INFO (jetty-launcher-968-thread-4) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44735_solr [junit4] 2> 822565 INFO (zkCallback-981-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3) [junit4] 2> 822566 INFO (zkCallback-980-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3) [junit4] 2> 822566 INFO (zkCallback-985-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3) [junit4] 2> 822573 INFO (jetty-launcher-968-thread-3) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40949_solr [junit4] 2> 822576 INFO (zkCallback-981-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 822576 INFO (zkCallback-985-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 822576 INFO (zkCallback-980-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 822578 INFO (zkCallback-991-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3) [junit4] 2> 822590 INFO (zkCallback-991-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 822609 INFO (jetty-launcher-968-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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node2/. [junit4] 2> 822619 INFO (jetty-launcher-968-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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node1/. [junit4] 2> 822624 INFO (jetty-launcher-968-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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node4/. [junit4] 2> 822629 INFO (jetty-launcher-968-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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node3/. [junit4] 2> 823026 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 823027 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45571/solr ready [junit4] 2> 823053 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas [junit4] 2> 823054 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 823106 INFO (qtp1977710531-6710) [ ] 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> 823108 INFO (OverseerThreadFactory-3737-thread-1) [ ] o.a.s.c.CreateCollectionCmd Create collection collection [junit4] 2> 823108 WARN (OverseerThreadFactory-3737-thread-1) [ ] 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> 823109 ERROR (OverseerThreadFactory-3737-thread-1) [ ] 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> 823112 INFO (qtp1977710531-6710) [ ] 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=5 [junit4] 2> 823112 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas [junit4] 2> 823134 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateShouldFailOnExistingCore [junit4] 2> 823135 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 823189 INFO (qtp991059057-6744) [ ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-002&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker&wt=javabin&version=2 [junit4] 2> 823191 INFO (OverseerStateUpdate-97185629349281799-127.0.0.1:40949_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 824203 INFO (qtp991059057-6744) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 824213 INFO (qtp991059057-6744) [ ] o.a.s.s.IndexSchema [halfcollection_shard1_replica1] Schema name=minimal [junit4] 2> 824216 INFO (qtp991059057-6744) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 824217 INFO (qtp991059057-6744) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard1_replica1' using configuration from collection halfcollectionblocker [junit4] 2> 824218 INFO (qtp991059057-6744) [ ] 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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node4/halfcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-002/] [junit4] 2> 824233 INFO (qtp991059057-6744) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 824233 INFO (qtp991059057-6744) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 824236 INFO (qtp991059057-6744) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 824236 INFO (qtp991059057-6744) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 824237 INFO (qtp991059057-6744) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3be36343[halfcollection_shard1_replica1] main] [junit4] 2> 824238 INFO (qtp991059057-6744) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 824238 INFO (qtp991059057-6744) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 824238 INFO (qtp991059057-6744) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 824238 INFO (searcherExecutor-3746-thread-1) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] Registered new searcher Searcher@3be36343[halfcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 824238 INFO (qtp991059057-6744) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554970071514742784 [junit4] 2> 824245 INFO (qtp991059057-6744) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 824245 INFO (qtp991059057-6744) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 824245 INFO (qtp991059057-6744) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:44735/solr/halfcollection_shard1_replica1/ [junit4] 2> 824245 INFO (qtp991059057-6744) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 824245 INFO (qtp991059057-6744) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:44735/solr/halfcollection_shard1_replica1/ has no replicas [junit4] 2> 824250 INFO (qtp991059057-6744) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:44735/solr/halfcollection_shard1_replica1/ shard1 [junit4] 2> 824401 INFO (qtp991059057-6744) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 824403 INFO (qtp991059057-6744) [ ] 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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-002&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker&wt=javabin&version=2} status=0 QTime=1215 [junit4] 2> 824453 INFO (qtp359200126-6722) [ ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-003&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker2&wt=javabin&version=2 [junit4] 2> 824454 INFO (OverseerStateUpdate-97185629349281799-127.0.0.1:40949_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 825109 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 825473 INFO (qtp359200126-6722) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 825479 INFO (qtp359200126-6722) [ ] o.a.s.s.IndexSchema [halfcollection_shard1_replica1] Schema name=minimal [junit4] 2> 825481 INFO (qtp359200126-6722) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 825482 INFO (qtp359200126-6722) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard1_replica1' using configuration from collection halfcollectionblocker2 [junit4] 2> 825482 INFO (qtp359200126-6722) [ ] 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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node3/halfcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-003/] [junit4] 2> 825491 INFO (qtp359200126-6722) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 825491 INFO (qtp359200126-6722) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 825493 INFO (qtp359200126-6722) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 825493 INFO (qtp359200126-6722) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 825494 INFO (qtp359200126-6722) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@565371ac[halfcollection_shard1_replica1] main] [junit4] 2> 825494 INFO (qtp359200126-6722) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 825495 INFO (qtp359200126-6722) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 825495 INFO (qtp359200126-6722) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 825495 INFO (searcherExecutor-3751-thread-1) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] Registered new searcher Searcher@565371ac[halfcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 825495 INFO (qtp359200126-6722) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554970072832802816 [junit4] 2> 825498 INFO (qtp359200126-6722) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 825499 INFO (qtp359200126-6722) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 825499 INFO (qtp359200126-6722) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:40949/solr/halfcollection_shard1_replica1/ [junit4] 2> 825499 INFO (qtp359200126-6722) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 825499 INFO (qtp359200126-6722) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:40949/solr/halfcollection_shard1_replica1/ has no replicas [junit4] 2> 825500 INFO (qtp359200126-6722) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:40949/solr/halfcollection_shard1_replica1/ shard1 [junit4] 2> 825651 INFO (qtp359200126-6722) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 825653 INFO (qtp359200126-6722) [ ] 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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-003&collection.configName=conf&name=halfcollection_shard1_replica1&action=CREATE&numShards=1&collection=halfcollectionblocker2&wt=javabin&version=2} status=0 QTime=1200 [junit4] 2> 825656 INFO (qtp1977710531-6731) [ ] 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:44735_solr,127.0.0.1:40949_solr&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 825657 INFO (OverseerThreadFactory-3737-thread-2) [ ] o.a.s.c.CreateCollectionCmd Create collection halfcollection [junit4] 2> 825866 INFO (qtp359200126-6719) [ ] 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> 825866 INFO (qtp991059057-6752) [ ] 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> 825867 WARN (qtp359200126-6719) [ ] o.a.s.c.CoreContainer Creating a core with existing name is not allowed [junit4] 2> 825867 ERROR (qtp359200126-6719) [ ] 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:799) [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:377) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:365) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:156) [junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:169) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:664) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:445) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:296) [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:110) [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> 825868 INFO (qtp359200126-6719) [ ] 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> 825868 ERROR (qtp359200126-6719) [ ] 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:799) [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:377) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:365) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:156) [junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:169) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:664) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:445) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:296) [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:110) [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> 825868 ERROR (OverseerThreadFactory-3737-thread-2) [ ] o.a.s.c.OverseerCollectionMessageHandler Error from shard: https://127.0.0.1:40949/solr [junit4] 2> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:40949/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 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> 825970 INFO (zkCallback-991-thread-2) [ ] 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> 826873 INFO (qtp991059057-6752) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 826879 INFO (qtp991059057-6752) [ ] o.a.s.s.IndexSchema [halfcollection_shard2_replica1] Schema name=minimal [junit4] 2> 826881 INFO (qtp991059057-6752) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 826882 INFO (qtp991059057-6752) [ ] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard2_replica1' using configuration from collection halfcollection [junit4] 2> 826882 INFO (qtp991059057-6752) [ ] 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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node4/halfcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node4/./halfcollection_shard2_replica1/data/] [junit4] 2> 826890 INFO (qtp991059057-6752) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 826891 INFO (qtp991059057-6752) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 826895 INFO (qtp991059057-6752) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 826895 INFO (qtp991059057-6752) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 826895 INFO (qtp991059057-6752) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@368d2de7[halfcollection_shard2_replica1] main] [junit4] 2> 826895 INFO (qtp991059057-6752) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 826896 INFO (qtp991059057-6752) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 826896 INFO (qtp991059057-6752) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 826896 INFO (searcherExecutor-3756-thread-1) [ ] o.a.s.c.SolrCore [halfcollection_shard2_replica1] Registered new searcher Searcher@368d2de7[halfcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 826896 INFO (qtp991059057-6752) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554970074301857792 [junit4] 2> 826900 INFO (qtp991059057-6752) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 826900 INFO (qtp991059057-6752) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 826900 INFO (qtp991059057-6752) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:44735/solr/halfcollection_shard2_replica1/ [junit4] 2> 826900 INFO (qtp991059057-6752) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 826900 INFO (qtp991059057-6752) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:44735/solr/halfcollection_shard2_replica1/ has no replicas [junit4] 2> 826902 INFO (qtp991059057-6752) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:44735/solr/halfcollection_shard2_replica1/ shard2 [junit4] 2> 827003 INFO (zkCallback-991-thread-2) [ ] 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> 827052 INFO (qtp991059057-6752) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 827069 INFO (qtp991059057-6752) [ ] 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=1203 [junit4] 2> 827070 ERROR (OverseerThreadFactory-3737-thread-2) [ ] o.a.s.c.OverseerCollectionMessageHandler Cleaning up collection [halfcollection]. [junit4] 2> 827070 INFO (OverseerThreadFactory-3737-thread-2) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 827072 INFO (qtp991059057-6747) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard2_replica1 [junit4] 2> 827072 INFO (qtp991059057-6747) [ ] o.a.s.c.SolrCore [halfcollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@416947ce [junit4] 2> 827073 INFO (qtp991059057-6747) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection.shard2.replica1 [junit4] 2> 827083 INFO (qtp991059057-6747) [ ] 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=11 [junit4] 2> 827785 INFO (OverseerThreadFactory-3737-thread-2) [ ] o.a.s.c.CreateCollectionCmd Cleaned up artifacts for failed create collection for [halfcollection] [junit4] 2> 827786 INFO (qtp1977710531-6731) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 829658 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 857789 ERROR (qtp1977710531-6731) [ ] o.a.s.h.a.CollectionsHandler Timed out waiting for new collection's replicas to become ACTIVE with timeout=30 [junit4] 2> 857789 INFO (qtp1977710531-6731) [ ] 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:44735_solr,127.0.0.1:40949_solr&wt=javabin&version=2} status=0 QTime=32133 [junit4] 2> 857790 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreateShouldFailOnExistingCore [junit4] 2> 857824 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionOnlyInZk [junit4] 2> 857825 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 857828 INFO (qtp1977710531-6725) [ ] 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> 857848 INFO (OverseerThreadFactory-3737-thread-3) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 857860 INFO (qtp359200126-6719) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 857860 INFO (qtp359200126-6719) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@52dd2555 [junit4] 2> 857861 INFO (qtp359200126-6719) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 857868 INFO (qtp359200126-6719) [ ] 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=9 [junit4] 2> 858576 INFO (qtp1977710531-6725) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfcollectionblocker2&action=DELETE&wt=javabin&version=2} status=0 QTime=748 [junit4] 2> 858579 INFO (qtp1977710531-6730) [ ] 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> 858580 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 858581 INFO (OverseerThreadFactory-3737-thread-4) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 858586 INFO (qtp991059057-6752) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 858586 INFO (qtp991059057-6752) [ ] o.a.s.c.SolrCore [halfcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@7ebd5d2d [junit4] 2> 858587 INFO (qtp991059057-6752) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfcollection_shard1_replica1 [junit4] 2> 858593 INFO (qtp991059057-6752) [ ] 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=7 [junit4] 2> 859296 INFO (qtp1977710531-6730) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfcollectionblocker&action=DELETE&wt=javabin&version=2} status=0 QTime=717 [junit4] 2> 859301 INFO (qtp1977710531-6731) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=onlyinzk&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 859303 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 859306 INFO (qtp1977710531-6731) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=4 [junit4] 2> 859308 INFO (qtp1977710531-6710) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 859308 INFO (qtp1977710531-6710) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 859310 INFO (qtp1977710531-6710) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=onlyinzk&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 859311 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection onlyinzk [junit4] 2> 859311 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 859519 INFO (qtp359200126-6724) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard1_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard1&wt=javabin&version=2 [junit4] 2> 859520 INFO (qtp1977710531-6725) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard2_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard2&wt=javabin&version=2 [junit4] 2> 859623 INFO (zkCallback-985-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4]) [junit4] 2> 859624 INFO (zkCallback-980-thread-6) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4]) [junit4] 2> 860528 INFO (qtp1977710531-6725) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 860528 INFO (qtp359200126-6724) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 860536 INFO (qtp1977710531-6725) [ ] o.a.s.s.IndexSchema [onlyinzk_shard2_replica1] Schema name=minimal [junit4] 2> 860536 INFO (qtp359200126-6724) [ ] o.a.s.s.IndexSchema [onlyinzk_shard1_replica1] Schema name=minimal [junit4] 2> 860539 INFO (qtp1977710531-6725) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 860539 INFO (qtp359200126-6724) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 860539 INFO (qtp359200126-6724) [ ] o.a.s.c.CoreContainer Creating SolrCore 'onlyinzk_shard1_replica1' using configuration from collection onlyinzk [junit4] 2> 860539 INFO (qtp1977710531-6725) [ ] o.a.s.c.CoreContainer Creating SolrCore 'onlyinzk_shard2_replica1' using configuration from collection onlyinzk [junit4] 2> 860540 INFO (qtp359200126-6724) [ ] o.a.s.c.SolrCore [[onlyinzk_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node3/onlyinzk_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node3/./onlyinzk_shard1_replica1/data/] [junit4] 2> 860540 INFO (qtp1977710531-6725) [ ] o.a.s.c.SolrCore [[onlyinzk_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node1/onlyinzk_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node1/./onlyinzk_shard2_replica1/data/] [junit4] 2> 860554 INFO (qtp1977710531-6725) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 860554 INFO (qtp359200126-6724) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 860554 INFO (qtp1977710531-6725) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 860554 INFO (qtp359200126-6724) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 860602 INFO (qtp359200126-6724) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 860602 INFO (qtp359200126-6724) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 860602 INFO (qtp359200126-6724) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@69d601ab[onlyinzk_shard1_replica1] main] [junit4] 2> 860602 INFO (qtp1977710531-6725) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 860602 INFO (qtp1977710531-6725) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 860602 INFO (qtp1977710531-6725) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3a7ca6e4[onlyinzk_shard2_replica1] main] [junit4] 2> 860603 INFO (qtp359200126-6724) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 860603 INFO (qtp359200126-6724) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 860603 INFO (qtp1977710531-6725) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 860603 INFO (qtp359200126-6724) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 860603 INFO (qtp1977710531-6725) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 860603 INFO (qtp1977710531-6725) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 860603 INFO (searcherExecutor-3762-thread-1) [ ] o.a.s.c.SolrCore [onlyinzk_shard2_replica1] Registered new searcher Searcher@3a7ca6e4[onlyinzk_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 860603 INFO (searcherExecutor-3761-thread-1) [ ] o.a.s.c.SolrCore [onlyinzk_shard1_replica1] Registered new searcher Searcher@69d601ab[onlyinzk_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 860603 INFO (qtp359200126-6724) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554970109646209024 [junit4] 2> 860603 INFO (qtp1977710531-6725) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554970109646209024 [junit4] 2> 860608 INFO (qtp1977710531-6725) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 860608 INFO (qtp1977710531-6725) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 860608 INFO (qtp359200126-6724) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 860608 INFO (qtp359200126-6724) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 860608 INFO (qtp1977710531-6725) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:41014/solr/onlyinzk_shard2_replica1/ [junit4] 2> 860608 INFO (qtp359200126-6724) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:40949/solr/onlyinzk_shard1_replica1/ [junit4] 2> 860608 INFO (qtp1977710531-6725) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 860608 INFO (qtp359200126-6724) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 860609 INFO (qtp1977710531-6725) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:41014/solr/onlyinzk_shard2_replica1/ has no replicas [junit4] 2> 860609 INFO (qtp359200126-6724) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:40949/solr/onlyinzk_shard1_replica1/ has no replicas [junit4] 2> 860611 INFO (qtp1977710531-6725) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:41014/solr/onlyinzk_shard2_replica1/ shard2 [junit4] 2> 860611 INFO (qtp359200126-6724) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:40949/solr/onlyinzk_shard1_replica1/ shard1 [junit4] 2> 860713 INFO (zkCallback-980-thread-5) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4]) [junit4] 2> 860713 INFO (zkCallback-985-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4]) [junit4] 2> 860762 INFO (qtp1977710531-6725) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 860762 INFO (qtp359200126-6724) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 860775 INFO (qtp1977710531-6725) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard2_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard2&wt=javabin&version=2} status=0 QTime=1255 [junit4] 2> 860775 INFO (qtp359200126-6724) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard1_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard1&wt=javabin&version=2} status=0 QTime=1256 [junit4] 2> 860777 INFO (qtp1977710531-6710) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 860865 INFO (zkCallback-980-thread-5) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4]) [junit4] 2> 860865 INFO (zkCallback-985-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4]) [junit4] 2> 861313 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 861777 INFO (qtp1977710531-6710) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=onlyinzk&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=2467 [junit4] 2> 861779 INFO (qtp1977710531-6730) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 861779 INFO (qtp1977710531-6730) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 861780 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionOnlyInZk [junit4] 2> 861798 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard [junit4] 2> 861798 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 861800 INFO (qtp1977710531-6713) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=onlyinzk&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 861801 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 861811 INFO (qtp1977710531-6731) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk_shard2_replica1 [junit4] 2> 861811 INFO (qtp359200126-6718) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk_shard1_replica1 [junit4] 2> 861811 INFO (qtp1977710531-6731) [ ] o.a.s.c.SolrCore [onlyinzk_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@716498e6 [junit4] 2> 861811 INFO (qtp359200126-6718) [ ] o.a.s.c.SolrCore [onlyinzk_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@5d1430bf [junit4] 2> 861812 INFO (qtp1977710531-6731) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk.shard2.replica1 [junit4] 2> 861812 INFO (qtp359200126-6718) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk.shard1.replica1 [junit4] 2> 861835 INFO (qtp1977710531-6731) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=onlyinzk_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=31 [junit4] 2> 861835 INFO (qtp359200126-6718) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=onlyinzk_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=31 [junit4] 2> 862539 INFO (qtp1977710531-6713) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=738 [junit4] 2> 862541 INFO (qtp1977710531-6725) [ ] 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> 862555 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection oversharded [junit4] 2> 862556 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 862556 ERROR (OverseerThreadFactory-3737-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> 862557 INFO (qtp1977710531-6725) [ ] 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=16 [junit4] 2> 862558 INFO (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMaxNodesPerShard [junit4] 2> 862590 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreationAndDeletion [junit4] 2> 862590 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 862592 INFO (qtp1977710531-6730) [ ] 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> 862593 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection created_and_deleted [junit4] 2> 862594 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 862798 INFO (qtp1977710531-6710) [ ] 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> 862901 INFO (zkCallback-985-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> 863805 INFO (qtp1977710531-6710) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 863811 INFO (qtp1977710531-6710) [ ] o.a.s.s.IndexSchema [created_and_deleted_shard1_replica1] Schema name=minimal [junit4] 2> 863813 INFO (qtp1977710531-6710) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 863814 INFO (qtp1977710531-6710) [ ] o.a.s.c.CoreContainer Creating SolrCore 'created_and_deleted_shard1_replica1' using configuration from collection created_and_deleted [junit4] 2> 863814 INFO (qtp1977710531-6710) [ ] 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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node1/created_and_deleted_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node1/./created_and_deleted_shard1_replica1/data/] [junit4] 2> 863822 INFO (qtp1977710531-6710) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 863822 INFO (qtp1977710531-6710) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 863827 INFO (qtp1977710531-6710) [ ] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 863827 INFO (qtp1977710531-6710) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 863827 INFO (qtp1977710531-6710) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4cbca81[created_and_deleted_shard1_replica1] main] [junit4] 2> 863827 INFO (qtp1977710531-6710) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 863828 INFO (qtp1977710531-6710) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 863828 INFO (qtp1977710531-6710) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 863828 INFO (searcherExecutor-3771-thread-1) [ ] o.a.s.c.SolrCore [created_and_deleted_shard1_replica1] Registered new searcher Searcher@4cbca81[created_and_deleted_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 863828 INFO (qtp1977710531-6710) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1554970113027866624 [junit4] 2> 863832 INFO (qtp1977710531-6710) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 863832 INFO (qtp1977710531-6710) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 863832 INFO (qtp1977710531-6710) [ ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:41014/solr/created_and_deleted_shard1_replica1/ [junit4] 2> 863832 INFO (qtp1977710531-6710) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 863832 INFO (qtp1977710531-6710) [ ] o.a.s.c.SyncStrategy https://127.0.0.1:41014/solr/created_and_deleted_shard1_replica1/ has no replicas [junit4] 2> 863834 INFO (qtp1977710531-6710) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:41014/solr/created_and_deleted_shard1_replica1/ shard1 [junit4] 2> 863935 INFO (zkCallback-985-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> 863984 INFO (qtp1977710531-6710) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 863987 INFO (qtp1977710531-6710) [ ] 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=1189 [junit4] 2> 863988 INFO (qtp1977710531-6730) [ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 864087 INFO (zkCallback-985-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> 864595 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 864989 INFO (qtp1977710531-6730) [ ] 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=2396 [junit4] 2> 864991 INFO (qtp1977710531-6731) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 864991 INFO (qtp1977710531-6731) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 864993 INFO (qtp1977710531-6725) [ ] 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> 864994 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 864996 INFO (qtp1977710531-6713) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.created_and_deleted_shard1_replica1 [junit4] 2> 864996 INFO (qtp1977710531-6713) [ ] o.a.s.c.SolrCore [created_and_deleted_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@3ecf4b6a [junit4] 2> 864997 INFO (qtp1977710531-6713) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.created_and_deleted.shard1.replica1 [junit4] 2> 865007 INFO (qtp1977710531-6713) [ ] 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=11 [junit4] 2> 865710 INFO (qtp1977710531-6725) [ ] 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=717 [junit4] 2> 865713 INFO (qtp1977710531-6710) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 865713 INFO (qtp1977710531-6710) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 865713 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreationAndDeletion [junit4] 2> 865734 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDeleteNonExistentCollection [junit4] 2> 865734 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[31FBC57DD31D8ED4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 865737 INFO (qtp1977710531-6710) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=unknown_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 865739 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true [junit4] 2> 865739 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 865739 ERROR (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: unknown_collection operation: delete failed:org.apache.solr.common.SolrException: Could not find collection : unknown_collection [junit4] 2> at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:194) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:843) [junit4] 2> at org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:81) [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> 865741 ERROR (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor :org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /overseer/collection-queue-work/qnr-0000000020 [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.setData(ZooKeeper.java:1270) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:373) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:370) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.setData(SolrZkClient.java:370) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.setData(SolrZkClient.java:571) [junit4] 2> at org.apache.solr.cloud.OverseerTaskQueue.remove(OverseerTaskQueue.java:94) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.cleanUpWorkQueue(OverseerTaskProcessor.java:320) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:201) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> [junit4] 2> 865742 INFO (qtp1977710531-6710) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=unknown_collection&action=DELETE&wt=javabin&version=2} status=400 QTime=4 [junit4] 2> 865742 INFO (OverseerCollectionConfigSetProcessor-97185629349281799-127.0.0.1:40949_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> 865744 INFO (qtp1977710531-6713) [ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 865749 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.CreateCollectionCmd Create collection acollectionafterbaddelete [junit4] 2> 865955 INFO (qtp359200126-6711) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2 [junit4] 2> 866004 INFO (qtp883074942-6706) [ ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2 [junit4] 2> 866107 INFO (zkCallback-980-thread-5) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4]) [junit4] 2> 866107 INFO (zkCallback-981-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4]) [junit4] 2> 866964 INFO (qtp359200126-6711) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 866992 INFO (qtp359200126-6711) [ ] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica1] Schema name=minimal [junit4] 2> 866995 INFO (qtp359200126-6711) [ ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id [junit4] 2> 866996 INFO (qtp359200126-6711) [ ] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica1' using configuration from collection acollectionafterbaddelete [junit4] 2> 866996 INFO (qtp359200126-6711) [ ] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node3/acollectionafterbaddelete_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001/tempDir-001/node3/./acollectionafterbaddelete_shard1_replica1/data/] [junit4] 2> 867015 INFO (qtp883074942-6706) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 867017 INFO (qtp359200126-6711) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 867017 INFO (qtp359200126-6711) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 867024 INFO (qtp883074942-6706) [ ] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica2] Schema name=minimal [junit4] 2> 867024 INFO (qtp359200126-6711) [ ] o.a.s.u.CommitTracker Hard AutoCommit [...truncated too long message...] [junit4] 2> [junit4] 2> 967452 ERROR (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.OverseerCollectionMessageHandler Collection: reloaded_collection operation: reload failed:java.util.concurrent.RejectedExecutionException: Task org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$$Lambda$182/975351927@7d57216c rejected from org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor@3dc79c9[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 70] [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2076) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:842) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1388) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.execute(ExecutorUtil.java:214) [junit4] 2> at java.base/java.util.concurrent.ExecutorCompletionService.submit(ExecutorCompletionService.java:178) [junit4] 2> at org.apache.solr.handler.component.HttpShardHandler.submit(HttpShardHandler.java:194) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.waitForCoreAdminAsyncCallToComplete(OverseerCollectionMessageHandler.java:933) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.waitForAsyncCallsToComplete(OverseerCollectionMessageHandler.java:913) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processResponses(OverseerCollectionMessageHandler.java:792) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:849) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:832) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.reloadCollection(OverseerCollectionMessageHandler.java:274) [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> 967455 INFO (OverseerThreadFactory-3737-thread-5) [ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000073 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 967455 WARN (zkCallback-980-thread-7) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 967456 INFO (jetty-launcher-968-thread-6) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 967456 INFO (jetty-launcher-968-thread-6) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5c52e370{/solr,null,UNAVAILABLE} [junit4] 2> 968086 WARN (zkCallback-991-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> 968087 INFO (jetty-launcher-968-thread-5) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 968087 WARN (zkCallback-1017-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 968087 INFO (jetty-launcher-968-thread-5) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5109db7a{/solr,null,UNAVAILABLE} [junit4] 2> 968088 INFO (jetty-launcher-968-thread-7) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node [junit4] 2> 968088 INFO (jetty-launcher-968-thread-7) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@30137f51{/solr,null,UNAVAILABLE} [junit4] 2> 968088 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45571 45571 [junit4] 2> 973115 INFO (Thread-1773) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45571 45571 [junit4] 2> 973115 WARN (Thread-1773) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 26 /solr/aliases.json [junit4] 2> 23 /solr/configs/conf [junit4] 2> 6 /solr/configs/conf2 [junit4] 2> 5 /solr/security.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 235 /solr/clusterstate.json [junit4] 2> 26 /solr/clusterprops.json [junit4] 2> 5 /solr/collections/awhollynewcollection_0/state.json [junit4] 2> 4 /solr/collections/nodes_used_collection/state.json [junit4] 2> 4 /solr/collections/addReplicaColl/state.json [junit4] 2> 4 /solr/collections/reloaded_collection/state.json [junit4] 2> 3 /solr/collections/acollectionafterbaddelete/state.json [junit4] 2> 2 /solr/collections/onlyinzk/state.json [junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard2/election/97185629349281802-core_node2-n_0000000000 [junit4] 2> 2 /solr/collections/halfdeletedcollection/state.json [junit4] 2> 2 /solr/overseer_elect/election/97185629349281802-127.0.0.1:41014_solr-n_0000000001 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 387 /solr/collections [junit4] 2> 101 /solr/overseer/queue [junit4] 2> 69 /solr/overseer/collection-queue-work [junit4] 2> 49 /solr/live_nodes [junit4] 2> 28 /solr/overseer/queue-work [junit4] 2> [junit4] 2> 973116 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[31FBC57DD31D8ED4]-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/J0/temp/solr.cloud.CollectionsAPIDistributedZkTest_31FBC57DD31D8ED4-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {_version_=BlockTreeOrds(blocksize=128), id=Lucene50(blocksize=128)}, docValues:{}, maxPointsInLeafNode=1275, maxMBSortInHeap=6.61202259589016, sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=en-SD, timezone=Europe/Luxembourg [junit4] 2> NOTE: Linux 4.4.0-53-generic amd64/Oracle Corporation 9-ea (64-bit)/cpus=12,threads=1,free=145929408,total=509542400 [junit4] 2> NOTE: All tests run in this JVM: [TestFoldingMultitermQuery, TestPerFieldSimilarityWithDefaultOverride, DistributedQueryComponentOptimizationTest, TestSha256AuthenticationProvider, ConjunctionSolrSpellCheckerTest, AtomicUpdatesTest, AnalysisAfterCoreReloadTest, TestFieldTypeCollectionResource, CdcrReplicationDistributedZkTest, TestSubQueryTransformerDistrib, TestDFISimilarityFactory, TestOmitPositions, HighlighterConfigTest, CacheHeaderTest, SolrSlf4jReporterTest, TestRandomFaceting, TestSolrCloudSnapshots, UniqFieldsUpdateProcessorFactoryTest, UUIDUpdateProcessorFallbackTest, TestCustomSort, HttpPartitionTest, TestJmxIntegration, DistributedFacetPivotLargeTest, TestCrossCoreJoin, AnalyticsQueryTest, PathHierarchyTokenizerFactoryTest, CursorPagingTest, TestIntervalFaceting, TestHighlightDedupGrouping, MetricUtilsTest, TestSolrDeletionPolicy2, SynonymTokenizerTest, TestCloudInspectUtil, TestPerFieldSimilarity, TestLeaderElectionWithEmptyReplica, TestSSLRandomization, CreateCollectionCleanupTest, NotRequiredUniqueKeyTest, TestLazyCores, SolrXmlInZkTest, TestSolrConfigHandler, TestJsonFacets, HdfsCollectionsAPIDistributedZkTest, SignatureUpdateProcessorFactoryTest, TestComponentsName, DistributedQueryElevationComponentTest, DistribDocExpirationUpdateProcessorTest, TestSolrCloudWithHadoopAuthPlugin, TestSmileRequest, LeaderElectionIntegrationTest, TestRestManager, TestGraphTermsQParserPlugin, OverriddenZkACLAndCredentialsProvidersTest, RequiredFieldsTest, TestEmbeddedSolrServerConstructors, TestMaxScoreQueryParser, DeleteShardTest, TestReplicationHandler, SecurityConfHandlerTest, SimpleCollectionCreateDeleteTest, CurrencyFieldOpenExchangeTest, DeleteLastCustomShardedReplicaTest, TestStressLucene, BitVectorTest, TestBulkSchemaConcurrent, TestPseudoReturnFields, PeerSyncWithIndexFingerprintCachingTest, TestNRTOpen, TestRawResponseWriter, SolrGangliaReporterTest, DefaultValueUpdateProcessorTest, BlockCacheTest, HdfsBasicDistributedZkTest, TestRemoteStreaming, StandardRequestHandlerTest, ManagedSchemaRoundRobinCloudTest, SolrMetricManagerTest, NumericFieldsTest, TestChildDocTransformer, TestFastLRUCache, FastVectorHighlighterTest, TestSchemaResource, TriLevelCompositeIdRoutingTest, TestGraphMLResponseWriter, RegexBoostProcessorTest, UtilsToolTest, TestCSVLoader, TestCorePropertiesReload, TestFaceting, ResourceLoaderTest, ReplicaListTransformerTest, AlternateDirectoryTest, UUIDFieldTest, TestPHPSerializedResponseWriter, TestUniqueKeyFieldResource, SolrCoreTest, TestSolrCloudWithSecureImpersonation, TestSolr4Spatial, SolrRequestParserTest, ClusterStateTest, SyncSliceTest, ActionThrottleTest, ReturnFieldsTest, TestDownShardTolerantSearch, TestAtomicUpdateErrorCases, TestHdfsUpdateLog, TestDynamicFieldResource, CollectionsAPIDistributedZkTest] [junit4] Completed [346/675 (1!)] on J0 in 150.74s, 20 tests, 1 error <<< FAILURES! [...truncated 52549 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
