You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/03/01 17:35:17 UTC
[JENKINS] Lucene-Solr-Tests-6.6 - Build # 43 - Still unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.6/43/
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
Stack Trace:
java.lang.AssertionError: Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
at __randomizedtesting.SeedInfo.seed([E754C01620BF8B9A:AF21B4A2268CA40F]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.checkNoTwoShardsUseTheSameIndexDir(CollectionsAPIDistributedZkTest.java:646)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:524)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12027 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/init-core-data-001
[junit4] 2> 387966 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=218 numCloses=218
[junit4] 2> 387966 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 387967 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 387968 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001
[junit4] 2> 387968 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 387968 INFO (Thread-1453) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 387968 INFO (Thread-1453) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 387970 ERROR (Thread-1453) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 388068 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:33290
[junit4] 2> 388087 INFO (jetty-launcher-706-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 388087 INFO (jetty-launcher-706-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 388091 INFO (jetty-launcher-706-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 388091 INFO (jetty-launcher-706-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 388099 INFO (jetty-launcher-706-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@50e9b510{/solr,null,AVAILABLE}
[junit4] 2> 388100 INFO (jetty-launcher-706-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5e563cdb{HTTP/1.1,[http/1.1]}{127.0.0.1:42700}
[junit4] 2> 388100 INFO (jetty-launcher-706-thread-1) [ ] o.e.j.s.Server Started @390100ms
[junit4] 2> 388100 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42700}
[junit4] 2> 388100 ERROR (jetty-launcher-706-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 388101 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 388101 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 388101 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 388101 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-01T16:58:23.311Z
[junit4] 2> 388102 INFO (jetty-launcher-706-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@12b4e583{/solr,null,AVAILABLE}
[junit4] 2> 388102 INFO (jetty-launcher-706-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@c6016b9{HTTP/1.1,[http/1.1]}{127.0.0.1:34214}
[junit4] 2> 388102 INFO (jetty-launcher-706-thread-3) [ ] o.e.j.s.Server Started @390102ms
[junit4] 2> 388103 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34214}
[junit4] 2> 388103 ERROR (jetty-launcher-706-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 388103 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 388103 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 388103 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 388103 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-01T16:58:23.313Z
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@527c35d4{/solr,null,AVAILABLE}
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4e2c2f02{HTTP/1.1,[http/1.1]}{127.0.0.1:54229}
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.e.j.s.Server Started @390105ms
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54229}
[junit4] 2> 388105 ERROR (jetty-launcher-706-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 388105 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-01T16:58:23.315Z
[junit4] 2> 388109 INFO (jetty-launcher-706-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@687fa21b{/solr,null,AVAILABLE}
[junit4] 2> 388109 INFO (jetty-launcher-706-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@79f1c9dc{HTTP/1.1,[http/1.1]}{127.0.0.1:33972}
[junit4] 2> 388109 INFO (jetty-launcher-706-thread-4) [ ] o.e.j.s.Server Started @390109ms
[junit4] 2> 388110 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33972}
[junit4] 2> 388110 ERROR (jetty-launcher-706-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 388110 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 388110 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 388110 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 388110 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-01T16:58:23.320Z
[junit4] 2> 388110 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 388112 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 388120 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 388121 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 388126 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 388127 INFO (jetty-launcher-706-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33290/solr
[junit4] 2> 388131 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 388131 INFO (jetty-launcher-706-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33290/solr
[junit4] 2> 388137 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 388137 INFO (jetty-launcher-706-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33290/solr
[junit4] 2> 388142 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 388149 INFO (jetty-launcher-706-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33290/solr
[junit4] 2> 388200 INFO (jetty-launcher-706-thread-3) [n:127.0.0.1:34214_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 388200 INFO (jetty-launcher-706-thread-2) [n:127.0.0.1:54229_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 388200 INFO (jetty-launcher-706-thread-4) [n:127.0.0.1:33972_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 388201 INFO (jetty-launcher-706-thread-1) [n:127.0.0.1:42700_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 388201 INFO (jetty-launcher-706-thread-4) [n:127.0.0.1:33972_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:33972_solr
[junit4] 2> 388202 INFO (jetty-launcher-706-thread-3) [n:127.0.0.1:34214_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34214_solr
[junit4] 2> 388202 INFO (jetty-launcher-706-thread-2) [n:127.0.0.1:54229_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54229_solr
[junit4] 2> 388202 INFO (jetty-launcher-706-thread-1) [n:127.0.0.1:42700_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42700_solr
[junit4] 2> 388202 INFO (jetty-launcher-706-thread-4) [n:127.0.0.1:33972_solr ] o.a.s.c.Overseer Overseer (id=99609706704404492-127.0.0.1:33972_solr-n_0000000000) starting
[junit4] 2> 388204 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 388208 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 388208 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 388212 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 388212 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 388226 INFO (zkCallback-728-thread-1-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 388238 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 388241 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 388261 INFO (jetty-launcher-706-thread-4) [n:127.0.0.1:33972_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33972_solr
[junit4] 2> 388263 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 388263 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 388263 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 388263 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 388268 INFO (jetty-launcher-706-thread-3) [n:127.0.0.1:34214_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node3/.
[junit4] 2> 388344 INFO (jetty-launcher-706-thread-4) [n:127.0.0.1:33972_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node4/.
[junit4] 2> 388344 INFO (jetty-launcher-706-thread-2) [n:127.0.0.1:54229_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node2/.
[junit4] 2> 388352 INFO (jetty-launcher-706-thread-1) [n:127.0.0.1:42700_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node1/.
[junit4] 2> 388361 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 388362 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33290/solr ready
[junit4] 2> 388396 INFO (TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[E754C01620BF8B9A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCoresAreDistributedAcrossNodes
[junit4] 2> 388398 INFO (TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[E754C01620BF8B9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 388401 INFO (qtp2010386312-4558) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=nodes_used_collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 388403 INFO (OverseerThreadFactory-1941-thread-1-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.CreateCollectionCmd Create collection nodes_used_collection
[junit4] 2> 388515 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard1_replica2&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard1&wt=javabin&version=2
[junit4] 2> 388516 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 388516 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard1_replica1&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard1&wt=javabin&version=2
[junit4] 2> 388516 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 388517 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard2_replica1&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard2&wt=javabin&version=2
[junit4] 2> 388517 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard2_replica2&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard2&wt=javabin&version=2
[junit4] 2> 388517 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 388518 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 388633 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 388634 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 388634 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 388634 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 389528 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 389528 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 389535 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.s.IndexSchema [nodes_used_collection_shard2_replica1] Schema name=minimal
[junit4] 2> 389536 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.s.IndexSchema [nodes_used_collection_shard1_replica2] Schema name=minimal
[junit4] 2> 389537 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 389538 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard2_replica1' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 389538 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 389538 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.SolrCore [[nodes_used_collection_shard2_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node3/nodes_used_collection_shard2_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node3/./nodes_used_collection_shard2_replica1/data/]
[junit4] 2> 389538 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 389538 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard1_replica2' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 389539 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 389539 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 389539 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.SolrCore [[nodes_used_collection_shard1_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node2/nodes_used_collection_shard1_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node2/./nodes_used_collection_shard1_replica2/data/]
[junit4] 2> 389541 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 389551 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.s.IndexSchema [nodes_used_collection_shard2_replica2] Schema name=minimal
[junit4] 2> 389554 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.s.IndexSchema [nodes_used_collection_shard1_replica1] Schema name=minimal
[junit4] 2> 389555 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 389555 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard2_replica2' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 389555 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 389555 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'nodes_used_collection_shard1_replica1' using configuration from collection nodes_used_collection, trusted=true
[junit4] 2> 389555 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 389556 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.c.SolrCore [[nodes_used_collection_shard2_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node4/nodes_used_collection_shard2_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node4/./nodes_used_collection_shard2_replica2/data/]
[junit4] 2> 389556 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 389556 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.c.SolrCore [[nodes_used_collection_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node1/nodes_used_collection_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node1/./nodes_used_collection_shard1_replica1/data/]
[junit4] 2> 389591 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 389591 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 389592 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 389592 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 389593 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1be7599d[nodes_used_collection_shard2_replica1] main]
[junit4] 2> 389594 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 389594 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 389594 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 389594 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593755308973359104
[junit4] 2> 389596 INFO (searcherExecutor-1950-thread-1-processing-n:127.0.0.1:34214_solr x:nodes_used_collection_shard2_replica1 s:shard2 c:nodes_used_collection) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.SolrCore [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@1be7599d[nodes_used_collection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 389601 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9998ms
[junit4] 2> 389607 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 389607 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 389609 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 389609 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 389610 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@737fdfda[nodes_used_collection_shard1_replica2] main]
[junit4] 2> 389611 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 389612 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 389612 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 389612 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 389612 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 389612 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 389613 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 389613 INFO (searcherExecutor-1951-thread-1-processing-n:127.0.0.1:54229_solr x:nodes_used_collection_shard1_replica2 s:shard1 c:nodes_used_collection) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.SolrCore [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@737fdfda[nodes_used_collection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 389613 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593755308993282048
[junit4] 2> 389613 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@17d92803[nodes_used_collection_shard2_replica2] main]
[junit4] 2> 389613 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 389613 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 389614 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 389614 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 389614 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 389614 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 389614 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 389614 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593755308994330624
[junit4] 2> 389615 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@47f1574f[nodes_used_collection_shard1_replica1] main]
[junit4] 2> 389616 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 389616 INFO (searcherExecutor-1952-thread-1-processing-n:127.0.0.1:33972_solr x:nodes_used_collection_shard2_replica2 s:shard2 c:nodes_used_collection) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.c.SolrCore [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@17d92803[nodes_used_collection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 389616 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 389617 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 389617 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593755308997476352
[junit4] 2> 389617 INFO (searcherExecutor-1953-thread-1-processing-n:127.0.0.1:42700_solr x:nodes_used_collection_shard1_replica1 s:shard1 c:nodes_used_collection) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.c.SolrCore [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@47f1574f[nodes_used_collection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 389620 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 389722 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 389722 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 389722 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 389722 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390102 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 390102 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 390102 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:34214/solr/nodes_used_collection_shard2_replica1/
[junit4] 2> 390102 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:34214/solr START replicas=[http://127.0.0.1:33972/solr/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4] 2> 390102 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:34214/solr DONE. We have no versions. sync failed.
[junit4] 2> 390105 INFO (qtp534543879-4553) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 r:core_node4 x:nodes_used_collection_shard2_replica2] o.a.s.c.S.Request [nodes_used_collection_shard2_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 390105 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 390105 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 390105 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 390108 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:34214/solr/nodes_used_collection_shard2_replica1/ shard2
[junit4] 2> 390121 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 390121 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 390121 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:54229/solr/nodes_used_collection_shard1_replica2/
[junit4] 2> 390121 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:54229/solr START replicas=[http://127.0.0.1:42700/solr/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4] 2> 390121 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:54229/solr DONE. We have no versions. sync failed.
[junit4] 2> 390123 INFO (qtp2010386312-4561) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 r:core_node1 x:nodes_used_collection_shard1_replica1] o.a.s.c.S.Request [nodes_used_collection_shard1_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 390123 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 390123 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 390123 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 390126 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:54229/solr/nodes_used_collection_shard1_replica2/ shard1
[junit4] 2> 390229 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390229 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390229 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390229 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390259 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 390261 INFO (qtp1180210852-4541) [n:127.0.0.1:34214_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard2_replica1&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=1743
[junit4] 2> 390277 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 390278 INFO (qtp259113879-4568) [n:127.0.0.1:54229_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard1_replica2&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard1&wt=javabin&version=2} status=0 QTime=1763
[junit4] 2> 390381 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390381 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390381 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390381 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390621 INFO (qtp534543879-4550) [n:127.0.0.1:33972_solr c:nodes_used_collection s:shard2 x:nodes_used_collection_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard2_replica2&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=2105
[junit4] 2> 390622 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr c:nodes_used_collection s:shard1 x:nodes_used_collection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=nodes_used_collection_shard1_replica1&action=CREATE&numShards=2&collection=nodes_used_collection&shard=shard1&wt=javabin&version=2} status=0 QTime=2106
[junit4] 2> 390625 INFO (qtp2010386312-4558) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 390727 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390727 INFO (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390727 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 390727 INFO (zkCallback-725-thread-1-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/nodes_used_collection/state.json] for collection [nodes_used_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 391625 INFO (qtp2010386312-4558) [n:127.0.0.1:42700_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=nodes_used_collection&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3224
[junit4] 2> 391626 INFO (TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[E754C01620BF8B9A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCoresAreDistributedAcrossNodes
[junit4] 2> 391662 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[E754C01620BF8B9A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNoConfigSetExist
[junit4] 2> 391665 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[E754C01620BF8B9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 391667 INFO (qtp2010386312-4559) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=nodes_used_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 391670 INFO (OverseerThreadFactory-1941-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 391670 INFO (OverseerCollectionConfigSetProcessor-99609706704404492-127.0.0.1:33972_solr-n_0000000000) [n:127.0.0.1:33972_solr ] 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> 391671 INFO (qtp2010386312-4562) [n:127.0.0.1:42700_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard1.replica1
[junit4] 2> 391671 INFO (qtp2010386312-4562) [n:127.0.0.1:42700_solr ] o.a.s.c.SolrCore [nodes_used_collection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1fae3626
[junit4] 2> 391672 INFO (qtp534543879-4551) [n:127.0.0.1:33972_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard2.replica2
[junit4] 2> 391672 INFO (qtp534543879-4551) [n:127.0.0.1:33972_solr ] o.a.s.c.SolrCore [nodes_used_collection_shard2_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@71186746
[junit4] 2> 391673 INFO (qtp259113879-4552) [n:127.0.0.1:54229_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard1.replica2
[junit4] 2> 391673 INFO (qtp259113879-4552) [n:127.0.0.1:54229_solr ] o.a.s.c.SolrCore [nodes_used_collection_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@42f5d420
[junit4] 2> 391674 INFO (qtp1180210852-4543) [n:127.0.0.1:34214_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard2.replica1
[junit4] 2> 391674 INFO (qtp1180210852-4543) [n:127.0.0.1:34214_solr ] o.a.s.c.SolrCore [nodes_used_collection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4279b6c2
[junit4] 2> 391674 INFO (qtp534543879-4551) [n:127.0.0.1:33972_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard2.replica2
[junit4] 2> 391677 INFO (qtp534543879-4551) [n:127.0.0.1:33972_solr ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader parent node, won't remove previous leader registration.
[junit4] 2> 391677 INFO (qtp534543879-4551) [n:127.0.0.1:33972_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=nodes_used_collection_shard2_replica2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 391682 INFO (qtp1180210852-4543) [n:127.0.0.1:34214_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard2.replica1
[junit4] 2> 391683 INFO (qtp2010386312-4562) [n:127.0.0.1:42700_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard1.replica1
[junit4] 2> 391683 WARN (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.LeaderElector Our node is no longer in line to be leader
[junit4] 2> 391683 INFO (qtp259113879-4552) [n:127.0.0.1:54229_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard1.replica2
[junit4] 2> 391684 INFO (qtp1180210852-4543) [n:127.0.0.1:34214_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=nodes_used_collection_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=12
[junit4] 2> 391685 INFO (qtp2010386312-4562) [n:127.0.0.1:42700_solr ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader parent node, won't remove previous leader registration.
[junit4] 2> 391685 INFO (qtp2010386312-4562) [n:127.0.0.1:42700_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=nodes_used_collection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=13
[junit4] 2> 391685 WARN (zkCallback-727-thread-1-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.LeaderElector Our node is no longer in line to be leader
[junit4] 2> 391686 INFO (qtp259113879-4552) [n:127.0.0.1:54229_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=nodes_used_collection_shard1_replica2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=13
[junit4] 2> 392390 INFO (qtp2010386312-4559) [n:127.0.0.1:42700_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=nodes_used_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=723
[junit4] 2> 392394 INFO (qtp2010386312-4534) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-002&collection.configName=conf123&name=corewithnocollection3&action=CREATE&numShards=1&collection=&wt=javabin&version=2
[junit4] 2> 392403 INFO (OverseerStateUpdate-99609706704404492-127.0.0.1:33972_solr-n_0000000000) [n:127.0.0.1:33972_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 393398 ERROR (qtp2010386312-4534) [n:127.0.0.1:42700_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.c.c.ZkStateReader Specified config=[conf123] does not exist in ZooKeeper at location=[/configs/conf123]
[junit4] 2> 393400 ERROR (qtp2010386312-4534) [n:127.0.0.1:42700_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Error CREATEing SolrCore 'corewithnocollection3': Unable to create core [corewithnocollection3] Caused by: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:898)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:91)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:384)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:361)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:305)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:462)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.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.lang.Thread.run(Thread.java:748)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: Unable to create core [corewithnocollection3]
[junit4] 2> at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:964)
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:862)
[junit4] 2> ... 34 more
[junit4] 2> Caused by: org.apache.solr.common.cloud.ZooKeeperException: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.readConfigName(ZkStateReader.java:189)
[junit4] 2> at org.apache.solr.cloud.CloudConfigSetService.createCoreResourceLoader(CloudConfigSetService.java:54)
[junit4] 2> at org.apache.solr.core.ConfigSetService.getConfig(ConfigSetService.java:75)
[junit4] 2> at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:944)
[junit4] 2> ... 35 more
[junit4] 2>
[junit4] 2> 393400 INFO (qtp2010386312-4534) [n:127.0.0.1:42700_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-002&collection.configName=conf123&name=corewithnocollection3&action=CREATE&numShards=1&collection=&wt=javabin&version=2} status=400 QTime=1006
[junit4] 2> 393671 INFO (OverseerCollectionConfigSetProcessor-99609706704404492-127.0.0.1:33972_solr-n_0000000000) [n:127.0.0.1:33972_solr ] 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> 394403 INFO (qtp2010386312-4561) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 394403 INFO (qtp2010386312-4561) [n:127.0.0.1:42700_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 394403 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[E754C01620BF8B9A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNoConfigSetExist
[junit4] 2> 394431 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[E754C01620BF8B9A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDeleteNonExistentCollection
[junit4] 2> 394431 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[E754C01620BF8B9A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 394434 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=corewithnocollection3&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 394436 INFO (OverseerThreadFactory-1941-thread-3-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 395139 INFO (qtp2010386312-4542) [n:127.0.0.1:42700_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=corewithnocollection3&action=DELETE&wt=javabin&version=2} status=0 QTime=704
[junit4] 2> 395141 INFO (qtp2010386312-4558) [n:127.0.0.1:42700_solr ] 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> 395143 INFO (OverseerCollectionConfigSetProcessor-99609706704404492-127.0.0.1:33972_solr-n_0000000000) [n:127.0.0.1:33972_solr ] 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> 395143 INFO (OverseerThreadFactory-1941-thread-4-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 395143 ERROR (OverseerThreadFactory-1941-thread-4-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] 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:846)
[junit4] 2> at org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:88)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:226)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 395145 INFO (qtp2010386312-4558) [n:127.0.0.1:42700_solr ] 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> 395147 INFO (qtp2010386312-4562) [n:127.0.0.1:42700_solr ] 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> 395149 INFO (OverseerThreadFactory-1941-thread-5-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.CreateCollectionCmd Create collection acollectionafterbaddelete
[junit4] 2> 395149 INFO (OverseerCollectionConfigSetProcessor-99609706704404492-127.0.0.1:33972_solr-n_0000000000) [n:127.0.0.1:33972_solr ] 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> 395354 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr ] 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> 395354 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr ] 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> 395460 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] 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> 395461 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] 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> 396367 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 396370 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 396373 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica2] Schema name=minimal
[junit4] 2> 396376 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica1] Schema name=minimal
[junit4] 2> 396376 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 396376 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica2' using configuration from collection acollectionafterbaddelete, trusted=true
[junit4] 2> 396377 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 396377 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node3/acollectionafterbaddelete_shard1_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node3/./acollectionafterbaddelete_shard1_replica2/data/]
[junit4] 2> 396378 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 396378 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica1' using configuration from collection acollectionafterbaddelete, trusted=true
[junit4] 2> 396378 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 396378 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node4/acollectionafterbaddelete_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001/tempDir-001/node4/./acollectionafterbaddelete_shard1_replica1/data/]
[junit4] 2> 396410 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 396410 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 396410 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 396410 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 396411 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 396411 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 396411 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 396411 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 396412 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@31c9c940[acollectionafterbaddelete_shard1_replica2] main]
[junit4] 2> 396412 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@475a59fa[acollectionafterbaddelete_shard1_replica1] main]
[junit4] 2> 396413 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 396413 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 396413 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 396413 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 396413 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593755316123598848
[junit4] 2> 396413 INFO (searcherExecutor-1970-thread-1-processing-n:127.0.0.1:34214_solr x:acollectionafterbaddelete_shard1_replica2 s:shard1 c:acollectionafterbaddelete) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] Registered new searcher Searcher@31c9c940[acollectionafterbaddelete_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 396414 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 396414 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 396414 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593755316124647424
[junit4] 2> 396414 INFO (searcherExecutor-1971-thread-1-processing-n:127.0.0.1:33972_solr x:acollectionafterbaddelete_shard1_replica1 s:shard1 c:acollectionafterbaddelete) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] Registered new searcher Searcher@475a59fa[acollectionafterbaddelete_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 396418 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 396418 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 396418 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:34214/solr/acollectionafterbaddelete_shard1_replica2/
[junit4] 2> 396419 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica2 url=http://127.0.0.1:34214/solr START replicas=[http://127.0.0.1:33972/solr/acollectionafterbaddelete_shard1_replica1/] nUpdates=100
[junit4] 2> 396419 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica2 url=http://127.0.0.1:34214/solr DONE. We have no versions. sync failed.
[junit4] 2> 396422 INFO (qtp534543879-4554) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.S.Request [acollectionafterbaddelete_shard1_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 396423 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 396423 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 396423 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 396425 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:34214/solr/acollectionafterbaddelete_shard1_replica2/ shard1
[junit4] 2> 396527 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] 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> 396527 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] 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> 396576 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 396577 INFO (qtp1180210852-4544) [n:127.0.0.1:34214_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=1223
[junit4] 2> 396679 INFO (zkCallback-726-thread-1-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] 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> 396679 INFO (zkCallback-728-thread-2-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] 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> 397420 INFO (qtp534543879-4555) [n:127.0.0.1:33972_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=2066
[junit4] 2> 397421 INFO (qtp2010386312-4562) [n:127.0.0.1:42700_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 397423 INFO (OverseerCollectionConfigSetProcessor-9960970670440
[...truncated too long message...]
> 509695 INFO (OverseerThreadFactory-1941-thread-5-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] 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> 509696 WARN (zkCallback-728-thread-3-processing-n:127.0.0.1:33972_solr) [n:127.0.0.1:33972_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 509696 INFO (jetty-closer-707-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@687fa21b{/solr,null,UNAVAILABLE}
[junit4] 2> 510670 WARN (zkCallback-727-thread-2-processing-n:127.0.0.1:42700_solr) [n:127.0.0.1:42700_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 510671 INFO (jetty-closer-707-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@50e9b510{/solr,null,UNAVAILABLE}
[junit4] 2> 510670 WARN (zkCallback-726-thread-2-processing-n:127.0.0.1:34214_solr) [n:127.0.0.1:34214_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 510671 INFO (jetty-closer-707-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@12b4e583{/solr,null,UNAVAILABLE}
[junit4] 2> 511128 INFO (zkCallback-725-thread-3-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:54229_solr
[junit4] 2> 511128 INFO (zkCallback-725-thread-5-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (1)
[junit4] 2> 511129 INFO (zkCallback-725-thread-6-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard2 r:core_node7 x:awhollynewcollection_0_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 511130 INFO (coreCloseExecutor-2177-thread-1) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard3 r:core_node10 x:awhollynewcollection_0_shard3_replica2] o.a.s.c.SolrCore [awhollynewcollection_0_shard3_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@1dbfa813
[junit4] 2> 511131 INFO (coreCloseExecutor-2177-thread-2) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard4 r:core_node11 x:awhollynewcollection_0_shard4_replica3] o.a.s.c.SolrCore [awhollynewcollection_0_shard4_replica3] CLOSING SolrCore org.apache.solr.core.SolrCore@558921db
[junit4] 2> 511138 INFO (coreCloseExecutor-2177-thread-1) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard3 r:core_node10 x:awhollynewcollection_0_shard3_replica2] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard3.replica2
[junit4] 2> 511139 INFO (coreCloseExecutor-2177-thread-2) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard4 r:core_node11 x:awhollynewcollection_0_shard4_replica3] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard4.replica3
[junit4] 2> 511142 WARN (zkCallback-725-thread-2-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 513629 WARN (zkCallback-725-thread-6-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard2 r:core_node7 x:awhollynewcollection_0_shard2_replica1] o.a.s.c.SyncStrategy Closed, skipping sync up.
[junit4] 2> 513630 INFO (zkCallback-725-thread-6-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard2 r:core_node7 x:awhollynewcollection_0_shard2_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 513630 INFO (zkCallback-725-thread-6-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard2 r:core_node7 x:awhollynewcollection_0_shard2_replica1] o.a.s.c.SolrCore [awhollynewcollection_0_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@48960c6
[junit4] 2> 513634 INFO (zkCallback-725-thread-6-processing-n:127.0.0.1:54229_solr) [n:127.0.0.1:54229_solr c:awhollynewcollection_0 s:shard2 r:core_node7 x:awhollynewcollection_0_shard2_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard2.replica1
[junit4] 2> 513635 INFO (jetty-closer-707-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@527c35d4{/solr,null,UNAVAILABLE}
[junit4] 2> 513635 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 513636 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33290 33290
[junit4] 2> 513811 INFO (Thread-1453) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33290 33290
[junit4] 2> 513811 WARN (Thread-1453) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/aliases.json
[junit4] 2> 25 /solr/clusterprops.json
[junit4] 2> 23 /solr/configs/conf
[junit4] 2> 5 /solr/configs/conf2
[junit4] 2> 4 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 337 /solr/clusterstate.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/shard1/election/99609706704404491-core_node3-n_0000000000
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard2/election/99609706704404492-core_node2-n_0000000000
[junit4] 2> 2 /solr/collections/halfdeletedcollection/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 482 /solr/collections
[junit4] 2> 25 /solr/live_nodes
[junit4] 2>
[junit4] 2> 513812 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[E754C01620BF8B9A]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E754C01620BF8B9A-001
[junit4] 2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=5, maxDocsPerChunk=8, blockSize=389), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=5, blockSize=389)), sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=cs-CZ, timezone=US/Aleutian
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=4,threads=1,free=66574168,total=514326528
[junit4] 2> NOTE: All tests run in this JVM: [URLClassifyProcessorTest, DistanceFunctionTest, TestSolrCloudWithDelegationTokens, TestConfigSetsAPIExclusivity, DistributedFacetPivotSmallTest, TestPayloadScoreQParserPlugin, TestImpersonationWithHadoopAuth, SpatialHeatmapFacetsTest, TestSQLHandlerNonCloud, TestFieldCollectionResource, TestFuzzyAnalyzedSuggestions, SoftAutoCommitTest, TestFiltering, DistributedFacetPivotLargeTest, SolrInfoMBeanTest, SpellCheckComponentTest, RankQueryTest, FullHLLTest, TestClusterProperties, TestObjectReleaseTracker, SystemInfoHandlerTest, TestRandomRequestDistribution, TermVectorComponentTest, SpellingQueryConverterTest, SparseHLLTest, HdfsDirectoryFactoryTest, TestSolrQueryParserDefaultOperatorResource, SolrJmxReporterCloudTest, TestQuerySenderListener, TestReqParamsAPI, TestCollectionAPIs, TestCloudManagedSchema, TestCustomSort, TestCursorMarkWithoutUniqueKey, PKIAuthenticationIntegrationTest, TestDistributedGrouping, TestRequestForwarding, LoggingHandlerTest, CollectionStateFormat2Test, SharedFSAutoReplicaFailoverUtilsTest, CleanupOldIndexTest, TestLeaderElectionZkExpiry, ChaosMonkeySafeLeaderTest, AssignTest, TestJsonFacetRefinement, BasicFunctionalityTest, UUIDUpdateProcessorFallbackTest, GraphQueryTest, TestTrie, SegmentsInfoRequestHandlerTest, RuleEngineTest, MoreLikeThisHandlerTest, ZkSolrClientTest, TestUpdate, RAMDirectoryFactoryTest, TestNoOpRegenerator, TestStressVersions, TestRuleBasedAuthorizationPlugin, TestElisionMultitermQuery, SpellCheckCollatorTest, TestShardHandlerFactory, TestCopyFieldCollectionResource, DirectSolrConnectionTest, TestReloadDeadlock, TestBM25SimilarityFactory, TestSchemaManager, TestCharFilters, TestSystemIdResolver, TestSchemaSimilarityResource, SortByFunctionTest, CursorMarkTest, SliceStateTest, HdfsBasicDistributedZkTest, TestLRUCache, TestSolrIndexConfig, BlockCacheTest, TriLevelCompositeIdRoutingTest, TestIntervalFaceting, ConnectionReuseTest, DistributedIntervalFacetingTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [213/713 (1!)] on J1 in 125.86s, 20 tests, 1 failure <<< FAILURES!
[...truncated 47912 lines...]
[JENKINS] Lucene-Solr-Tests-6.6 - Build # 45 - Still unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.6/45/
2 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
Stack Trace:
java.lang.AssertionError: Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
at __randomizedtesting.SeedInfo.seed([CB4E4B01BDAA51DA:833B3FB5BB997E4F]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.checkNoTwoShardsUseTheSameIndexDir(CollectionsAPIDistributedZkTest.java:646)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:524)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.cloud.LegacyCloudClusterPropTest.testCreateCollectionSwitchLegacyCloud
Error Message:
Should have found property replicaType in properties file
Stack Trace:
java.lang.AssertionError: Should have found property replicaType in properties file
at __randomizedtesting.SeedInfo.seed([CB4E4B01BDAA51DA:1A49B98419A5DAE8]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.LegacyCloudClusterPropTest.checkMandatoryProps(LegacyCloudClusterPropTest.java:158)
at org.apache.solr.cloud.LegacyCloudClusterPropTest.createAndTest(LegacyCloudClusterPropTest.java:90)
at org.apache.solr.cloud.LegacyCloudClusterPropTest.testCreateCollectionSwitchLegacyCloud(LegacyCloudClusterPropTest.java:69)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 11532 lines...]
[junit4] Suite: org.apache.solr.cloud.LegacyCloudClusterPropTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.LegacyCloudClusterPropTest_CB4E4B01BDAA51DA-001/init-core-data-001
[junit4] 2> 244973 WARN (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=14 numCloses=14
[junit4] 2> 244973 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 244975 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 244975 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.LegacyCloudClusterPropTest_CB4E4B01BDAA51DA-001/tempDir-001
[junit4] 2> 244975 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 244976 INFO (Thread-1030) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 244976 INFO (Thread-1030) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 244980 ERROR (Thread-1030) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 245076 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:37640
[junit4] 2> 245081 INFO (jetty-launcher-629-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 245082 INFO (jetty-launcher-629-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@76c7edd6{/solr,null,AVAILABLE}
[junit4] 2> 245084 INFO (jetty-launcher-629-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@43492ecf{HTTP/1.1,[http/1.1]}{127.0.0.1:57841}
[junit4] 2> 245084 INFO (jetty-launcher-629-thread-1) [ ] o.e.j.s.Server Started @247327ms
[junit4] 2> 245085 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57841}
[junit4] 2> 245085 ERROR (jetty-launcher-629-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 245085 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 245085 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 245085 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 245085 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-02T07:10:17.202Z
[junit4] 2> 245087 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 245107 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 245107 INFO (jetty-launcher-629-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37640/solr
[junit4] 2> 245149 INFO (jetty-launcher-629-thread-1) [n:127.0.0.1:57841_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 245150 INFO (jetty-launcher-629-thread-1) [n:127.0.0.1:57841_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57841_solr
[junit4] 2> 245152 INFO (jetty-launcher-629-thread-1) [n:127.0.0.1:57841_solr ] o.a.s.c.Overseer Overseer (id=99613056505872387-127.0.0.1:57841_solr-n_0000000000) starting
[junit4] 2> 245175 INFO (jetty-launcher-629-thread-1) [n:127.0.0.1:57841_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57841_solr
[junit4] 2> 245179 INFO (zkCallback-636-thread-1-processing-n:127.0.0.1:57841_solr) [n:127.0.0.1:57841_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 245285 INFO (jetty-launcher-629-thread-1) [n:127.0.0.1:57841_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.LegacyCloudClusterPropTest_CB4E4B01BDAA51DA-001/tempDir-001/node1/.
[junit4] 2> 245321 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 245325 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37640/solr ready
[junit4] 2> 245336 INFO (TEST-LegacyCloudClusterPropTest.testCreateCollectionSwitchLegacyCloud-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateCollectionSwitchLegacyCloud
[junit4] 2> 245354 INFO (qtp152708473-3427) [n:127.0.0.1:57841_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterprop with params val=true&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 245357 INFO (qtp152708473-3427) [n:127.0.0.1:57841_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={val=true&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 245362 INFO (qtp152708473-3428) [n:127.0.0.1:57841_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&maxShardsPerNode=1&name=legacyTrue&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 245364 INFO (OverseerThreadFactory-1524-thread-1-processing-n:127.0.0.1:57841_solr) [n:127.0.0.1:57841_solr ] o.a.s.c.CreateCollectionCmd Create collection legacyTrue
[junit4] 2> 245471 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=legacyTrue_shard1_replica1&action=CREATE&numShards=1&collection=legacyTrue&shard=shard1&wt=javabin&version=2
[junit4] 2> 245471 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 245575 INFO (zkCallback-636-thread-1-processing-n:127.0.0.1:57841_solr) [n:127.0.0.1:57841_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/legacyTrue/state.json] for collection [legacyTrue] has occurred - updating... (live nodes size: [1])
[junit4] 2> 246483 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 246489 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.s.IndexSchema [legacyTrue_shard1_replica1] Schema name=minimal
[junit4] 2> 246491 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 246491 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'legacyTrue_shard1_replica1' using configuration from collection legacyTrue, trusted=true
[junit4] 2> 246491 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 246491 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.SolrCore [[legacyTrue_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.LegacyCloudClusterPropTest_CB4E4B01BDAA51DA-001/tempDir-001/node1/legacyTrue_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.LegacyCloudClusterPropTest_CB4E4B01BDAA51DA-001/tempDir-001/node1/./legacyTrue_shard1_replica1/data/]
[junit4] 2> 246521 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 246521 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 246522 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 246522 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 246523 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@d834ae6[legacyTrue_shard1_replica1] main]
[junit4] 2> 246524 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 246525 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 246525 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 246525 INFO (searcherExecutor-1527-thread-1-processing-n:127.0.0.1:57841_solr x:legacyTrue_shard1_replica1 s:shard1 c:legacyTrue) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.SolrCore [legacyTrue_shard1_replica1] Registered new searcher Searcher@d834ae6[legacyTrue_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 246526 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593808905718202368
[junit4] 2> 246531 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 246531 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 246531 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:57841/solr/legacyTrue_shard1_replica1/
[junit4] 2> 246531 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 246531 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:57841/solr/legacyTrue_shard1_replica1/ has no replicas
[junit4] 2> 246531 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 246534 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:57841/solr/legacyTrue_shard1_replica1/ shard1
[junit4] 2> 246636 INFO (zkCallback-636-thread-2-processing-n:127.0.0.1:57841_solr) [n:127.0.0.1:57841_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/legacyTrue/state.json] for collection [legacyTrue] has occurred - updating... (live nodes size: [1])
[junit4] 2> 246685 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 246687 INFO (qtp152708473-3430) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 x:legacyTrue_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=legacyTrue_shard1_replica1&action=CREATE&numShards=1&collection=legacyTrue&shard=shard1&wt=javabin&version=2} status=0 QTime=1216
[junit4] 2> 246695 INFO (qtp152708473-3428) [n:127.0.0.1:57841_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 246789 INFO (zkCallback-636-thread-2-processing-n:127.0.0.1:57841_solr) [n:127.0.0.1:57841_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/legacyTrue/state.json] for collection [legacyTrue] has occurred - updating... (live nodes size: [1])
[junit4] 2> 247370 INFO (OverseerCollectionConfigSetProcessor-99613056505872387-127.0.0.1:57841_solr-n_0000000000) [n:127.0.0.1:57841_solr ] 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> 247695 INFO (qtp152708473-3428) [n:127.0.0.1:57841_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&maxShardsPerNode=1&name=legacyTrue&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2333
[junit4] 2> 247698 INFO (TEST-LegacyCloudClusterPropTest.testCreateCollectionSwitchLegacyCloud-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreateCollectionSwitchLegacyCloud
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=LegacyCloudClusterPropTest -Dtests.method=testCreateCollectionSwitchLegacyCloud -Dtests.seed=CB4E4B01BDAA51DA -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=es-GT -Dtests.timezone=VST -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 2.37s J2 | LegacyCloudClusterPropTest.testCreateCollectionSwitchLegacyCloud <<<
[junit4] > Throwable #1: java.lang.AssertionError: Should have found property replicaType in properties file
[junit4] > at __randomizedtesting.SeedInfo.seed([CB4E4B01BDAA51DA:1A49B98419A5DAE8]:0)
[junit4] > at org.apache.solr.cloud.LegacyCloudClusterPropTest.checkMandatoryProps(LegacyCloudClusterPropTest.java:158)
[junit4] > at org.apache.solr.cloud.LegacyCloudClusterPropTest.createAndTest(LegacyCloudClusterPropTest.java:90)
[junit4] > at org.apache.solr.cloud.LegacyCloudClusterPropTest.testCreateCollectionSwitchLegacyCloud(LegacyCloudClusterPropTest.java:69)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 247701 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 0x161e58c10060005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 247703 INFO (jetty-closer-630-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@43492ecf{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 247703 INFO (jetty-closer-630-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=607123148
[junit4] 2> 247703 INFO (jetty-closer-630-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 247703 INFO (jetty-closer-630-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 247703 INFO (jetty-closer-630-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 247705 INFO (coreCloseExecutor-1532-thread-1) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 r:core_node1 x:legacyTrue_shard1_replica1] o.a.s.c.SolrCore [legacyTrue_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@ec96e2d
[junit4] 2> 247705 INFO (coreCloseExecutor-1532-thread-1) [n:127.0.0.1:57841_solr c:legacyTrue s:shard1 r:core_node1 x:legacyTrue_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.legacyTrue.shard1.replica1
[junit4] 2> 247706 INFO (jetty-closer-630-thread-1) [ ] o.a.s.c.Overseer Overseer (id=99613056505872387-127.0.0.1:57841_solr-n_0000000000) closing
[junit4] 2> 247706 INFO (OverseerStateUpdate-99613056505872387-127.0.0.1:57841_solr-n_0000000000) [n:127.0.0.1:57841_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:57841_solr
[junit4] 2> 249207 WARN (zkCallback-636-thread-2-processing-n:127.0.0.1:57841_solr) [n:127.0.0.1:57841_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 249208 INFO (jetty-closer-630-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@76c7edd6{/solr,null,UNAVAILABLE}
[junit4] 2> 249208 ERROR (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 249209 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37640 37640
[junit4] 2> 249379 INFO (Thread-1030) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37640 37640
[junit4] 2> 249380 WARN (Thread-1030) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2> 2 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2> 2 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/live_nodes
[junit4] 2> 2 /solr/collections
[junit4] 2>
[junit4] 2> 249380 INFO (SUITE-LegacyCloudClusterPropTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.LegacyCloudClusterPropTest_CB4E4B01BDAA51DA-001
[junit4] 2> Mar 02, 2018 7:10:21 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {}, docValues:{}, maxPointsInLeafNode=618, maxMBSortInHeap=6.855833757422597, sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=es-GT, timezone=VST
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=4,threads=1,free=222728640,total=524812288
[junit4] 2> NOTE: All tests run in this JVM: [QueryParsingTest, TermVectorComponentDistributedTest, TestTestInjection, TestReload, TestRandomRequestDistribution, TestUseDocValuesAsStored2, SolrCoreMetricManagerTest, TestCoreDiscovery, SolrCoreCheckLockOnStartupTest, CdcrReplicationDistributedZkTest, TestDynamicLoading, PrimUtilsTest, SuggesterTSTTest, TestCollationField, TestReqParamsAPI, PingRequestHandlerTest, DistributedQueryComponentOptimizationTest, TestFieldCacheWithThreads, TestExclusionRuleCollectionAccess, TestCloudPivotFacet, HdfsDirectoryTest, TestUnifiedSolrHighlighter, TestSolrCloudWithDelegationTokens, BlockCacheTest, NoCacheHeaderTest, TestJsonFacetRefinement, TestFieldTypeResource, LukeRequestHandlerTest, TestSolrCoreSnapshots, TestPhraseSuggestions, RequestHandlersTest, SharedFSAutoReplicaFailoverUtilsTest, TestCustomSort, XmlUpdateRequestHandlerTest, TestCloudManagedSchema, DistributedFacetPivotLargeTest, PKIAuthenticationIntegrationTest, TestSolrFieldCacheMBean, TestSystemCollAutoCreate, LegacyCloudClusterPropTest]
[junit4] Completed [56/714 (1!)] on J2 in 4.93s, 1 test, 1 failure <<< FAILURES!
[...truncated 755 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/init-core-data-001
[junit4] 2> 790269 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=8 numCloses=8
[junit4] 2> 790269 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 790270 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 790271 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001
[junit4] 2> 790271 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 790271 INFO (Thread-3007) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 790271 INFO (Thread-3007) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 790279 ERROR (Thread-3007) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 790371 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:57579
[junit4] 2> 790384 INFO (jetty-launcher-1520-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 790385 INFO (jetty-launcher-1520-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 790386 INFO (jetty-launcher-1520-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 790387 INFO (jetty-launcher-1520-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 790391 INFO (jetty-launcher-1520-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6abe088a{/solr,null,AVAILABLE}
[junit4] 2> 790392 INFO (jetty-launcher-1520-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@56235125{SSL,[ssl, http/1.1]}{127.0.0.1:54009}
[junit4] 2> 790393 INFO (jetty-launcher-1520-thread-1) [ ] o.e.j.s.Server Started @792635ms
[junit4] 2> 790393 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54009}
[junit4] 2> 790393 ERROR (jetty-launcher-1520-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 790393 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 790393 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 790393 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 790393 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-02T07:19:22.510Z
[junit4] 2> 790408 INFO (jetty-launcher-1520-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@f86aed7{/solr,null,AVAILABLE}
[junit4] 2> 790408 INFO (jetty-launcher-1520-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@41a62890{SSL,[ssl, http/1.1]}{127.0.0.1:54753}
[junit4] 2> 790408 INFO (jetty-launcher-1520-thread-3) [ ] o.e.j.s.Server Started @792650ms
[junit4] 2> 790408 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54753}
[junit4] 2> 790408 ERROR (jetty-launcher-1520-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 790409 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 790409 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 790409 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 790409 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-02T07:19:22.526Z
[junit4] 2> 790413 INFO (jetty-launcher-1520-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@26485f55{/solr,null,AVAILABLE}
[junit4] 2> 790413 INFO (jetty-launcher-1520-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2ed1e932{SSL,[ssl, http/1.1]}{127.0.0.1:57341}
[junit4] 2> 790413 INFO (jetty-launcher-1520-thread-2) [ ] o.e.j.s.Server Started @792655ms
[junit4] 2> 790413 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57341}
[junit4] 2> 790413 ERROR (jetty-launcher-1520-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 790413 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 790414 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 790414 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 790414 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-02T07:19:22.531Z
[junit4] 2> 790415 INFO (jetty-launcher-1520-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@77ea2124{/solr,null,AVAILABLE}
[junit4] 2> 790416 INFO (jetty-launcher-1520-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5352f974{SSL,[ssl, http/1.1]}{127.0.0.1:55895}
[junit4] 2> 790416 INFO (jetty-launcher-1520-thread-4) [ ] o.e.j.s.Server Started @792658ms
[junit4] 2> 790416 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=55895}
[junit4] 2> 790416 ERROR (jetty-launcher-1520-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 790416 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.3
[junit4] 2> 790416 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 790416 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 790416 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-02T07:19:22.533Z
[junit4] 2> 790427 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 790432 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 790445 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 790447 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 790448 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 790450 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 790451 INFO (jetty-launcher-1520-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57579/solr
[junit4] 2> 790451 INFO (jetty-launcher-1520-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57579/solr
[junit4] 2> 790453 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 0x161e59462160004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 790455 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 790455 INFO (jetty-launcher-1520-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57579/solr
[junit4] 2> 790462 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 790469 INFO (jetty-launcher-1520-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57579/solr
[junit4] 2> 790490 INFO (jetty-launcher-1520-thread-1) [n:127.0.0.1:54009_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 790490 INFO (jetty-launcher-1520-thread-1) [n:127.0.0.1:54009_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:54009_solr
[junit4] 2> 790491 INFO (jetty-launcher-1520-thread-1) [n:127.0.0.1:54009_solr ] o.a.s.c.Overseer Overseer (id=99613092242391048-127.0.0.1:54009_solr-n_0000000000) starting
[junit4] 2> 790501 INFO (jetty-launcher-1520-thread-2) [n:127.0.0.1:57341_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 790502 INFO (jetty-launcher-1520-thread-2) [n:127.0.0.1:57341_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57341_solr
[junit4] 2> 790516 INFO (zkCallback-1536-thread-1-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 790516 INFO (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 790518 INFO (jetty-launcher-1520-thread-4) [n:127.0.0.1:55895_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 790520 INFO (jetty-launcher-1520-thread-4) [n:127.0.0.1:55895_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 790521 INFO (jetty-launcher-1520-thread-4) [n:127.0.0.1:55895_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55895_solr
[junit4] 2> 790522 INFO (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 790522 INFO (zkCallback-1536-thread-1-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 790542 INFO (jetty-launcher-1520-thread-1) [n:127.0.0.1:54009_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54009_solr
[junit4] 2> 790547 INFO (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 790552 INFO (zkCallback-1538-thread-1-processing-n:127.0.0.1:55895_solr) [n:127.0.0.1:55895_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 790557 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 790560 INFO (jetty-launcher-1520-thread-3) [n:127.0.0.1:54753_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 790561 INFO (jetty-launcher-1520-thread-3) [n:127.0.0.1:54753_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 790563 INFO (jetty-launcher-1520-thread-3) [n:127.0.0.1:54753_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54753_solr
[junit4] 2> 790564 INFO (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 790564 INFO (zkCallback-1538-thread-1-processing-n:127.0.0.1:55895_solr) [n:127.0.0.1:55895_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 790570 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 790577 INFO (zkCallback-1545-thread-1-processing-n:127.0.0.1:54753_solr) [n:127.0.0.1:54753_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 790658 INFO (jetty-launcher-1520-thread-1) [n:127.0.0.1:54009_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node1/.
[junit4] 2> 790662 INFO (jetty-launcher-1520-thread-4) [n:127.0.0.1:55895_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node4/.
[junit4] 2> 790676 INFO (jetty-launcher-1520-thread-3) [n:127.0.0.1:54753_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node3/.
[junit4] 2> 790701 INFO (jetty-launcher-1520-thread-2) [n:127.0.0.1:57341_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node2/.
[junit4] 2> 790716 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 790717 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:57579/solr ready
[junit4] 2> 790747 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
[junit4] 2> 790748 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 790817 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr ] 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> 790819 INFO (OverseerThreadFactory-4139-thread-1-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.CreateCollectionCmd Create collection collection
[junit4] 2> 790819 WARN (OverseerThreadFactory-4139-thread-1-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] 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> 790820 ERROR (OverseerThreadFactory-4139-thread-1-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] 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:226)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 790823 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr ] 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> 790843 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
[junit4] 2> 790864 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection
[junit4] 2> 790865 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 790868 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2
[junit4] 2> 790869 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 790870 INFO (OverseerStateUpdate-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 791878 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 791885 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 791887 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 791887 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 791888 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 791888 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node2/halfdeletedcollection_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-002/]
[junit4] 2> 791921 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 791921 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 791922 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 791922 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 791923 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@567f395e[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 791924 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 791924 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 791924 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 791924 INFO (searcherExecutor-4148-thread-1-processing-n:127.0.0.1:57341_solr x:halfdeletedcollection_shard1_replica1 c:halfdeletedcollection) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@567f395e[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 791924 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593809477609455616
[junit4] 2> 791930 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 791930 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 791930 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:57341/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 791930 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 791930 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:57341/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 791930 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 791933 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:57341/solr/halfdeletedcollection_shard1_replica1/ shard2
[junit4] 2> 792084 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 792086 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2} status=0 QTime=1218
[junit4] 2> 792088 INFO (qtp1492280155-9768) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 792090 INFO (OverseerThreadFactory-4139-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 792090 INFO (OverseerCollectionConfigSetProcessor-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] 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> 792094 INFO (qtp1492280155-9773) [n:127.0.0.1:57341_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 792094 INFO (qtp1492280155-9773) [n:127.0.0.1:57341_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@11c57125
[junit4] 2> 792095 INFO (qtp1492280155-9773) [n:127.0.0.1:57341_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 792096 INFO (qtp1492280155-9773) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 792799 INFO (qtp1492280155-9768) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=710
[junit4] 2> 792801 INFO (qtp1492280155-9771) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 792801 INFO (qtp1492280155-9771) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 792802 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 792804 INFO (OverseerThreadFactory-4139-thread-3-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.CreateCollectionCmd Create collection halfdeletedcollection
[junit4] 2> 792804 INFO (OverseerCollectionConfigSetProcessor-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] 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> 793016 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2
[junit4] 2> 793066 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2
[junit4] 2> 793066 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 793170 INFO (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 793170 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 794026 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 794034 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 794036 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 794036 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 794037 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 794037 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node2/halfdeletedcollection_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node2/./halfdeletedcollection_shard1_replica1/data/]
[junit4] 2> 794080 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.3
[junit4] 2> 794088 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica1] Schema name=minimal
[junit4] 2> 794090 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 794091 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard2_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 794091 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 794091 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node1/halfdeletedcollection_shard2_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001/tempDir-001/node1/./halfdeletedcollection_shard2_replica1/data/]
[junit4] 2> 794099 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 794099 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 794100 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 794100 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 794100 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1229762b[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 794101 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 794101 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 794102 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 794102 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593809479893254144
[junit4] 2> 794103 INFO (searcherExecutor-4153-thread-1-processing-n:127.0.0.1:57341_solr x:halfdeletedcollection_shard1_replica1 s:shard1 c:halfdeletedcollection) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@1229762b[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 794107 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 794107 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 794107 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:57341/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 794107 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 794107 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:57341/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 794107 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 794111 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:57341/solr/halfdeletedcollection_shard1_replica1/ shard1
[junit4] 2> 794127 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 794127 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 794138 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 794138 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 794138 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@61a2b9d4[halfdeletedcollection_shard2_replica1] main]
[junit4] 2> 794139 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 794140 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 794140 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 794140 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593809479933100032
[junit4] 2> 794140 INFO (searcherExecutor-4154-thread-1-processing-n:127.0.0.1:54009_solr x:halfdeletedcollection_shard2_replica1 s:shard2 c:halfdeletedcollection) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] Registered new searcher Searcher@61a2b9d4[halfdeletedcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 794147 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 794147 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 794147 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:54009/solr/halfdeletedcollection_shard2_replica1/
[junit4] 2> 794147 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 794147 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:54009/solr/halfdeletedcollection_shard2_replica1/ has no replicas
[junit4] 2> 794147 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 794150 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:54009/solr/halfdeletedcollection_shard2_replica1/ shard2
[junit4] 2> 794250 INFO (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 794251 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 794262 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 794266 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=1250
[junit4] 2> 794300 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 794303 INFO (qtp1003230050-9746) [n:127.0.0.1:54009_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=1236
[junit4] 2> 794304 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 794404 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 794404 INFO (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 794805 INFO (OverseerCollectionConfigSetProcessor-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] 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> 795304 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=2501
[junit4] 2> 795306 INFO (qtp1492280155-9769) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 795307 INFO (qtp1492280155-9769) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 795307 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deletePartiallyCreatedCollection
[junit4] 2> 795327 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateNodeSet
[junit4] 2> 795328 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 795330 INFO (qtp1492280155-9773) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 795332 INFO (OverseerThreadFactory-4139-thread-4-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 795334 INFO (qtp1492280155-9772) [n:127.0.0.1:57341_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 795334 INFO (qtp1492280155-9772) [n:127.0.0.1:57341_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@3e755ff3
[junit4] 2> 795335 INFO (qtp1492280155-9772) [n:127.0.0.1:57341_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 795336 INFO (qtp1003230050-9747) [n:127.0.0.1:54009_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard2.replica1
[junit4] 2> 795336 INFO (qtp1003230050-9747) [n:127.0.0.1:54009_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1bd5f22d
[junit4] 2> 795338 INFO (qtp1492280155-9772) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 795339 INFO (qtp1003230050-9747) [n:127.0.0.1:54009_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard2.replica1
[junit4] 2> 795342 INFO (qtp1003230050-9747) [n:127.0.0.1:54009_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 796046 INFO (qtp1492280155-9773) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=715
[junit4] 2> 796048 INFO (qtp1492280155-9768) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=nodeset_collection&action=CREATE&numShards=2&createNodeSet=https://127.0.0.1:54753/solr,https://127.0.0.1:55895/solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 796049 INFO (OverseerThreadFactory-4139-thread-5-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.CreateCollectionCmd Create collection nodeset_collection
[junit4] 2> 796050 WARN (OverseerThreadFactory-4139-thread-5-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.CreateCollectionCmd It is unusual to create a collection (nodeset_collection) without cores.
[junit4] 2> 796050 INFO (OverseerCollectionConfigSetProcessor-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] 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> 796258 INFO (qtp1492280155-9768) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 796258 INFO (qtp1492280155-9768) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=nodeset_collection&action=CREATE&numShards=2&createNodeSet=https://127.0.0.1:54753/solr,https://127.0.0.1:55895/solr&wt=javabin&version=2} status=0 QTime=210
[junit4] 2> 796259 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreateNodeSet
[junit4] 2> 796293 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionRemovesStaleZkCollectionsNode
[junit4] 2> 796294 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 796296 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=nodeset_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 796298 INFO (OverseerThreadFactory-4139-thread-5-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 796298 INFO (OverseerCollectionConfigSetProcessor-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] 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> 797001 INFO (qtp1492280155-9774) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=nodeset_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=704
[junit4] 2> 797005 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=out_of_sync_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 797011 INFO (OverseerCollectionConfigSetProcessor-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] 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> 797014 INFO (qtp1492280155-9775) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=out_of_sync_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 797016 INFO (qtp1492280155-9769) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 797016 INFO (qtp1492280155-9769) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 797016 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionRemovesStaleZkCollectionsNode
[junit4] 2> 797045 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
[junit4] 2> 797046 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 797049 INFO (qtp1492280155-9769) [n:127.0.0.1:57341_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 797051 INFO (OverseerThreadFactory-4139-thread-5-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.CreateCollectionCmd Create collection acollection
[junit4] 2> 797051 ERROR (OverseerThreadFactory-4139-thread-5-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards is a required param (when using CompositeId router).
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:112)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:226)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 797052 INFO (OverseerCollectionConfigSetProcessor-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] 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> 797059 INFO (qtp1492280155-9769) [n:127.0.0.1:57341_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2} status=400 QTime=10
[junit4] 2> 797064 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
[junit4] 2> 797089 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBadActionNames
[junit4] 2> 797090 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[CB4E4B01BDAA51DA]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 797093 ERROR (qtp1492280155-9773) [n:127.0.0.1:57341_solr ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Unknown action: BADACTION
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:210)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510)
[...truncated too long message...]
re@5a0f1cd6
[junit4] 2> 880368 INFO (coreCloseExecutor-4410-thread-1) [n:127.0.0.1:55895_solr c:nodes_used_collection s:shard1 r:core_node1 x:nodes_used_collection_shard1_replica2] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard1.replica2
[junit4] 2> 880368 INFO (coreCloseExecutor-4409-thread-1) [n:127.0.0.1:54753_solr c:nodes_used_collection s:shard2 r:core_node2 x:nodes_used_collection_shard2_replica2] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard2.replica2
[junit4] 2> 880369 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 880369 INFO (zkCallback-1545-thread-2-processing-n:127.0.0.1:54753_solr) [n:127.0.0.1:54753_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 880369 INFO (zkCallback-1538-thread-1-processing-n:127.0.0.1:55895_solr) [n:127.0.0.1:55895_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 880372 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 880383 INFO (coreCloseExecutor-4413-thread-1) [n:127.0.0.1:54009_solr c:nodes_used_collection s:shard2 r:core_node3 x:nodes_used_collection_shard2_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.nodes_used_collection.shard2.replica1
[junit4] 2> 880384 INFO (zkCallback-1536-thread-2-processing-n:127.0.0.1:54009_solr) [n:127.0.0.1:54009_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 880388 INFO (jetty-closer-1521-thread-1) [ ] o.a.s.c.Overseer Overseer (id=99613092242391048-127.0.0.1:54009_solr-n_0000000000) closing
[junit4] 2> 880388 INFO (OverseerStateUpdate-99613092242391048-127.0.0.1:54009_solr-n_0000000000) [n:127.0.0.1:54009_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:54009_solr
[junit4] 2> 880389 INFO (jetty-closer-1521-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6abe088a{/solr,null,UNAVAILABLE}
[junit4] 2> 880390 WARN (zkCallback-1545-thread-3-processing-n:127.0.0.1:54753_solr) [n:127.0.0.1:54753_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 880390 INFO (jetty-closer-1521-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@f86aed7{/solr,null,UNAVAILABLE}
[junit4] 2> 881869 WARN (zkCallback-1539-thread-1-processing-n:127.0.0.1:57341_solr) [n:127.0.0.1:57341_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 881869 INFO (jetty-closer-1521-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@26485f55{/solr,null,UNAVAILABLE}
[junit4] 2> 881872 WARN (zkCallback-1538-thread-1-processing-n:127.0.0.1:55895_solr) [n:127.0.0.1:55895_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 881872 INFO (jetty-closer-1521-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@77ea2124{/solr,null,UNAVAILABLE}
[junit4] 2> 881873 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 881873 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:57579 57579
[junit4] 2> 881971 INFO (Thread-3007) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:57579 57579
[junit4] 2> 881972 WARN (Thread-3007) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/aliases.json
[junit4] 2> 23 /solr/configs/conf
[junit4] 2> 5 /solr/configs/conf2
[junit4] 2> 4 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 289 /solr/clusterstate.json
[junit4] 2> 25 /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> 3 /solr/collections/addReplicaColl/leader_elect/shard1/election/99613092242391049-core_node1-n_0000000000
[junit4] 2> 2 /solr/overseer_elect/election/99613092242391048-127.0.0.1:54009_solr-n_0000000000
[junit4] 2> 2 /solr/collections/onlyinzk/state.json
[junit4] 2> 2 /solr/collections/awhollynewcollection_0/leader_elect/shard1/election/99613092242391049-core_node18-n_0000000001
[junit4] 2> 2 /solr/collections/awhollynewcollection_0/leader_elect/shard1/election/99613092242391048-core_node3-n_0000000000
[junit4] 2> 2 /solr/collections/awhollynewcollection_0/leader_elect/shard2/election/99613092242391049-core_node2-n_0000000000
[junit4] 2> 2 /solr/collections/awhollynewcollection_0/leader_elect/shard3/election/99613092242391048-core_node8-n_0000000000
[junit4] 2> 2 /solr/collections/halfdeletedcollection/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 488 /solr/collections
[junit4] 2> 25 /solr/live_nodes
[junit4] 2>
[junit4] 2> 881972 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[CB4E4B01BDAA51DA]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_CB4E4B01BDAA51DA-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=PostingsFormat(name=Asserting)}, docValues:{}, maxPointsInLeafNode=1672, maxMBSortInHeap=7.1000094344028035, sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=ar-JO, timezone=Atlantic/Cape_Verde
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=4,threads=1,free=103048992,total=516947968
[junit4] 2> NOTE: All tests run in this JVM: [QueryParsingTest, TermVectorComponentDistributedTest, TestTestInjection, TestReload, TestRandomRequestDistribution, TestUseDocValuesAsStored2, SolrCoreMetricManagerTest, TestCoreDiscovery, SolrCoreCheckLockOnStartupTest, CdcrReplicationDistributedZkTest, TestDynamicLoading, PrimUtilsTest, SuggesterTSTTest, TestCollationField, TestReqParamsAPI, PingRequestHandlerTest, DistributedQueryComponentOptimizationTest, TestFieldCacheWithThreads, TestExclusionRuleCollectionAccess, TestCloudPivotFacet, HdfsDirectoryTest, TestUnifiedSolrHighlighter, TestSolrCloudWithDelegationTokens, BlockCacheTest, NoCacheHeaderTest, TestJsonFacetRefinement, TestFieldTypeResource, LukeRequestHandlerTest, TestSolrCoreSnapshots, TestPhraseSuggestions, RequestHandlersTest, SharedFSAutoReplicaFailoverUtilsTest, TestCustomSort, XmlUpdateRequestHandlerTest, TestCloudManagedSchema, DistributedFacetPivotLargeTest, PKIAuthenticationIntegrationTest, TestSolrFieldCacheMBean, TestSystemCollAutoCreate, LegacyCloudClusterPropTest, CursorMarkTest, OutOfBoxZkACLAndCredentialsProvidersTest, TestLMJelinekMercerSimilarityFactory, TestDFRSimilarityFactory, FullHLLTest, HdfsWriteToMultipleCollectionsTest, TimeZoneUtilsTest, MoveReplicaTest, TestLFUCache, PrimitiveFieldTypeTest, SolrPluginUtilsTest, TestIntervalFaceting, TestOrdValues, TestObjectReleaseTracker, OverseerModifyCollectionTest, TestConfig, HdfsCollectionsAPIDistributedZkTest, TestRuleBasedAuthorizationPlugin, RestartWhileUpdatingTest, FullSolrCloudDistribCmdsTest, AutoCommitTest, StatelessScriptUpdateProcessorFactoryTest, MetricsHandlerTest, TestCustomDocTransformer, HdfsRecoveryZkTest, BlockJoinFacetDistribTest, TestFileDictionaryLookup, TestSegmentSorting, TestNoOpRegenerator, ResponseLogComponentTest, TestConfigSets, TestSmileRequest, TestTolerantUpdateProcessorCloud, BinaryUpdateRequestHandlerTest, SolrJmxReporterCloudTest, TestTrieFacet, TestInitParams, TestEmbeddedSolrServerSchemaAPI, TestDistributedMissingSort, FieldAnalysisRequestHandlerTest, ActionThrottleTest, ZkStateReaderTest, DeleteShardTest, TestSolrDynamicMBean, SegmentsInfoRequestHandlerTest, StatsComponentTest, TestIndexingPerformance, SimpleFacetsTest, TestRequestForwarding, CloneFieldUpdateProcessorFactoryTest, TestShardHandlerFactory, SuggesterTest, TestManagedStopFilterFactory, CoreAdminRequestStatusTest, TestCloudDeleteByQuery, BigEndianAscendingWordSerializerTest, TestSubQueryTransformerDistrib, SaslZkACLProviderTest, TestExtendedDismaxParser, SolrTestCaseJ4Test, TestSort, TestStressReorder, TestRecovery, UnloadDistributedZkTest, ParsingFieldUpdateProcessorsTest, HardAutoCommitTest, BadIndexSchemaTest, CurrencyFieldXmlFileTest, AsyncCallRequestStatusResponseTest, TestFieldCache, TestConfigOverlay, BasicDistributedZk2Test, DistributedFacetPivotSmallTest, CloudExitableDirectoryReaderTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [287/714 (2!)] on J2 in 91.72s, 20 tests, 1 failure <<< FAILURES!
[...truncated 47667 lines...]
[JENKINS] Lucene-Solr-Tests-6.6 - Build # 44 - Failure
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.6/44/
All tests passed
Build Log:
[...truncated 10549 lines...]
[javac] Compiling 1088 source files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/classes/java
[javac] /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/core/src/java/org/apache/solr/core/CoreContainer.java:1557: error: cannot find symbol
[javac] DocCollection coll = getZkController().getZkStateReader().getClusterState().getCollection(cd.getCollectionName());
[javac] ^
[javac] symbol: class DocCollection
[javac] location: class CoreContainer
[javac] Note: Some input files use or override a deprecated API.
[javac] Note: Recompile with -Xlint:deprecation for details.
[javac] Note: Some input files use unchecked or unsafe operations.
[javac] Note: Recompile with -Xlint:unchecked for details.
[javac] 1 error
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/build.xml:775: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/build.xml:719: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build.xml:267: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/common-build.xml:549: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/common-build.xml:497: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/common-build.xml:398: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/lucene/common-build.xml:535: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/lucene/common-build.xml:2007: Compile failed; see the compiler error output for details.
Total time: 22 minutes 42 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any