Build: https://builds.apache.org/job/Lucene-Solr-Tests-6.6/51/

1 tests failed.
FAILED:  
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI

Error Message:
Error from server at 
http://127.0.0.1:38929/solr/awhollynewcollection_0_shard2_replica1: 
ClusterState says we are the leader 
(http://127.0.0.1:38929/solr/awhollynewcollection_0_shard2_replica1), but 
locally we don't think so. Request came from null

Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from 
server at http://127.0.0.1:38929/solr/awhollynewcollection_0_shard2_replica1: 
ClusterState says we are the leader 
(http://127.0.0.1:38929/solr/awhollynewcollection_0_shard2_replica1), but 
locally we don't think so. Request came from null
        at 
__randomizedtesting.SeedInfo.seed([CD25B084281E95F7:8550C4302E2DBA62]:0)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:819)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1263)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1134)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1073)
        at 
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:160)
        at 
org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:521)
        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)
Caused by: 
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at 
http://127.0.0.1:38929/solr/awhollynewcollection_0_shard2_replica1: 
ClusterState says we are the leader 
(http://127.0.0.1:38929/solr/awhollynewcollection_0_shard2_replica1), but 
locally we don't think so. Request came from null
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:612)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:447)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:388)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:796)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        ... 1 more




Build Log:
[...truncated 11890 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_CD25B084281E95F7-001/init-core-data-001
   [junit4]   2> 404270 WARN  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
   [junit4]   2> 404271 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields
   [junit4]   2> 404277 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-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> 404278 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-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_CD25B084281E95F7-001/tempDir-001
   [junit4]   2> 404279 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 404279 INFO  (Thread-803) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 404279 INFO  (Thread-803) [    ] o.a.s.c.ZkTestServer Starting 
server
   [junit4]   2> 404283 ERROR (Thread-803) [    ] 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> 404379 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:38975
   [junit4]   2> 404407 INFO  (jetty-launcher-493-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 404407 INFO  (jetty-launcher-493-thread-3) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 404413 INFO  (jetty-launcher-493-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@68f6e559{/solr,null,AVAILABLE}
   [junit4]   2> 404422 INFO  (jetty-launcher-493-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 404423 INFO  (jetty-launcher-493-thread-4) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 404424 INFO  (jetty-launcher-493-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@535fd78c{HTTP/1.1,[http/1.1]}{127.0.0.1:49099}
   [junit4]   2> 404424 INFO  (jetty-launcher-493-thread-2) [    ] 
o.e.j.s.Server Started @407656ms
   [junit4]   2> 404424 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=49099}
   [junit4]   2> 404424 ERROR (jetty-launcher-493-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 404424 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.3
   [junit4]   2> 404424 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 404425 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 404425 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-03-05T22:26:15.496Z
   [junit4]   2> 404433 INFO  (jetty-launcher-493-thread-4) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@6558955{/solr,null,AVAILABLE}
   [junit4]   2> 404434 INFO  (jetty-launcher-493-thread-4) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@627a7481{HTTP/1.1,[http/1.1]}{127.0.0.1:42767}
   [junit4]   2> 404434 INFO  (jetty-launcher-493-thread-4) [    ] 
o.e.j.s.Server Started @407666ms
   [junit4]   2> 404434 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=42767}
   [junit4]   2> 404434 ERROR (jetty-launcher-493-thread-4) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 404434 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.3
   [junit4]   2> 404434 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 404434 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 404434 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-03-05T22:26:15.505Z
   [junit4]   2> 404439 INFO  (jetty-launcher-493-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@46c2e2c6{/solr,null,AVAILABLE}
   [junit4]   2> 404448 INFO  (jetty-launcher-493-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@39e97a85{HTTP/1.1,[http/1.1]}{127.0.0.1:40593}
   [junit4]   2> 404448 INFO  (jetty-launcher-493-thread-1) [    ] 
o.e.j.s.Server Started @407681ms
   [junit4]   2> 404448 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=40593}
   [junit4]   2> 404449 ERROR (jetty-launcher-493-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.3
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@32e87480{/solr,null,AVAILABLE}
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-03-05T22:26:15.520Z
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-3) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@461e8c55{HTTP/1.1,[http/1.1]}{127.0.0.1:38929}
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-3) [    ] 
o.e.j.s.Server Started @407682ms
   [junit4]   2> 404449 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=38929}
   [junit4]   2> 404450 ERROR (jetty-launcher-493-thread-3) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 404450 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.3
   [junit4]   2> 404450 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 404450 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 404450 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-03-05T22:26:15.521Z
   [junit4]   2> 404458 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 404465 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 404478 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 404478 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 404485 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 404487 INFO  (jetty-launcher-493-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38975/solr
   [junit4]   2> 404502 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 404505 INFO  (jetty-launcher-493-thread-4) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38975/solr
   [junit4]   2> 404507 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 404510 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 404524 INFO  (jetty-launcher-493-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38975/solr
   [junit4]   2> 404564 INFO  (jetty-launcher-493-thread-2) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 404592 INFO  (jetty-launcher-493-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38975/solr
   [junit4]   2> 404594 INFO  (jetty-launcher-493-thread-2) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:49099_solr
   [junit4]   2> 404606 INFO  (jetty-launcher-493-thread-2) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.Overseer Overseer 
(id=99633645181468679-127.0.0.1:49099_solr-n_0000000000) starting
   [junit4]   2> 404621 INFO  (jetty-launcher-493-thread-4) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 404623 INFO  (jetty-launcher-493-thread-4) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:42767_solr
   [junit4]   2> 404659 INFO  (jetty-launcher-493-thread-2) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49099_solr
   [junit4]   2> 404680 INFO  
(zkCallback-513-thread-1-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 404681 INFO  
(OverseerStateUpdate-99633645181468679-127.0.0.1:49099_solr-n_0000000000) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 404690 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 404695 INFO  (jetty-launcher-493-thread-1) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 404698 INFO  (jetty-launcher-493-thread-1) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 404700 INFO  (jetty-launcher-493-thread-1) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:40593_solr
   [junit4]   2> 404719 INFO  
(zkCallback-515-thread-1-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 404724 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 404729 INFO  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 404737 INFO  (jetty-launcher-493-thread-3) 
[n:127.0.0.1:38929_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 404745 INFO  (jetty-launcher-493-thread-3) 
[n:127.0.0.1:38929_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 404755 INFO  (jetty-launcher-493-thread-3) 
[n:127.0.0.1:38929_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:38929_solr
   [junit4]   2> 404756 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 404757 INFO  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 404757 INFO  
(zkCallback-515-thread-1-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 404761 INFO  
(zkCallback-517-thread-1-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 404820 INFO  (jetty-launcher-493-thread-4) 
[n:127.0.0.1:42767_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_CD25B084281E95F7-001/tempDir-001/node4/.
   [junit4]   2> 404851 INFO  (jetty-launcher-493-thread-3) 
[n:127.0.0.1:38929_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_CD25B084281E95F7-001/tempDir-001/node2/.
   [junit4]   2> 404856 INFO  (jetty-launcher-493-thread-2) 
[n:127.0.0.1:49099_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_CD25B084281E95F7-001/tempDir-001/node1/.
   [junit4]   2> 404860 INFO  (jetty-launcher-493-thread-1) 
[n:127.0.0.1:40593_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_CD25B084281E95F7-001/tempDir-001/node3/.
   [junit4]   2> 404870 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 404871 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38975/solr ready
   [junit4]   2> 404904 INFO  
(TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[CD25B084281E95F7])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testBadActionNames
   [junit4]   2> 404906 INFO  
(TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[CD25B084281E95F7])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 404914 ERROR (qtp1435928670-3149) [n:127.0.0.1:42767_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)
   [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> 
   [junit4]   2> 404914 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={name=badactioncollection&action=BADACTION&numShards=2&wt=javabin&version=2}
 status=400 QTime=2
   [junit4]   2> 404915 INFO  
(TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[CD25B084281E95F7])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testBadActionNames
   [junit4]   2> 404942 INFO  
(TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[CD25B084281E95F7])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testCoresAreDistributedAcrossNodes
   [junit4]   2> 404944 INFO  
(TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[CD25B084281E95F7])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 404947 INFO  (qtp1435928670-3150) [n:127.0.0.1:42767_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> 404949 INFO  
(OverseerThreadFactory-1502-thread-1-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
nodes_used_collection
   [junit4]   2> 405072 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 405072 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 405072 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 405072 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 406072 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 406072 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 406073 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 406073 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 406073 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 406073 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 406073 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 406080 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 406193 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_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> 406193 INFO  
(zkCallback-517-thread-1-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_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> 406193 INFO  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_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> 406193 INFO  
(zkCallback-515-thread-1-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_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> 407118 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407161 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407162 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407168 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407172 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407173 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407177 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407182 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407182 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407182 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 407182 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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_CD25B084281E95F7-001/tempDir-001/node4/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_CD25B084281E95F7-001/tempDir-001/node4/./nodes_used_collection_shard2_replica1/data/]
   [junit4]   2> 407183 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407184 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407184 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407185 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica2] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 407185 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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_CD25B084281E95F7-001/tempDir-001/node1/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_CD25B084281E95F7-001/tempDir-001/node1/./nodes_used_collection_shard1_replica2/data/]
   [junit4]   2> 407186 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407186 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407187 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 407187 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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_CD25B084281E95F7-001/tempDir-001/node3/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_CD25B084281E95F7-001/tempDir-001/node3/./nodes_used_collection_shard1_replica1/data/]
   [junit4]   2> 407194 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407194 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407195 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica2] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 407195 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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_CD25B084281E95F7-001/tempDir-001/node2/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_CD25B084281E95F7-001/tempDir-001/node2/./nodes_used_collection_shard2_replica2/data/]
   [junit4]   2> 407297 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407297 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407298 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 407298 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 407299 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@7021dd2[nodes_used_collection_shard2_replica2] main]
   [junit4]   2> 407300 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407300 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407301 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 407301 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 407301 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407301 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407302 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_solr 
c:nodes_used_collection s:shard2  x:nodes_used_collection_shard2_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@11993471[nodes_used_collection_shard2_replica1] main]
   [junit4]   2> 407302 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407302 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407303 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407303 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407303 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 407303 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 407303 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407303 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407304 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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> 407304 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407304 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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 1594138326073344000
   [junit4]   2> 407308 INFO  
(searcherExecutor-1514-thread-1-processing-n:127.0.0.1:38929_solr 
x:nodes_used_collection_shard2_replica2 s:shard2 c:nodes_used_collection) 
[n:127.0.0.1:38929_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@7021dd2[nodes_used_collection_shard2_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 407310 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 407310 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 407311 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@e3dc476[nodes_used_collection_shard1_replica1] main]
   [junit4]   2> 407309 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@251d1758[nodes_used_collection_shard1_replica2] main]
   [junit4]   2> 407315 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407315 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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 1594138326084878336
   [junit4]   2> 407317 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407317 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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> 407317 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407317 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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 1594138326086975488
   [junit4]   2> 407317 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407317 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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> 407318 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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 1594138326088024064
   [junit4]   2> 407324 INFO  
(searcherExecutor-1513-thread-1-processing-n:127.0.0.1:40593_solr 
x:nodes_used_collection_shard1_replica1 s:shard1 c:nodes_used_collection) 
[n:127.0.0.1:40593_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@e3dc476[nodes_used_collection_shard1_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 407325 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 407325 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 407325 INFO  
(searcherExecutor-1512-thread-1-processing-n:127.0.0.1:49099_solr 
x:nodes_used_collection_shard1_replica2 s:shard1 c:nodes_used_collection) 
[n:127.0.0.1:49099_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@251d1758[nodes_used_collection_shard1_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 407325 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:40593/solr/nodes_used_collection_shard1_replica1/
   [junit4]   2> 407325 INFO  
(searcherExecutor-1511-thread-1-processing-n:127.0.0.1:42767_solr 
x:nodes_used_collection_shard2_replica1 s:shard2 c:nodes_used_collection) 
[n:127.0.0.1:42767_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@11993471[nodes_used_collection_shard2_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 407325 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard1_replica1 
url=http://127.0.0.1:40593/solr START 
replicas=[http://127.0.0.1:49099/solr/nodes_used_collection_shard1_replica2/] 
nUpdates=100
   [junit4]   2> 407327 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407327 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407327 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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:42767/solr/nodes_used_collection_shard2_replica1/
   [junit4]   2> 407327 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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:42767/solr START 
replicas=[http://127.0.0.1:38929/solr/nodes_used_collection_shard2_replica2/] 
nUpdates=100
   [junit4]   2> 407332 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.u.PeerSync PeerSync: core=nodes_used_collection_shard1_replica1 
url=http://127.0.0.1:40593/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 407332 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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:42767/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 407340 INFO  (qtp1695931867-3139) [n:127.0.0.1:38929_solr 
c:nodes_used_collection s:shard2 r:core_node1 
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=4
   [junit4]   2> 407346 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407346 INFO  (qtp55797945-3130) [n:127.0.0.1:49099_solr 
c:nodes_used_collection s:shard1 r:core_node2 
x:nodes_used_collection_shard1_replica2] o.a.s.c.S.Request 
[nodes_used_collection_shard1_replica2]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 407346 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407346 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407347 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 407347 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_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> 407347 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 407350 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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:42767/solr/nodes_used_collection_shard2_replica1/ shard2
   [junit4]   2> 407354 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:40593/solr/nodes_used_collection_shard1_replica1/ shard1
   [junit4]   2> 407457 INFO  
(zkCallback-517-thread-1-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_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> 407457 INFO  
(zkCallback-515-thread-1-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_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> 407457 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_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> 407457 INFO  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_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> 407501 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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> 407504 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_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=2433
   [junit4]   2> 407505 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_solr 
c:nodes_used_collection s:shard1  x:nodes_used_collection_shard1_replica1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 407509 INFO  (qtp773973318-3161) [n:127.0.0.1:40593_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=2439
   [junit4]   2> 407613 INFO  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_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> 407613 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_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> 407613 INFO  
(zkCallback-515-thread-1-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_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> 407614 INFO  
(zkCallback-517-thread-1-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_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> 408333 INFO  (qtp55797945-3132) [n:127.0.0.1:49099_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=3263
   [junit4]   2> 408336 INFO  (qtp1695931867-3142) [n:127.0.0.1:38929_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=3263
   [junit4]   2> 408350 INFO  (qtp1435928670-3150) [n:127.0.0.1:42767_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> 408453 INFO  
(zkCallback-517-thread-1-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_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> 408453 INFO  
(zkCallback-515-thread-1-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_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> 408453 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_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> 408453 INFO  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_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> 408954 INFO  
(OverseerCollectionConfigSetProcessor-99633645181468679-127.0.0.1:49099_solr-n_0000000000)
 [n:127.0.0.1:49099_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> 409351 INFO  (qtp1435928670-3150) [n:127.0.0.1:42767_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=4404
   [junit4]   2> 409352 INFO  
(TEST-CollectionsAPIDistributedZkTest.testCoresAreDistributedAcrossNodes-seed#[CD25B084281E95F7])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testCoresAreDistributedAcrossNodes
   [junit4]   2> 409378 INFO  
(TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[CD25B084281E95F7])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
   [junit4]   2> 409380 INFO  
(TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[CD25B084281E95F7])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 409388 INFO  (qtp1435928670-3151) [n:127.0.0.1:42767_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> 409417 INFO  
(OverseerThreadFactory-1502-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing 
Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 409419 INFO  (qtp773973318-3162) [n:127.0.0.1:40593_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard1.replica1
   [junit4]   2> 409420 INFO  (qtp55797945-3133) [n:127.0.0.1:49099_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard1.replica2
   [junit4]   2> 409420 INFO  (qtp1435928670-3153) [n:127.0.0.1:42767_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard2.replica1
   [junit4]   2> 409422 INFO  (qtp773973318-3162) [n:127.0.0.1:40593_solr    ] 
o.a.s.c.SolrCore [nodes_used_collection_shard1_replica1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@501e207a
   [junit4]   2> 409422 INFO  (qtp1695931867-3144) [n:127.0.0.1:38929_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard2.replica2
   [junit4]   2> 409425 INFO  (qtp55797945-3133) [n:127.0.0.1:49099_solr    ] 
o.a.s.c.SolrCore [nodes_used_collection_shard1_replica2]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@1ee3356d
   [junit4]   2> 409425 INFO  (qtp1435928670-3153) [n:127.0.0.1:42767_solr    ] 
o.a.s.c.SolrCore [nodes_used_collection_shard2_replica1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@47c818df
   [junit4]   2> 409425 INFO  (qtp1695931867-3144) [n:127.0.0.1:38929_solr    ] 
o.a.s.c.SolrCore [nodes_used_collection_shard2_replica2]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@5b158290
   [junit4]   2> 409432 INFO  (qtp1435928670-3153) [n:127.0.0.1:42767_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard2.replica1
   [junit4]   2> 409439 INFO  (qtp1695931867-3144) [n:127.0.0.1:38929_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard2.replica2
   [junit4]   2> 409441 INFO  (qtp773973318-3162) [n:127.0.0.1:40593_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard1.replica1
   [junit4]   2> 409450 INFO  (qtp1695931867-3144) [n:127.0.0.1:38929_solr    ] 
o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader 
parent node, won't remove previous leader registration.
   [junit4]   2> 409452 WARN  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.LeaderElector 
   [junit4]   2> org.apache.solr.common.SolrException: SolrCore not 
found:nodes_used_collection_shard1_replica2 in []
   [junit4]   2>        at 
org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:294)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:170)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:135)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:56)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:348)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient$3.lambda$process$0(SolrZkClient.java:269)
   [junit4]   2>        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]   2>        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [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> 409452 WARN  
(zkCallback-517-thread-1-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_solr    ] o.a.s.c.LeaderElector Our node is no longer in 
line to be leader
   [junit4]   2> 409458 INFO  (qtp55797945-3133) [n:127.0.0.1:49099_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.nodes_used_collection.shard1.replica2
   [junit4]   2> 409453 INFO  (qtp1435928670-3153) [n:127.0.0.1:42767_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=33
   [junit4]   2> 409453 INFO  (qtp773973318-3162) [n:127.0.0.1:40593_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=33
   [junit4]   2> 409452 INFO  (qtp1695931867-3144) [n:127.0.0.1:38929_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=30
   [junit4]   2> 409466 INFO  (qtp55797945-3133) [n:127.0.0.1:49099_solr    ] 
o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader 
parent node, won't remove previous leader registration.
   [junit4]   2> 409467 INFO  (qtp55797945-3133) [n:127.0.0.1:49099_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=47
   [junit4]   2> 410174 INFO  (qtp1435928670-3151) [n:127.0.0.1:42767_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=785
   [junit4]   2> 410175 INFO  
(OverseerCollectionConfigSetProcessor-99633645181468679-127.0.0.1:49099_solr-n_0000000000)
 [n:127.0.0.1:49099_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> 410177 INFO  (qtp1435928670-3145) [n:127.0.0.1:42767_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> 410179 INFO  
(OverseerThreadFactory-1502-thread-3-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
collection
   [junit4]   2> 410179 WARN  
(OverseerThreadFactory-1502-thread-3-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_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> 410180 ERROR 
(OverseerThreadFactory-1502-thread-3-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_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> 410195 INFO  (qtp1435928670-3145) [n:127.0.0.1:42767_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=18
   [junit4]   2> 410196 INFO  
(TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[CD25B084281E95F7])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
   [junit4]   2> 410238 INFO  
(TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[CD25B084281E95F7]) [ 
   ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
   [junit4]   2> 410239 INFO  
(TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[CD25B084281E95F7]) [ 
   ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 410243 INFO  (qtp1435928670-3152) [n:127.0.0.1:42767_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 410250 INFO  
(OverseerThreadFactory-1502-thread-4-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
addReplicaColl
   [junit4]   2> 410250 INFO  
(OverseerCollectionConfigSetProcessor-99633645181468679-127.0.0.1:49099_solr-n_0000000000)
 [n:127.0.0.1:49099_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> 410458 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 410458 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 410459 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 410459 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr    ] 
o.a.s.u.TestInjection Inject random core creation delay of 1s
   [junit4]   2> 411458 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 411458 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
   [junit4]   2> 411459 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
   [junit4]   2> 411459 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 411577 INFO  
(zkCallback-515-thread-1-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 411577 INFO  
(zkCallback-517-thread-1-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 411577 INFO  
(zkCallback-513-thread-2-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 411578 INFO  
(zkCallback-507-thread-2-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] 
has occurred - updating... (live nodes size: [4])
   [junit4]   2> 412533 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.3
   [junit4]   2> 412533 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.3
   [junit4]   2> 412546 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.3
   [junit4]   2> 412549 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.3
   [junit4]   2> 412552 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.IndexSchema [addReplicaColl_shard1_replica1] Schema name=minimal
   [junit4]   2> 412559 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 412559 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica1' using 
configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 412562 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.IndexSchema [addReplicaColl_shard2_replica2] Schema name=minimal
   [junit4]   2> 412565 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 412565 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica2' using 
configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 412565 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 412566 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore 
[[addReplicaColl_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_CD25B084281E95F7-001/tempDir-001/node2/addReplicaColl_shard2_replica2],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_CD25B084281E95F7-001/tempDir-001/node2/./addReplicaColl_shard2_replica2/data/]
   [junit4]   2> 412570 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 412570 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore 
[[addReplicaColl_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_CD25B084281E95F7-001/tempDir-001/node3/addReplicaColl_shard1_replica1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_CD25B084281E95F7-001/tempDir-001/node3/./addReplicaColl_shard1_replica1/data/]
   [junit4]   2> 412579 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.IndexSchema [addReplicaColl_shard2_replica1] Schema name=minimal
   [junit4]   2> 412584 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.IndexSchema [addReplicaColl_shard1_replica2] Schema name=minimal
   [junit4]   2> 412588 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 412589 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica1' using 
configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 412589 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 412589 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica2' using 
configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 412589 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 412589 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrCore 
[[addReplicaColl_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_CD25B084281E95F7-001/tempDir-001/node4/addReplicaColl_shard2_replica1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_CD25B084281E95F7-001/tempDir-001/node4/./addReplicaColl_shard2_replica1/data/]
   [junit4]   2> 412589 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 412589 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore 
[[addReplicaColl_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_CD25B084281E95F7-001/tempDir-001/node1/addReplicaColl_shard1_replica2],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-6.6/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_CD25B084281E95F7-001/tempDir-001/node1/./addReplicaColl_shard1_replica2/data/]
   [junit4]   2> 412724 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 412724 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 412725 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 412725 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 412728 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@6f8b7db0[addReplicaColl_shard1_replica2] main]
   [junit4]   2> 412730 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 412730 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 412730 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 412738 INFO  
(searcherExecutor-1534-thread-1-processing-n:127.0.0.1:49099_solr 
x:addReplicaColl_shard1_replica2 s:shard1 c:addReplicaColl) 
[n:127.0.0.1:49099_solr c:addReplicaColl s:shard1  
x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore 
[addReplicaColl_shard1_replica2] Registered new searcher 
Searcher@6f8b7db0[addReplicaColl_shard1_replica2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 412739 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 412739 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 412740 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 412740 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 412741 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@30c9155d[addReplicaColl_shard1_replica1] main]
   [junit4]   2> 412742 INFO  (qtp55797945-3129) [n:127.0.0.1:49099_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1594138331775500288
   [junit4]   2> 412742 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 412742 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 412743 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 412743 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 412743 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 412743 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 412743 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 412745 INFO  (qtp1695931867-3141) [n:127.0.0.1:38929_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@48c833e8[addReplicaColl_shard2_replica2] main]
   [junit4]   2> 412745 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1594138331778646016
   [junit4]   2> 412746 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 412746 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 412747 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 412747 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 412756 INFO  
(searcherExecutor-1531-thread-1-processing-n:127.0.0.1:40593_solr 
x:addReplicaColl_shard1_replica1 s:shard1 c:addReplicaColl) 
[n:127.0.0.1:40593_solr c:addReplicaColl s:shard1  
x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore 
[addReplicaColl_shard1_replica1] Registered new searcher 
Searcher@30c9155d[addReplicaColl_shard1_replica1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 412762 INFO  (qtp773973318-3163) [n:127.0.0.1:40593_solr 
c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard1: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 412763 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@5ebfc88c[addReplicaColl_shard2_replica1] main]
   [junit4]   2> 412764 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 412764 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 412764 INFO  (qtp1435928670-3149) [n:127.0.0.1:42767_solr 
c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] 
o.a.s.h.ReplicationHandler Commits will be reserved for

[...truncated too long message...]

2> 504132 INFO  (jetty-closer-494-thread-3) [    ] o.e.j.s.AbstractConnector 
Stopped ServerConnector@535fd78c{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 504135 INFO  (coreCloseExecutor-1695-thread-1) 
[n:127.0.0.1:42767_solr c:corewithnocollection s:shard1 r:core_node1 
x:corewithnocollection] o.a.s.c.SolrCore [corewithnocollection]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@124e9647
   [junit4]   2> 504136 INFO  (jetty-closer-494-thread-3) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=77082144
   [junit4]   2> 504137 INFO  (jetty-closer-494-thread-3) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 504137 INFO  (jetty-closer-494-thread-3) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
   [junit4]   2> 504137 INFO  (jetty-closer-494-thread-3) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
   [junit4]   2> 504138 INFO  (coreCloseExecutor-1695-thread-2) 
[n:127.0.0.1:42767_solr c:corewithnocollection2 s:shard1 r:core_node1 
x:corewithnocollection2] o.a.s.c.SolrCore [corewithnocollection2]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@133c25b3
   [junit4]   2> 504138 INFO  (coreCloseExecutor-1695-thread-1) 
[n:127.0.0.1:42767_solr c:corewithnocollection s:shard1 r:core_node1 
x:corewithnocollection] o.a.s.m.SolrMetricManager Closing metric reporters for: 
solr.core.corewithnocollection
   [junit4]   2> 504146 WARN  
(zkCallback-539-thread-3-processing-n:127.0.0.1:38929_solr) 
[n:127.0.0.1:38929_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 504146 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:38975) [    
] o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x161f845bcb80011, 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> 504146 INFO  (coreCloseExecutor-1695-thread-2) 
[n:127.0.0.1:42767_solr c:corewithnocollection2 s:shard1 r:core_node1 
x:corewithnocollection2] o.a.s.m.SolrMetricManager Closing metric reporters 
for: solr.core.corewithnocollection2
   [junit4]   2> 504147 INFO  (jetty-closer-494-thread-2) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@a656783{/solr,null,UNAVAILABLE}
   [junit4]   2> 504148 INFO  
(zkCallback-513-thread-1-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 504149 INFO  (jetty-closer-494-thread-3) [    ] 
o.a.s.c.Overseer Overseer 
(id=99633645181468679-127.0.0.1:49099_solr-n_0000000000) closing
   [junit4]   2> 504149 INFO  
(OverseerStateUpdate-99633645181468679-127.0.0.1:49099_solr-n_0000000000) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 
127.0.0.1:49099_solr
   [junit4]   2> 504149 INFO  
(zkCallback-515-thread-6-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 504150 INFO  
(zkCallback-507-thread-6-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 504150 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:38975) [    
] o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x161f845bcb80009, 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> 504151 INFO  
(zkCallback-507-thread-6-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 504160 INFO  
(zkCallback-507-thread-6-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (1)
   [junit4]   2> 504161 WARN  
(zkCallback-507-thread-6-processing-n:127.0.0.1:49099_solr) 
[n:127.0.0.1:49099_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 504161 INFO  (jetty-closer-494-thread-3) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@68f6e559{/solr,null,UNAVAILABLE}
   [junit4]   2> 505650 WARN  
(zkCallback-513-thread-1-processing-n:127.0.0.1:42767_solr) 
[n:127.0.0.1:42767_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 505650 INFO  (jetty-closer-494-thread-1) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@6558955{/solr,null,UNAVAILABLE}
   [junit4]   2> 505659 WARN  
(zkCallback-515-thread-7-processing-n:127.0.0.1:40593_solr) 
[n:127.0.0.1:40593_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 505660 INFO  (jetty-closer-494-thread-4) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@46c2e2c6{/solr,null,UNAVAILABLE}
   [junit4]   2> 505661 ERROR 
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-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> 505661 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:38975 38975
   [junit4]   2> 505762 INFO  (Thread-856) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:38975 38975
   [junit4]   2> 505763 WARN  (Thread-856) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        12      /solr/aliases.json
   [junit4]   2>        12      /solr/clusterprops.json
   [junit4]   2>        8       /solr/configs/conf
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        327     /solr/clusterstate.json
   [junit4]   2>        3       
/solr/collections/acollectionafterbaddelete/state.json
   [junit4]   2>        2       
/solr/collections/halfdeletedcollection/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        354     /solr/collections
   [junit4]   2>        12      /solr/live_nodes
   [junit4]   2> 
   [junit4]   2> 505763 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[CD25B084281E95F7]-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_CD25B084281E95F7-001
   [junit4]   2> Mar 05, 2018 10:27:56 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene62): 
{_version_=BlockTreeOrds(blocksize=128), id=PostingsFormat(name=Memory 
doPackFST= true)}, docValues:{}, maxPointsInLeafNode=1937, 
maxMBSortInHeap=7.548163136433013, 
sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=ms, 
timezone=Asia/Ashgabat
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_144 (64-bit)/cpus=4,threads=1,free=137598104,total=524288000
   [junit4]   2> NOTE: All tests run in this JVM: [DateRangeFieldTest, 
TestMinMaxOnMultiValuedField, TermVectorComponentTest, TermsComponentTest, 
SuggestComponentTest, DistributedFacetPivotSmallAdvancedTest, 
TestRandomCollapseQParserPlugin, DocValuesTest, TestSurroundQueryParser, 
TestFuzzyAnalyzedSuggestions, TestQueryTypes, RAMDirectoryFactoryTest, 
SolrInfoMBeanTest, TestInitQParser, SpellCheckComponentTest, 
SolrGraphiteReporterTest, HdfsUnloadDistributedZkTest, 
TestDownShardTolerantSearch, LeaderFailoverAfterPartitionTest, 
TestClusterStateMutator, ShufflingReplicaListTransformerTest, ExplicitHLLTest, 
TestFieldCacheSanityChecker, DirectSolrConnectionTest, 
TestDocBasedVersionConstraints, TestDistributedGrouping, ZkCLITest, 
ZkControllerTest, TestBM25SimilarityFactory, TestGeoJSONResponseWriter, 
TestSerializedLuceneMatchVersion, TlogReplayBufferedWhileIndexingTest, 
TestCustomStream, TestAddFieldRealTimeGet, TestCloudJSONFacetJoinDomain, 
SortByFunctionTest, TestConfigSetProperties, DistributedTermsComponentTest, 
FileUtilsTest, SimplePostToolTest, TestMultiWordSynonyms, TestNumericTerms32, 
TestSimpleTrackingShardHandler, TestUniqueKeyFieldResource, 
BlobRepositoryCloudTest, TestWordDelimiterFilterFactory, TestSystemIdResolver, 
TestFieldTypeCollectionResource, DistributedIntervalFacetingTest, 
DirectSolrSpellCheckerTest, TestManagedResourceStorage, DistributedQueueTest, 
HighlighterTest, TestClassicSimilarityFactory, 
TestLMDirichletSimilarityFactory, CleanupOldIndexTest, 
TestEmbeddedSolrServerConstructors, TestBlendedInfixSuggestions, 
HdfsChaosMonkeySafeLeaderTest, BufferStoreTest, TestBlobHandler, 
TestInfoStreamLogging, DistributedQueryComponentCustomSortTest, 
TestSolrCoreParser, ExitableDirectoryReaderTest, ReplicationFactorTest, 
TestPointFields, SpellingQueryConverterTest, TestReplicationHandlerBackup, 
CollectionsAPIDistributedZkTest]
   [junit4] Completed [174/714 (1!)] on J1 in 101.76s, 20 tests, 1 error <<< 
FAILURES!

[...truncated 48072 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to