You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/10/09 19:20:19 UTC

[JENKINS] Lucene-Solr-7.x-MacOSX (64bit/jdk1.8.0) - Build # 235 - Still Unstable!

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/235/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

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

Error Message:
Error from server at https://127.0.0.1:52289/solr/awhollynewcollection_0_shard2_replica_n2: ClusterState says we are the leader (https://127.0.0.1:52289/solr/awhollynewcollection_0_shard2_replica_n2), 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 https://127.0.0.1:52289/solr/awhollynewcollection_0_shard2_replica_n2: ClusterState says we are the leader (https://127.0.0.1:52289/solr/awhollynewcollection_0_shard2_replica_n2), but locally we don't think so. Request came from null
	at __randomizedtesting.SeedInfo.seed([E13165F5DAE479A8:A9441141DCD7563D]:0)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:539)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:993)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
	at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:459)
	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:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	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:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	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 https://127.0.0.1:52289/solr/awhollynewcollection_0_shard2_replica_n2: ClusterState says we are the leader (https://127.0.0.1:52289/solr/awhollynewcollection_0_shard2_replica_n2), but locally we don't think so. Request came from null
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:626)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:516)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	... 1 more




Build Log:
[...truncated 11912 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/init-core-data-001
   [junit4]   2> 878327 WARN  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
   [junit4]   2> 878327 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 878332 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 878332 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 878335 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001
   [junit4]   2> 878335 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 878336 INFO  (Thread-1711) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 878336 INFO  (Thread-1711) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 878339 ERROR (Thread-1711) [    ] 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> 878446 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:52286
   [junit4]   2> 878468 INFO  (jetty-launcher-2030-thread-1) [    ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 878469 INFO  (jetty-launcher-2030-thread-2) [    ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 878470 INFO  (jetty-launcher-2030-thread-3) [    ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 878472 INFO  (jetty-launcher-2030-thread-4) [    ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 878474 INFO  (jetty-launcher-2030-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1bc6a61e{/solr,null,AVAILABLE}
   [junit4]   2> 878475 INFO  (jetty-launcher-2030-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@2ca64189{SSL,[ssl, http/1.1]}{127.0.0.1:52288}
   [junit4]   2> 878475 INFO  (jetty-launcher-2030-thread-1) [    ] o.e.j.s.Server Started @881771ms
   [junit4]   2> 878475 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52288}
   [junit4]   2> 878475 ERROR (jetty-launcher-2030-thread-1) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 878475 INFO  (jetty-launcher-2030-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1ac4b43b{/solr,null,AVAILABLE}
   [junit4]   2> 878476 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.1.0
   [junit4]   2> 878476 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 878476 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config dir: null
   [junit4]   2> 878476 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-10-09T18:15:20.839Z
   [junit4]   2> 878482 INFO  (jetty-launcher-2030-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@3cc0799d{SSL,[ssl, http/1.1]}{127.0.0.1:52289}
   [junit4]   2> 878482 INFO  (jetty-launcher-2030-thread-2) [    ] o.e.j.s.Server Started @881778ms
   [junit4]   2> 878482 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52289}
   [junit4]   2> 878483 ERROR (jetty-launcher-2030-thread-2) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 878483 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.1.0
   [junit4]   2> 878483 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 878483 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config dir: null
   [junit4]   2> 878483 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-10-09T18:15:20.846Z
   [junit4]   2> 878485 INFO  (jetty-launcher-2030-thread-3) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2216c53b{/solr,null,AVAILABLE}
   [junit4]   2> 878486 INFO  (jetty-launcher-2030-thread-4) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@25035d5d{/solr,null,AVAILABLE}
   [junit4]   2> 878486 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 878486 INFO  (jetty-launcher-2030-thread-4) [    ] o.e.j.s.AbstractConnector Started ServerConnector@19e20c85{SSL,[ssl, http/1.1]}{127.0.0.1:52292}
   [junit4]   2> 878486 INFO  (jetty-launcher-2030-thread-3) [    ] o.e.j.s.AbstractConnector Started ServerConnector@20b0e979{SSL,[ssl, http/1.1]}{127.0.0.1:52291}
   [junit4]   2> 878486 INFO  (jetty-launcher-2030-thread-4) [    ] o.e.j.s.Server Started @881783ms
   [junit4]   2> 878486 INFO  (jetty-launcher-2030-thread-3) [    ] o.e.j.s.Server Started @881783ms
   [junit4]   2> 878486 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52292}
   [junit4]   2> 878487 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52291}
   [junit4]   2> 878487 ERROR (jetty-launcher-2030-thread-4) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 878487 ERROR (jetty-launcher-2030-thread-3) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 878488 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.1.0
   [junit4]   2> 878489 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 878489 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config dir: null
   [junit4]   2> 878489 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.1.0
   [junit4]   2> 878489 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 878489 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-10-09T18:15:20.852Z
   [junit4]   2> 878489 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config dir: null
   [junit4]   2> 878489 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-10-09T18:15:20.852Z
   [junit4]   2> 878491 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 878494 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 878494 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 878495 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 878495 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 878496 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 878496 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 878503 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 878503 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 878510 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 878510 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 878514 INFO  (jetty-launcher-2030-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52286/solr
   [junit4]   2> 878514 INFO  (jetty-launcher-2030-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52286/solr
   [junit4]   2> 878516 INFO  (jetty-launcher-2030-thread-3) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52286/solr
   [junit4]   2> 878516 INFO  (jetty-launcher-2030-thread-4) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52286/solr
   [junit4]   2> 878785 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 878786 INFO  (jetty-launcher-2030-thread-4) [n:127.0.0.1:52292_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 878786 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:52291_solr
   [junit4]   2> 878788 INFO  (jetty-launcher-2030-thread-4) [n:127.0.0.1:52292_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52292_solr
   [junit4]   2> 878790 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.c.Overseer Overseer (id=98800298931060748-127.0.0.1:52291_solr-n_0000000000) starting
   [junit4]   2> 878791 INFO  (zkCallback-2052-thread-1-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 878792 INFO  (zkCallback-2051-thread-1-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 878794 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 878795 INFO  (jetty-launcher-2030-thread-2) [n:127.0.0.1:52289_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 878805 INFO  (jetty-launcher-2030-thread-2) [n:127.0.0.1:52289_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52289_solr
   [junit4]   2> 878887 INFO  (zkCallback-2051-thread-1-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 878896 INFO  (zkCallback-2052-thread-1-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 878906 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 878914 INFO  (jetty-launcher-2030-thread-4) [n:127.0.0.1:52292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 878921 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52291_solr
   [junit4]   2> 878926 INFO  (zkCallback-2051-thread-1-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 878926 INFO  (zkCallback-2052-thread-1-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 878927 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 878941 INFO  (jetty-launcher-2030-thread-2) [n:127.0.0.1:52289_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 878962 INFO  (jetty-launcher-2030-thread-1) [n:127.0.0.1:52288_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 878966 INFO  (jetty-launcher-2030-thread-1) [n:127.0.0.1:52288_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 878970 INFO  (jetty-launcher-2030-thread-4) [n:127.0.0.1:52292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 878970 INFO  (jetty-launcher-2030-thread-4) [n:127.0.0.1:52292_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 878971 INFO  (jetty-launcher-2030-thread-4) [n:127.0.0.1:52292_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node4
   [junit4]   2> 878972 INFO  (jetty-launcher-2030-thread-1) [n:127.0.0.1:52288_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52288_solr
   [junit4]   2> 878973 INFO  (zkCallback-2051-thread-1-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 878974 INFO  (zkCallback-2049-thread-1-processing-n:127.0.0.1:52288_solr) [n:127.0.0.1:52288_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 878978 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 878978 INFO  (zkCallback-2052-thread-1-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 878996 INFO  (jetty-launcher-2030-thread-2) [n:127.0.0.1:52289_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 878996 INFO  (jetty-launcher-2030-thread-2) [n:127.0.0.1:52289_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 878998 INFO  (jetty-launcher-2030-thread-2) [n:127.0.0.1:52289_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node2
   [junit4]   2> 879061 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 879120 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 879120 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 879121 INFO  (jetty-launcher-2030-thread-1) [n:127.0.0.1:52288_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 879122 INFO  (jetty-launcher-2030-thread-3) [n:127.0.0.1:52291_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node3
   [junit4]   2> 879136 INFO  (jetty-launcher-2030-thread-1) [n:127.0.0.1:52288_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 879136 INFO  (jetty-launcher-2030-thread-1) [n:127.0.0.1:52288_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 879137 INFO  (jetty-launcher-2030-thread-1) [n:127.0.0.1:52288_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node1
   [junit4]   2> 879224 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 879226 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:52286/solr ready
   [junit4]   2> 879269 INFO  (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[E13165F5DAE479A8]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
   [junit4]   2> 879271 INFO  (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[E13165F5DAE479A8]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 879297 INFO  (qtp1477444939-9063) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 879300 INFO  (OverseerThreadFactory-4034-thread-1-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd Create collection collection
   [junit4]   2> 879301 WARN  (OverseerThreadFactory-4034-thread-1-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd Specified number of replicas of 10 on collection collection is higher than 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> 879301 ERROR (OverseerThreadFactory-4034-thread-1-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_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, value of nrtReplicas is 10, value of tlogReplicas is 0 and value of pullReplicas is 0. This requires 20 shards to be created (higher than the allowed number)
   [junit4]   2> 	at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:173)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:229)
   [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:188)
   [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> 879306 INFO  (qtp1477444939-9063) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=8
   [junit4]   2> 879311 INFO  (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[E13165F5DAE479A8]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
   [junit4]   2> 879352 INFO  (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[E13165F5DAE479A8]) [    ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionRemovesStaleZkCollectionsNode
   [junit4]   2> 879354 INFO  (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[E13165F5DAE479A8]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 879361 INFO  (qtp1477444939-9064) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=out_of_sync_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 879366 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_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> 879371 INFO  (qtp1477444939-9064) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=out_of_sync_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 879376 INFO  (qtp1477444939-9065) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 879377 INFO  (qtp1477444939-9065) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 879377 INFO  (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[E13165F5DAE479A8]) [    ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionRemovesStaleZkCollectionsNode
   [junit4]   2> 879417 INFO  (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[E13165F5DAE479A8]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testCreateShouldFailOnExistingCore
   [junit4]   2> 879418 INFO  (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[E13165F5DAE479A8]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 879421 INFO  (qtp1477444939-9066) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfcollectionblocker&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 879424 INFO  (OverseerThreadFactory-4034-thread-3-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd Create collection halfcollectionblocker
   [junit4]   2> 879425 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_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> 879425 WARN  (OverseerThreadFactory-4034-thread-3-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd It is unusual to create a collection (halfcollectionblocker) without cores.
   [junit4]   2> 879546 INFO  (qtp1477444939-9066) [n:127.0.0.1:52288_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> 879546 INFO  (qtp1477444939-9066) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfcollectionblocker&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=&wt=javabin&version=2} status=0 QTime=125
   [junit4]   2> 879547 INFO  (qtp1477444939-9059) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:52292_solr&name=halfcollection_shard1_replica_n1&action=ADDREPLICA&collection=halfcollectionblocker&shard=shard1&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 879551 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_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> 879552 INFO  (OverseerThreadFactory-4034-thread-4-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:52292_solr for creating new replica
   [junit4]   2> 879554 INFO  (OverseerStateUpdate-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"addreplica",
   [junit4]   2>   "collection":"halfcollectionblocker",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"halfcollection_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:52292/solr",
   [junit4]   2>   "node_name":"127.0.0.1:52292_solr",
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 879796 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node21&collection.configName=conf&name=halfcollection_shard1_replica_n1&action=CREATE&collection=halfcollectionblocker&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 879797 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 879818 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
   [junit4]   2> 879830 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.IndexSchema [halfcollection_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 879833 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 879833 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard1_replica_n1' using configuration from collection halfcollectionblocker, trusted=true
   [junit4]   2> 879834 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.halfcollectionblocker.shard1.core_node21' (registry 'solr.core.halfcollectionblocker.shard1.core_node21') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 879834 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 879834 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrCore [[halfcollection_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node4/halfcollection_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node4/halfcollection_shard1_replica_n1/data/]
   [junit4]   2> 879891 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 879891 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 879897 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 879897 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 879899 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2ffa92f5[halfcollection_shard1_replica_n1] main]
   [junit4]   2> 879901 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 879901 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 879902 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 879902 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580804784536944640
   [junit4]   2> 879903 INFO  (searcherExecutor-4041-thread-1-processing-n:127.0.0.1:52292_solr x:halfcollection_shard1_replica_n1 s:shard1 c:halfcollectionblocker r:core_node21) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrCore [halfcollection_shard1_replica_n1] Registered new searcher Searcher@2ffa92f5[halfcollection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 879905 INFO  (zkCallback-2051-thread-1-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker/state.json] for collection [halfcollectionblocker] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 879905 INFO  (zkCallback-2051-thread-2-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker/state.json] for collection [halfcollectionblocker] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 879909 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 879909 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 879909 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52292/solr/halfcollection_shard1_replica_n1/
   [junit4]   2> 879909 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 879909 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:52292/solr/halfcollection_shard1_replica_n1/ has no replicas
   [junit4]   2> 879909 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 879914 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52292/solr/halfcollection_shard1_replica_n1/ shard1
   [junit4]   2> 880028 INFO  (zkCallback-2051-thread-2-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker/state.json] for collection [halfcollectionblocker] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880028 INFO  (zkCallback-2051-thread-1-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker/state.json] for collection [halfcollectionblocker] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880087 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 880089 INFO  (qtp11147599-9086) [n:127.0.0.1:52292_solr c:halfcollectionblocker s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node21&collection.configName=conf&name=halfcollection_shard1_replica_n1&action=CREATE&collection=halfcollectionblocker&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=294
   [junit4]   2> 880092 INFO  (qtp1477444939-9059) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:52292_solr&name=halfcollection_shard1_replica_n1&action=ADDREPLICA&collection=halfcollectionblocker&shard=shard1&type=NRT&wt=javabin&version=2} status=0 QTime=544
   [junit4]   2> 880093 INFO  (qtp1477444939-9061) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfcollectionblocker2&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 880095 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd Create collection halfcollectionblocker2
   [junit4]   2> 880096 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 doesn't exist.  Requestor may have disconnected from ZooKeeper
   [junit4]   2> 880096 WARN  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd It is unusual to create a collection (halfcollectionblocker2) without cores.
   [junit4]   2> 880214 INFO  (zkCallback-2051-thread-2-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker/state.json] for collection [halfcollectionblocker] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880214 INFO  (zkCallback-2051-thread-1-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker/state.json] for collection [halfcollectionblocker] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880321 INFO  (qtp1477444939-9061) [n:127.0.0.1:52288_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> 880321 INFO  (qtp1477444939-9061) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfcollectionblocker2&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=&wt=javabin&version=2} status=0 QTime=228
   [junit4]   2> 880322 INFO  (qtp1477444939-9062) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:52289_solr&name=halfcollection_shard1_replica_n1&action=ADDREPLICA&collection=halfcollectionblocker2&shard=shard1&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 880327 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist.  Requestor may have disconnected from ZooKeeper
   [junit4]   2> 880328 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:52289_solr for creating new replica
   [junit4]   2> 880331 INFO  (OverseerStateUpdate-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"addreplica",
   [junit4]   2>   "collection":"halfcollectionblocker2",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"halfcollection_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:52289/solr",
   [junit4]   2>   "node_name":"127.0.0.1:52289_solr",
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 880555 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node21&collection.configName=conf&name=halfcollection_shard1_replica_n1&action=CREATE&collection=halfcollectionblocker2&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 880556 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 880581 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
   [junit4]   2> 880594 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.IndexSchema [halfcollection_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 880596 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 880596 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard1_replica_n1' using configuration from collection halfcollectionblocker2, trusted=true
   [junit4]   2> 880597 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.halfcollectionblocker2.shard1.core_node21' (registry 'solr.core.halfcollectionblocker2.shard1.core_node21') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 880597 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 880597 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrCore [[halfcollection_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node2/halfcollection_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node2/halfcollection_shard1_replica_n1/data/]
   [junit4]   2> 880657 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 880657 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 880658 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 880659 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 880660 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@43bde820[halfcollection_shard1_replica_n1] main]
   [junit4]   2> 880661 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 880662 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 880663 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 880663 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580804785334910976
   [junit4]   2> 880664 INFO  (searcherExecutor-4046-thread-1-processing-n:127.0.0.1:52289_solr x:halfcollection_shard1_replica_n1 s:shard1 c:halfcollectionblocker2 r:core_node21) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SolrCore [halfcollection_shard1_replica_n1] Registered new searcher Searcher@43bde820[halfcollection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 880672 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker2/state.json] for collection [halfcollectionblocker2] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880673 INFO  (zkCallback-2050-thread-2-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker2/state.json] for collection [halfcollectionblocker2] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880679 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 880679 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 880679 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52289/solr/halfcollection_shard1_replica_n1/
   [junit4]   2> 880679 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 880679 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.SyncStrategy https://127.0.0.1:52289/solr/halfcollection_shard1_replica_n1/ has no replicas
   [junit4]   2> 880679 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 880685 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52289/solr/halfcollection_shard1_replica_n1/ shard1
   [junit4]   2> 880794 INFO  (zkCallback-2050-thread-2-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker2/state.json] for collection [halfcollectionblocker2] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880794 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker2/state.json] for collection [halfcollectionblocker2] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880848 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 880851 INFO  (qtp2054221042-9075) [n:127.0.0.1:52289_solr c:halfcollectionblocker2 s:shard1 r:core_node21 x:halfcollection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node21&collection.configName=conf&name=halfcollection_shard1_replica_n1&action=CREATE&collection=halfcollectionblocker2&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=295
   [junit4]   2> 880854 INFO  (qtp1477444939-9062) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={node=127.0.0.1:52289_solr&name=halfcollection_shard1_replica_n1&action=ADDREPLICA&collection=halfcollectionblocker2&shard=shard1&type=NRT&wt=javabin&version=2} status=0 QTime=531
   [junit4]   2> 880855 INFO  (qtp1477444939-9063) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfcollection&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=127.0.0.1:52292_solr,127.0.0.1:52289_solr&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 880858 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd Create collection halfcollection
   [junit4]   2> 880858 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000010 doesn't exist.  Requestor may have disconnected from ZooKeeper
   [junit4]   2> 880976 INFO  (zkCallback-2050-thread-2-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker2/state.json] for collection [halfcollectionblocker2] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 880976 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollectionblocker2/state.json] for collection [halfcollectionblocker2] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 881090 INFO  (OverseerStateUpdate-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"halfcollection",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"halfcollection_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:52292/solr",
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 881094 INFO  (OverseerStateUpdate-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"halfcollection",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"halfcollection_shard2_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:52289/solr",
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 881300 INFO  (qtp11147599-9093) [n:127.0.0.1:52292_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=halfcollection_shard1_replica_n1&action=CREATE&numShards=2&collection=halfcollection&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 881303 WARN  (qtp11147599-9093) [n:127.0.0.1:52292_solr    ] o.a.s.c.CoreContainer Creating a core with existing name is not allowed
   [junit4]   2> 881303 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=halfcollection_shard2_replica_n2&action=CREATE&numShards=2&collection=halfcollection&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 881303 ERROR (qtp11147599-9093) [n:127.0.0.1:52292_solr    ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Core with name 'halfcollection_shard1_replica_n1' already exists.
   [junit4]   2> 	at org.apache.solr.core.CoreContainer.create(CoreContainer.java:921)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:91)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:384)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:389)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174)
   [junit4]   2> 	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:745)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:726)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:507)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:382)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
   [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:426)
   [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:283)
   [junit4]   2> 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
   [junit4]   2> 	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:251)
   [junit4]   2> 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
   [junit4]   2> 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
   [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> 881303 INFO  (qtp11147599-9093) [n:127.0.0.1:52292_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=halfcollection_shard1_replica_n1&action=CREATE&numShards=2&collection=halfcollection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=500 QTime=3
   [junit4]   2> 881303 ERROR (qtp11147599-9093) [n:127.0.0.1:52292_solr    ] o.a.s.s.HttpSolrCall null:org.apache.solr.common.SolrException: Core with name 'halfcollection_shard1_replica_n1' already exists.
   [junit4]   2> 	at org.apache.solr.core.CoreContainer.create(CoreContainer.java:921)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:91)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:384)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:389)
   [junit4]   2> 	at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174)
   [junit4]   2> 	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:745)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:726)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:507)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:382)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
   [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:426)
   [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:283)
   [junit4]   2> 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
   [junit4]   2> 	at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:251)
   [junit4]   2> 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
   [junit4]   2> 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108)
   [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> 881306 ERROR (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerCollectionMessageHandler Error from shard: https://127.0.0.1:52292/solr
   [junit4]   2> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:52292/solr: Core with name 'halfcollection_shard1_replica_n1' already exists.
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:626)
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
   [junit4]   2> 	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219)
   [junit4]   2> 	at org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:172)
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [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 com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [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> 881414 INFO  (zkCallback-2050-thread-2-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollection/state.json] for collection [halfcollection] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 881414 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollection/state.json] for collection [halfcollection] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 882328 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0
   [junit4]   2> 882347 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.s.IndexSchema [halfcollection_shard2_replica_n2] Schema name=minimal
   [junit4]   2> 882352 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 882352 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'halfcollection_shard2_replica_n2' using configuration from collection halfcollection, trusted=true
   [junit4]   2> 882353 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.halfcollection.shard2.replica_n2' (registry 'solr.core.halfcollection.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5f796dc1
   [junit4]   2> 882353 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 882353 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.SolrCore [[halfcollection_shard2_replica_n2] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node2/halfcollection_shard2_replica_n2], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001/tempDir-001/node2/halfcollection_shard2_replica_n2/data/]
   [junit4]   2> 882432 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 882432 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 882433 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 882433 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 882435 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@72450c09[halfcollection_shard2_replica_n2] main]
   [junit4]   2> 882436 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 882437 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 882437 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 882437 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1580804787195084800
   [junit4]   2> 882438 INFO  (searcherExecutor-4051-thread-1-processing-n:127.0.0.1:52289_solr x:halfcollection_shard2_replica_n2 s:shard2 c:halfcollection r:core_node4) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.SolrCore [halfcollection_shard2_replica_n2] Registered new searcher Searcher@72450c09[halfcollection_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 882444 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 882444 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 882444 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:52289/solr/halfcollection_shard2_replica_n2/
   [junit4]   2> 882444 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 882445 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.SyncStrategy https://127.0.0.1:52289/solr/halfcollection_shard2_replica_n2/ has no replicas
   [junit4]   2> 882445 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 882452 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:52289/solr/halfcollection_shard2_replica_n2/ shard2
   [junit4]   2> 882557 INFO  (zkCallback-2050-thread-1-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollection/state.json] for collection [halfcollection] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 882557 INFO  (zkCallback-2050-thread-2-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfcollection/state.json] for collection [halfcollection] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 882605 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 882607 INFO  (qtp2054221042-9076) [n:127.0.0.1:52289_solr c:halfcollection s:shard2 r:core_node4 x:halfcollection_shard2_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=halfcollection_shard2_replica_n2&action=CREATE&numShards=2&collection=halfcollection&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1305
   [junit4]   2> 882608 ERROR (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerCollectionMessageHandler Cleaning up collection [halfcollection].
   [junit4]   2> 882610 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 882611 INFO  (qtp2054221042-9077) [n:127.0.0.1:52289_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfcollection.shard2.replica_n2, tag=null
   [junit4]   2> 882611 INFO  (qtp2054221042-9077) [n:127.0.0.1:52289_solr    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5594a758: rootName = null, domain = solr.core.halfcollection.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.halfcollection.shard2.replica_n2 / com.codahale.metrics.MetricRegistry@43dfee6
   [junit4]   2> 882635 INFO  (qtp2054221042-9077) [n:127.0.0.1:52289_solr    ] o.a.s.c.SolrCore [halfcollection_shard2_replica_n2]  CLOSING SolrCore org.apache.solr.core.SolrCore@486803c3
   [junit4]   2> 882635 INFO  (qtp2054221042-9077) [n:127.0.0.1:52289_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfcollection.shard2.replica_n2, tag=1214776259
   [junit4]   2> 882635 INFO  (qtp2054221042-9077) [n:127.0.0.1:52289_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.halfcollection.shard2.leader, tag=1214776259
   [junit4]   2> 882639 INFO  (qtp2054221042-9077) [n:127.0.0.1:52289_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfcollection_shard2_replica_n2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=28
   [junit4]   2> 883357 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd Cleaned up artifacts for failed create collection for [halfcollection]
   [junit4]   2> 883360 INFO  (qtp1477444939-9063) [n:127.0.0.1:52288_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> 884871 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000012 doesn't exist.  Requestor may have disconnected from ZooKeeper
   [junit4]   2> 913605 ERROR (qtp1477444939-9063) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Timed out waiting for new collection's replicas to become ACTIVE with timeout=30
   [junit4]   2> 913605 INFO  (qtp1477444939-9063) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfcollection&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=127.0.0.1:52292_solr,127.0.0.1:52289_solr&wt=javabin&version=2} status=0 QTime=32750
   [junit4]   2> 913605 INFO  (TEST-CollectionsAPIDistributedZkTest.testCreateShouldFailOnExistingCore-seed#[E13165F5DAE479A8]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testCreateShouldFailOnExistingCore
   [junit4]   2> 913630 INFO  (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[E13165F5DAE479A8]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard
   [junit4]   2> 913631 INFO  (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[E13165F5DAE479A8]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 913633 INFO  (qtp1477444939-9064) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfcollectionblocker2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 913636 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 913643 INFO  (qtp2054221042-9068) [n:127.0.0.1:52289_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfcollectionblocker2.shard1.core_node21, tag=null
   [junit4]   2> 913643 INFO  (qtp2054221042-9068) [n:127.0.0.1:52289_solr    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7e1b39b1: rootName = null, domain = solr.core.halfcollectionblocker2.shard1.core_node21, service url = null, agent id = null] for registry solr.core.halfcollectionblocker2.shard1.core_node21 / com.codahale.metrics.MetricRegistry@3ccd3fd6
   [junit4]   2> 913651 INFO  (qtp2054221042-9068) [n:127.0.0.1:52289_solr    ] o.a.s.c.SolrCore [halfcollection_shard1_replica_n1]  CLOSING SolrCore org.apache.solr.core.SolrCore@71d929c9
   [junit4]   2> 913651 INFO  (qtp2054221042-9068) [n:127.0.0.1:52289_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfcollectionblocker2.shard1.core_node21, tag=1910057417
   [junit4]   2> 913651 INFO  (qtp2054221042-9068) [n:127.0.0.1:52289_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.halfcollectionblocker2.shard1.leader, tag=1910057417
   [junit4]   2> 913654 INFO  (qtp2054221042-9068) [n:127.0.0.1:52289_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfcollection_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=11
   [junit4]   2> 914372 INFO  (qtp1477444939-9064) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfcollectionblocker2&action=DELETE&wt=javabin&version=2} status=0 QTime=739
   [junit4]   2> 914372 INFO  (qtp1477444939-9065) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfcollectionblocker&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 914375 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000014 doesn't exist.  Requestor may have disconnected from ZooKeeper
   [junit4]   2> 914376 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 914380 INFO  (qtp11147599-9094) [n:127.0.0.1:52292_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfcollectionblocker.shard1.core_node21, tag=null
   [junit4]   2> 914380 INFO  (qtp11147599-9094) [n:127.0.0.1:52292_solr    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2f1fd98e: rootName = null, domain = solr.core.halfcollectionblocker.shard1.core_node21, service url = null, agent id = null] for registry solr.core.halfcollectionblocker.shard1.core_node21 / com.codahale.metrics.MetricRegistry@64ff3817
   [junit4]   2> 914388 INFO  (qtp11147599-9094) [n:127.0.0.1:52292_solr    ] o.a.s.c.SolrCore [halfcollection_shard1_replica_n1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1c5e8106
   [junit4]   2> 914388 INFO  (qtp11147599-9094) [n:127.0.0.1:52292_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.halfcollectionblocker.shard1.core_node21, tag=475955462
   [junit4]   2> 914388 INFO  (qtp11147599-9094) [n:127.0.0.1:52292_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.halfcollectionblocker.shard1.leader, tag=475955462
   [junit4]   2> 914397 INFO  (qtp11147599-9094) [n:127.0.0.1:52292_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfcollection_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=17
   [junit4]   2> 915014 INFO  (qtp1477444939-9065) [n:127.0.0.1:52288_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfcollectionblocker&action=DELETE&wt=javabin&version=2} status=0 QTime=641
   [junit4]   2> 915016 INFO  (qtp1477444939-9066) [n:127.0.0.1:52288_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=oversharded&nrtReplicas=2&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 915019 INFO  (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.CreateCollectionCmd Create collection oversharded
   [junit4]   2> 915019 INFO  (OverseerCollectionConfigSetProcessor-98800298931060748-127.0.0.1:52291_solr-n_0000000000) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000016 doesn't exist.  Requestor may have disconnected from ZooKeeper
   [junit4]   2> 915020 ERROR (OverseerThreadFactory-4034-thread-5-processing-n:127.0.0.1:52291_solr) [n:127.0.0.1:52291_solr    ] o.a.s.c.OverseerCollectionMessageHandler Collection: oversharded operation: create failed:org.apache.solr.common.SolrException: Cannot create collection oversharded. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 3, value of nrtReplicas is 2, value of tlogReplicas is 0 and value of pullReplicas is 0. This requires 6 shards to be created (higher than the allowed number)
   [junit4]   2> 	at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:173)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:229)
   [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:188)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.ja

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

.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 962055 INFO  (jetty-closer-2031-thread-3) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2216c53b{/solr,null,UNAVAILABLE}
   [junit4]   2> 963547 WARN  (zkCallback-2051-thread-4-processing-n:127.0.0.1:52292_solr) [n:127.0.0.1:52292_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 963548 INFO  (jetty-closer-2031-thread-1) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@25035d5d{/solr,null,UNAVAILABLE}
   [junit4]   2> 963563 WARN  (zkCallback-2086-thread-2-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.ZkController Unable to register nodeLost path for 127.0.0.1:52288_solr
   [junit4]   2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:52288_solr
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:392)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:389)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:389)
   [junit4]   2> 	at org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:851)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:747)
   [junit4]   2> 	at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:746)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.access$1000(ZkStateReader.java:72)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1152)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1147)
   [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:188)
   [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> 963563 WARN  (zkCallback-2086-thread-2-processing-n:127.0.0.1:52289_solr) [n:127.0.0.1:52289_solr    ] o.a.s.c.ZkController Unable to register nodeLost path for 127.0.0.1:52292_solr
   [junit4]   2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:52292_solr
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:392)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$9.execute(SolrZkClient.java:389)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:389)
   [junit4]   2> 	at org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:851)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:747)
   [junit4]   2> 	at java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:746)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader.access$1000(ZkStateReader.java:72)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1152)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1147)
   [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:188)
   [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> 963564 INFO  (jetty-closer-2031-thread-2) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@36d9b887{/solr,null,UNAVAILABLE}
   [junit4]   2> 963565 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-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> 963565 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[E13165F5DAE479A8]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52286 52286
   [junit4]   2> 963566 INFO  (Thread-1757) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52286 52286
   [junit4]   2> 964071 WARN  (Thread-1757) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	5	/solr/collections/created_and_deleted/state.json
   [junit4]   2> 	4	/solr/collections/awhollynewcollection_0/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	58	/solr/collections
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_E13165F5DAE479A8-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): {id=PostingsFormat(name=MockRandom)}, docValues:{_version_=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=1446, maxMBSortInHeap=5.674381428577987, sim=RandomSimilarity(queryNorm=true): {}, locale=es-HN, timezone=America/Argentina/Jujuy
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=134948296,total=234622976
   [junit4]   2> NOTE: All tests run in this JVM: [TestSolrCloudWithKerberosAlt, OpenExchangeRatesOrgProviderTest, TestRecoveryHdfs, TestLuceneMatchVersion, MBeansHandlerTest, LukeRequestHandlerTest, StressHdfsTest, TestBulkSchemaConcurrent, AnalyticsQueryTest, AutoCommitTest, TestNamedUpdateProcessors, ShowFileRequestHandlerTest, TestQueryTypes, TestSolrConfigHandlerConcurrent, TestElisionMultitermQuery, TestDistribDocBasedVersion, DistribCursorPagingTest, TestSolrCoreParser, LoggingHandlerTest, ExternalFileFieldSortTest, TestAuthenticationFramework, SolrIndexConfigTest, TestValueSourceCache, DistributedFacetExistsSmallTest, BasicFunctionalityTest, TestPullReplica, GraphQueryTest, BasicDistributedZk2Test, PolyFieldTest, TestBadConfig, CurrencyFieldTypeTest, PingRequestHandlerTest, UpdateParamsTest, TestEmbeddedSolrServerConstructors, OverseerCollectionConfigSetProcessorTest, TestSystemIdResolver, TestRebalanceLeaders, InfoHandlerTest, TestConfigReload, AutoScalingHandlerTest, DistributedDebugComponentTest, WrapperMergePolicyFactoryTest, TestSimpleTextCodec, TestCoreDiscovery, TestCSVLoader, BadIndexSchemaTest, TestSchemalessBufferedUpdates, TestHashQParserPlugin, SpellingQueryConverterTest, TestStandardQParsers, DistributedMLTComponentTest, CoreAdminRequestStatusTest, TestManagedStopFilterFactory, SolrCoreCheckLockOnStartupTest, TestRangeQuery, DistributedFacetPivotSmallTest, TestSolrDeletionPolicy1, HdfsDirectoryFactoryTest, TestTrie, TestSmileRequest, AddBlockUpdateTest, TestSSLRandomization, BufferStoreTest, DocValuesMissingTest, CleanupOldIndexTest, TestConfigsApi, TestRequestForwarding, TestLMJelinekMercerSimilarityFactory, TestCollectionsAPIViaSolrCloudCluster, TestMissingGroups, SynonymTokenizerTest, TestPayloadCheckQParserPlugin, TestNonDefinedSimilarityFactory, ResponseHeaderTest, SignatureUpdateProcessorFactoryTest, BigEndianAscendingWordSerializerTest, TestCloudInspectUtil, TestRemoteStreaming, SSLMigrationTest, BlockJoinFacetRandomTest, TestNestedDocsSort, TestCrossCoreJoin, ExplicitHLLTest, BadComponentTest, TestDistributedGrouping, SimpleCollectionCreateDeleteTest, ExecutePlanActionTest, ManagedSchemaRoundRobinCloudTest, TestFieldCacheVsDocValues, ReplaceNodeTest, DistributedTermsComponentTest, TestExportWriter, TestRTGBase, TestCollationField, ForceLeaderTest, SearchHandlerTest, TestConfigSetImmutable, TestHttpShardHandlerFactory, TermVectorComponentTest, FieldMutatingUpdateProcessorTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed [130/744 (1!)] on J1 in 85.76s, 19 tests, 1 error <<< FAILURES!

[...truncated 49034 lines...]