You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/01/05 08:29:22 UTC

[JENKINS] Lucene-Solr-Tests-master - Build # 1590 - Unstable

Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/1590/

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

Error Message:
expected:<3> but was:<2>

Stack Trace:
java.lang.AssertionError: expected:<3> but was:<2>
	at __randomizedtesting.SeedInfo.seed([F9519BB8BE7BD0E1:B124EF0CB848FF74]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:517)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11705 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/init-core-data-001
   [junit4]   2> 856529 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 856529 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001
   [junit4]   2> 856530 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 856530 INFO  (Thread-2076) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 856530 INFO  (Thread-2076) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 856630 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:33441
   [junit4]   2> 856637 INFO  (jetty-launcher-1259-thread-1) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 856639 INFO  (jetty-launcher-1259-thread-4) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 856639 INFO  (jetty-launcher-1259-thread-2) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 856641 INFO  (jetty-launcher-1259-thread-3) [    ] o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 856648 INFO  (jetty-launcher-1259-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@78f87cab{/solr,null,AVAILABLE}
   [junit4]   2> 856650 INFO  (jetty-launcher-1259-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@6f449b4a{SSL,[ssl, http/1.1]}{127.0.0.1:35082}
   [junit4]   2> 856650 INFO  (jetty-launcher-1259-thread-2) [    ] o.e.j.s.Server Started @860155ms
   [junit4]   2> 856650 INFO  (jetty-launcher-1259-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35082}
   [junit4]   2> 856653 ERROR (jetty-launcher-1259-thread-2) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 856653 INFO  (jetty-launcher-1259-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6543eb4a{/solr,null,AVAILABLE}
   [junit4]   2> 856653 INFO  (jetty-launcher-1259-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.0.0
   [junit4]   2> 856664 INFO  (jetty-launcher-1259-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 856664 INFO  (jetty-launcher-1259-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 856664 INFO  (jetty-launcher-1259-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-01-05T07:54:37.518Z
   [junit4]   2> 856665 INFO  (jetty-launcher-1259-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@1ba7b822{SSL,[ssl, http/1.1]}{127.0.0.1:34416}
   [junit4]   2> 856665 INFO  (jetty-launcher-1259-thread-1) [    ] o.e.j.s.Server Started @860170ms
   [junit4]   2> 856665 INFO  (jetty-launcher-1259-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34416}
   [junit4]   2> 856665 ERROR (jetty-launcher-1259-thread-1) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 856665 INFO  (jetty-launcher-1259-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.0.0
   [junit4]   2> 856665 INFO  (jetty-launcher-1259-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 856665 INFO  (jetty-launcher-1259-thread-4) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@46669db{/solr,null,AVAILABLE}
   [junit4]   2> 856665 INFO  (jetty-launcher-1259-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 856666 INFO  (jetty-launcher-1259-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-01-05T07:54:37.520Z
   [junit4]   2> 856667 INFO  (jetty-launcher-1259-thread-4) [    ] o.e.j.s.AbstractConnector Started ServerConnector@257a276{SSL,[ssl, http/1.1]}{127.0.0.1:39469}
   [junit4]   2> 856667 INFO  (jetty-launcher-1259-thread-4) [    ] o.e.j.s.Server Started @860172ms
   [junit4]   2> 856667 INFO  (jetty-launcher-1259-thread-4) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39469}
   [junit4]   2> 856667 ERROR (jetty-launcher-1259-thread-4) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 856667 INFO  (jetty-launcher-1259-thread-4) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.0.0
   [junit4]   2> 856667 INFO  (jetty-launcher-1259-thread-4) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 856667 INFO  (jetty-launcher-1259-thread-4) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 856667 INFO  (jetty-launcher-1259-thread-4) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-01-05T07:54:37.521Z
   [junit4]   2> 856668 INFO  (jetty-launcher-1259-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 856677 INFO  (jetty-launcher-1259-thread-3) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2d1ec2a4{/solr,null,AVAILABLE}
   [junit4]   2> 856678 INFO  (jetty-launcher-1259-thread-3) [    ] o.e.j.s.AbstractConnector Started ServerConnector@a136fcd{SSL,[ssl, http/1.1]}{127.0.0.1:45102}
   [junit4]   2> 856679 INFO  (jetty-launcher-1259-thread-3) [    ] o.e.j.s.Server Started @860183ms
   [junit4]   2> 856679 INFO  (jetty-launcher-1259-thread-3) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45102}
   [junit4]   2> 856679 ERROR (jetty-launcher-1259-thread-3) [    ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 856679 INFO  (jetty-launcher-1259-thread-3) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.0.0
   [junit4]   2> 856679 INFO  (jetty-launcher-1259-thread-3) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 856679 INFO  (jetty-launcher-1259-thread-3) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 856679 INFO  (jetty-launcher-1259-thread-3) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2017-01-05T07:54:37.533Z
   [junit4]   2> 856685 INFO  (jetty-launcher-1259-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 856688 INFO  (jetty-launcher-1259-thread-4) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 856693 INFO  (jetty-launcher-1259-thread-3) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 856693 INFO  (jetty-launcher-1259-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33441/solr
   [junit4]   2> 856700 INFO  (jetty-launcher-1259-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33441/solr
   [junit4]   2> 856702 INFO  (jetty-launcher-1259-thread-4) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33441/solr
   [junit4]   2> 856704 INFO  (jetty-launcher-1259-thread-3) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33441/solr
   [junit4]   2> 856719 INFO  (jetty-launcher-1259-thread-1) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34416_solr
   [junit4]   2> 856720 INFO  (jetty-launcher-1259-thread-1) [n:127.0.0.1:34416_solr    ] o.a.s.c.Overseer Overseer (id=97229398172237833-127.0.0.1:34416_solr-n_0000000000) starting
   [junit4]   2> 856723 INFO  (jetty-launcher-1259-thread-2) [n:127.0.0.1:35082_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35082_solr
   [junit4]   2> 856724 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 856729 INFO  (zkCallback-1277-thread-1-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 856735 INFO  (jetty-launcher-1259-thread-1) [n:127.0.0.1:34416_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34416_solr
   [junit4]   2> 856736 INFO  (zkCallback-1277-thread-1-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 856736 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 856757 INFO  (jetty-launcher-1259-thread-4) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 856758 INFO  (jetty-launcher-1259-thread-3) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 856759 INFO  (jetty-launcher-1259-thread-4) [n:127.0.0.1:39469_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39469_solr
   [junit4]   2> 856760 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 856761 INFO  (zkCallback-1277-thread-1-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 856764 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 856764 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 856769 INFO  (jetty-launcher-1259-thread-3) [n:127.0.0.1:45102_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45102_solr
   [junit4]   2> 856769 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 856770 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 856775 INFO  (zkCallback-1277-thread-1-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 856775 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 856788 INFO  (jetty-launcher-1259-thread-1) [n:127.0.0.1:34416_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node1/.
   [junit4]   2> 856792 INFO  (jetty-launcher-1259-thread-4) [n:127.0.0.1:39469_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node4/.
   [junit4]   2> 856815 INFO  (jetty-launcher-1259-thread-3) [n:127.0.0.1:45102_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node3/.
   [junit4]   2> 856819 INFO  (jetty-launcher-1259-thread-2) [n:127.0.0.1:35082_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node2/.
   [junit4]   2> 858187 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 858188 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33441/solr ready
   [junit4]   2> 858215 INFO  (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testDeleteNonExistentCollection
   [junit4]   2> 858215 INFO  (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 858258 INFO  (qtp431812296-8399) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=unknown_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 858260 INFO  (OverseerThreadFactory-4365-thread-1-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 858263 ERROR (OverseerThreadFactory-4365-thread-1-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerCollectionMessageHandler Collection: unknown_collection operation: delete failed:org.apache.solr.common.SolrException: Could not find collection : unknown_collection
   [junit4]   2> 	at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:194)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:843)
   [junit4]   2> 	at org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:81)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 858268 INFO  (qtp431812296-8399) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=unknown_collection&action=DELETE&wt=javabin&version=2} status=400 QTime=10
   [junit4]   2> 858269 INFO  (qtp431812296-8395) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 858271 INFO  (OverseerCollectionConfigSetProcessor-97229398172237833-127.0.0.1:34416_solr-n_0000000000) [n:127.0.0.1:34416_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> 858271 INFO  (OverseerThreadFactory-4365-thread-2-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.CreateCollectionCmd Create collection acollectionafterbaddelete
   [junit4]   2> 858427 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2
   [junit4]   2> 858427 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2
   [junit4]   2> 858534 INFO  (zkCallback-1277-thread-3-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 858534 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859433 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859444 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 859447 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica2] Schema name=minimal
   [junit4]   2> 859449 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica1] Schema name=minimal
   [junit4]   2> 859450 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859451 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica2' using configuration from collection acollectionafterbaddelete
   [junit4]   2> 859451 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node1/acollectionafterbaddelete_shard1_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node1/./acollectionafterbaddelete_shard1_replica2/data/]
   [junit4]   2> 859451 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 859451 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica1' using configuration from collection acollectionafterbaddelete
   [junit4]   2> 859452 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node2/acollectionafterbaddelete_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node2/./acollectionafterbaddelete_shard1_replica1/data/]
   [junit4]   2> 859464 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 859464 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 859465 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859465 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859465 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@48143258[acollectionafterbaddelete_shard1_replica2] main]
   [junit4]   2> 859466 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 859466 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 859467 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 859467 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 859467 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2372275d[acollectionafterbaddelete_shard1_replica1] main]
   [junit4]   2> 859468 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 859468 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 859468 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859468 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 859468 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859468 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 859468 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1555670373836521472
   [junit4]   2> 859468 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1555670373836521472
   [junit4]   2> 859470 INFO  (searcherExecutor-4375-thread-1-processing-n:127.0.0.1:35082_solr x:acollectionafterbaddelete_shard1_replica1 s:shard1 c:acollectionafterbaddelete) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] Registered new searcher Searcher@2372275d[acollectionafterbaddelete_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859471 INFO  (searcherExecutor-4374-thread-1-processing-n:127.0.0.1:34416_solr x:acollectionafterbaddelete_shard1_replica2 s:shard1 c:acollectionafterbaddelete) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] Registered new searcher Searcher@48143258[acollectionafterbaddelete_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859473 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 859473 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 859474 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34416/solr/acollectionafterbaddelete_shard1_replica2/
   [junit4]   2> 859474 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica2 url=https://127.0.0.1:34416/solr START replicas=[https://127.0.0.1:35082/solr/acollectionafterbaddelete_shard1_replica1/] nUpdates=100
   [junit4]   2> 859474 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica2 url=https://127.0.0.1:34416/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 859477 INFO  (qtp730303071-8377) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.S.Request [acollectionafterbaddelete_shard1_replica1]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 859477 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 859477 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 859479 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34416/solr/acollectionafterbaddelete_shard1_replica2/ shard1
   [junit4]   2> 859582 INFO  (zkCallback-1277-thread-4-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859582 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859630 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 859632 INFO  (qtp2135676427-8371) [n:127.0.0.1:34416_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=1206
   [junit4]   2> 859733 INFO  (zkCallback-1277-thread-3-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 859733 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860475 INFO  (qtp730303071-8379) [n:127.0.0.1:35082_solr c:acollectionafterbaddelete s:shard1  x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=2047
   [junit4]   2> 860480 INFO  (qtp431812296-8395) [n:127.0.0.1:45102_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> 860583 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 860584 INFO  (zkCallback-1277-thread-3-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 861481 INFO  (qtp431812296-8395) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=3212
   [junit4]   2> 861483 INFO  (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testDeleteNonExistentCollection
   [junit4]   2> 861511 INFO  (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
   [junit4]   2> 861512 INFO  (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 861514 INFO  (qtp431812296-8373) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 861516 INFO  (OverseerThreadFactory-4365-thread-3-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 861517 INFO  (qtp2135676427-8372) [n:127.0.0.1:34416_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.acollectionafterbaddelete_shard1_replica2
   [junit4]   2> 861517 INFO  (qtp730303071-8381) [n:127.0.0.1:35082_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.acollectionafterbaddelete_shard1_replica1
   [junit4]   2> 861517 INFO  (qtp2135676427-8372) [n:127.0.0.1:34416_solr    ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2]  CLOSING SolrCore org.apache.solr.core.SolrCore@6df54c3b
   [junit4]   2> 861517 INFO  (qtp730303071-8381) [n:127.0.0.1:35082_solr    ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@4bf32767
   [junit4]   2> 861517 INFO  (qtp2135676427-8372) [n:127.0.0.1:34416_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.acollectionafterbaddelete.shard1.replica2
   [junit4]   2> 861517 INFO  (qtp730303071-8381) [n:127.0.0.1:35082_solr    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.acollectionafterbaddelete.shard1.replica1
   [junit4]   2> 861518 INFO  (OverseerCollectionConfigSetProcessor-97229398172237833-127.0.0.1:34416_solr-n_0000000000) [n:127.0.0.1:34416_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> 861518 INFO  (qtp730303071-8381) [n:127.0.0.1:35082_solr    ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader parent node, won't remove previous leader registration.
   [junit4]   2> 861519 INFO  (qtp730303071-8381) [n:127.0.0.1:35082_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=2
   [junit4]   2> 861519 WARN  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.LeaderElector Our node is no longer in line to be leader
   [junit4]   2> 861521 INFO  (qtp2135676427-8372) [n:127.0.0.1:34416_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=4
   [junit4]   2> 862224 INFO  (qtp431812296-8373) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2} status=0 QTime=710
   [junit4]   2> 862226 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 862236 INFO  (OverseerThreadFactory-4365-thread-4-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.CreateCollectionCmd Create collection collection
   [junit4]   2> 862236 INFO  (OverseerCollectionConfigSetProcessor-97229398172237833-127.0.0.1:34416_solr-n_0000000000) [n:127.0.0.1:34416_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> 862237 WARN  (OverseerThreadFactory-4365-thread-4-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.CreateCollectionCmd Specified replicationFactor of 10 on collection collection is higher than or equal to the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance.
   [junit4]   2> 862237 ERROR (OverseerThreadFactory-4365-thread-4-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2 and value of replicationFactor is 10. This requires 20 shards to be created (higher than the allowed number)
   [junit4]   2> 	at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 862239 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=13
   [junit4]   2> 862239 INFO  (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
   [junit4]   2> 862264 INFO  (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testZeroNumShards
   [junit4]   2> 862265 INFO  (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 862266 INFO  (qtp431812296-8396) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 862268 INFO  (OverseerCollectionConfigSetProcessor-97229398172237833-127.0.0.1:34416_solr-n_0000000000) [n:127.0.0.1:34416_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> 862268 INFO  (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.CreateCollectionCmd Create collection acollection
   [junit4]   2> 862268 ERROR (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards must be > 0
   [junit4]   2> 	at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:124)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 862270 INFO  (qtp431812296-8396) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2} status=400 QTime=3
   [junit4]   2> 862270 INFO  (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testZeroNumShards
   [junit4]   2> 862271 INFO  (OverseerCollectionConfigSetProcessor-97229398172237833-127.0.0.1:34416_solr-n_0000000000) [n:127.0.0.1:34416_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> 862294 INFO  (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard
   [junit4]   2> 862294 INFO  (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 862296 INFO  (qtp431812296-8397) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=oversharded&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 862298 INFO  (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.CreateCollectionCmd Create collection oversharded
   [junit4]   2> 862298 ERROR (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_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 and value of replicationFactor is 2. This requires 6 shards to be created (higher than the allowed number)
   [junit4]   2> 	at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 862299 INFO  (qtp431812296-8397) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=oversharded&action=CREATE&numShards=3&wt=javabin&version=2} status=400 QTime=2
   [junit4]   2> 862300 ERROR (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerTaskProcessor :org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /overseer/collection-queue-work/qnr-0000000010
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.setData(ZooKeeper.java:1270)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:373)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:370)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.setData(SolrZkClient.java:370)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.setData(SolrZkClient.java:571)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskQueue.remove(OverseerTaskQueue.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.markTaskComplete(OverseerTaskProcessor.java:525)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:483)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 862300 WARN  (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerTaskProcessor Resetting task: /overseer/collection-queue-work/qn-0000000010, requestid: null, taskKey: oversharded
   [junit4]   2> 862300 INFO  (TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testMaxNodesPerShard
   [junit4]   2> 862319 INFO  (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
   [junit4]   2> 862320 INFO  (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 862321 INFO  (qtp431812296-8399) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 862322 INFO  (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.CreateCollectionCmd Create collection acollection
   [junit4]   2> 862322 ERROR (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards is a required param (when using CompositeId router).
   [junit4]   2> 	at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:112)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 862324 INFO  (qtp431812296-8399) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2} status=400 QTime=3
   [junit4]   2> 862325 INFO  (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
   [junit4]   2> 862346 INFO  (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
   [junit4]   2> 862346 INFO  (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[F9519BB8BE7BD0E1]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 862347 INFO  (qtp431812296-8395) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 862349 INFO  (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.CreateCollectionCmd Create collection addReplicaColl
   [junit4]   2> 862560 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 862562 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
   [junit4]   2> 862565 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
   [junit4]   2> 862591 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 862695 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 862695 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 862695 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 862695 INFO  (zkCallback-1277-thread-3-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 863577 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 863578 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 863582 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 863583 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica1] Schema name=minimal
   [junit4]   2> 863585 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 863586 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica1' using configuration from collection addReplicaColl
   [junit4]   2> 863586 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica2] Schema name=minimal
   [junit4]   2> 863586 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node2/addReplicaColl_shard1_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node2/./addReplicaColl_shard1_replica1/data/]
   [junit4]   2> 863588 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 863589 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica2' using configuration from collection addReplicaColl
   [junit4]   2> 863589 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node1/addReplicaColl_shard2_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node1/./addReplicaColl_shard2_replica2/data/]
   [junit4]   2> 863597 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 863597 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 863598 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 863598 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 863598 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@538dd5c9[addReplicaColl_shard1_replica1] main]
   [junit4]   2> 863622 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 863622 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica1] Schema name=minimal
   [junit4]   2> 863624 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 863624 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 863625 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 863625 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 863626 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 863626 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 863626 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 863626 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 863626 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1555670378196500480
   [junit4]   2> 863626 INFO  (searcherExecutor-4384-thread-1-processing-n:127.0.0.1:35082_solr x:addReplicaColl_shard1_replica1 s:shard1 c:addReplicaColl) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore [addReplicaColl_shard1_replica1] Registered new searcher Searcher@538dd5c9[addReplicaColl_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 863628 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica2] Schema name=minimal
   [junit4]   2> 863628 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica1' using configuration from collection addReplicaColl
   [junit4]   2> 863629 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node3/addReplicaColl_shard2_replica1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node3/./addReplicaColl_shard2_replica1/data/]
   [junit4]   2> 863630 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 863630 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@30626aa3[addReplicaColl_shard2_replica2] main]
   [junit4]   2> 863631 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 863631 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica2' using configuration from collection addReplicaColl
   [junit4]   2> 863631 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node4/addReplicaColl_shard1_replica2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001/tempDir-001/node4/./addReplicaColl_shard1_replica2/data/]
   [junit4]   2> 863633 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 863633 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 863633 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 863633 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1555670378203840512
   [junit4]   2> 863637 INFO  (searcherExecutor-4385-thread-1-processing-n:127.0.0.1:34416_solr x:addReplicaColl_shard2_replica2 s:shard2 c:addReplicaColl) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore [addReplicaColl_shard2_replica2] Registered new searcher Searcher@30626aa3[addReplicaColl_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 863637 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 863637 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 863638 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 863638 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 863639 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@61dc6f9d[addReplicaColl_shard2_replica1] main]
   [junit4]   2> 863639 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 863639 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 863639 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 863639 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 863640 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1555670378211180544
   [junit4]   2> 863641 INFO  (searcherExecutor-4394-thread-1-processing-n:127.0.0.1:45102_solr x:addReplicaColl_shard2_replica1 s:shard2 c:addReplicaColl) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.c.SolrCore [addReplicaColl_shard2_replica1] Registered new searcher Searcher@61dc6f9d[addReplicaColl_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 863643 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 863644 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 863644 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 863644 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 863645 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@2c7aed3b[addReplicaColl_shard1_replica2] main]
   [junit4]   2> 863645 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 863645 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 863646 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 863646 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1555670378217472000
   [junit4]   2> 863649 INFO  (searcherExecutor-4395-thread-1-processing-n:127.0.0.1:39469_solr x:addReplicaColl_shard1_replica2 s:shard1 c:addReplicaColl) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore [addReplicaColl_shard1_replica2] Registered new searcher Searcher@2c7aed3b[addReplicaColl_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 863740 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 863740 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 863740 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 863740 INFO  (zkCallback-1277-thread-4-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864132 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 864132 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 864132 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:35082/solr/addReplicaColl_shard1_replica1/
   [junit4]   2> 864132 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard1_replica1 url=https://127.0.0.1:35082/solr START replicas=[https://127.0.0.1:39469/solr/addReplicaColl_shard1_replica2/] nUpdates=100
   [junit4]   2> 864132 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard1_replica1 url=https://127.0.0.1:35082/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 864137 INFO  (qtp1069374500-8390) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1 r:core_node4 x:addReplicaColl_shard1_replica2] o.a.s.c.S.Request [addReplicaColl_shard1_replica2]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 864138 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 864138 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 864139 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 864139 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 864139 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34416/solr/addReplicaColl_shard2_replica2/
   [junit4]   2> 864139 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard2_replica2 url=https://127.0.0.1:34416/solr START replicas=[https://127.0.0.1:45102/solr/addReplicaColl_shard2_replica1/] nUpdates=100
   [junit4]   2> 864140 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.u.PeerSync PeerSync: core=addReplicaColl_shard2_replica2 url=https://127.0.0.1:34416/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 864141 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:35082/solr/addReplicaColl_shard1_replica1/ shard1
   [junit4]   2> 864142 INFO  (qtp431812296-8392) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica1] o.a.s.c.S.Request [addReplicaColl_shard2_replica1]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 864142 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 864142 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 864143 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34416/solr/addReplicaColl_shard2_replica2/ shard2
   [junit4]   2> 864249 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864249 INFO  (zkCallback-1277-thread-4-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864249 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864249 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864292 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 864294 INFO  (qtp730303071-8380) [n:127.0.0.1:35082_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2} status=0 QTime=1733
   [junit4]   2> 864294 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 864295 INFO  (qtp2135676427-8363) [n:127.0.0.1:34416_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2} status=0 QTime=1733
   [junit4]   2> 864396 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864396 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864396 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864397 INFO  (zkCallback-1277-thread-3-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864647 INFO  (qtp431812296-8394) [n:127.0.0.1:45102_solr c:addReplicaColl s:shard2  x:addReplicaColl_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2} status=0 QTime=2081
   [junit4]   2> 864652 INFO  (qtp1069374500-8388) [n:127.0.0.1:39469_solr c:addReplicaColl s:shard1  x:addReplicaColl_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2} status=0 QTime=2060
   [junit4]   2> 864654 INFO  (qtp431812296-8395) [n:127.0.0.1:45102_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> 864754 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864754 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864754 INFO  (zkCallback-1277-thread-3-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 864754 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 865654 INFO  (qtp431812296-8395) [n:127.0.0.1:45102_solr    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3306
   [junit4]   2> 865656 INFO  (qtp431812296-8373) [n:127.0.0.1:45102_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:34416_solr&action=ADDREPLICA&collection=addReplicaColl&shard=shard1&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 865657 INFO  (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.AddReplicaCmd addReplica() : {
   [junit4]   2>   "collection":"addReplicaColl",
   [junit4]   2>   "node":"127.0.0.1:34416_solr",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "operation":"addreplica"}
   [junit4]   2> 865658 INFO  (OverseerThreadFactory-4365-thread-5-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:34416_solr for creating new replica
   [junit4]   2> 865658 INFO  (OverseerCollectionConfigSetProcessor-97229398172237833-127.0.0.1:34416_solr-n_0000000000) [n:127.0.0.1:34416_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> 865658 INFO  (qtp2135676427-8367) [n:127.0.0.1:34416_solr    ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&name=addReplicaColl_shard1_replica3&action=CREATE&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
   [junit4]   2> 865761 INFO  (zkCallback-1280-thread-1-processing-n:127.0.0.1:45102_solr) [n:127.0.0.1:45102_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 865761 INFO  (zkCallback-1279-thread-1-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 865761 INFO  (zkCallback-1278-thread-1-processing-n:127.0.0.1:35082_solr) [n:127.0.0.1:35082_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
   [junit4]   2> 865761 INFO  (zkCallback-1277-thread-1-processing-n:127.0.0.1:34416_solr) [n:127.0.0.1:34416_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeData

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

83802 INFO  (coreCloseExecutor-4641-thread-1) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard2 r:core_node20 x:awhollynewcollection_0_shard2_replica3] o.a.s.c.SolrCore [awhollynewcollection_0_shard2_replica3]  CLOSING SolrCore org.apache.solr.core.SolrCore@459ac46
   [junit4]   2> 983802 INFO  (coreCloseExecutor-4641-thread-2) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard1 r:core_node15 x:awhollynewcollection_0_shard1_replica3] o.a.s.c.SolrCore [awhollynewcollection_0_shard1_replica3]  CLOSING SolrCore org.apache.solr.core.SolrCore@7bb525c4
   [junit4]   2> 983802 INFO  (coreCloseExecutor-4641-thread-4) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard3 r:core_node18 x:awhollynewcollection_0_shard3_replica3] o.a.s.c.SolrCore [awhollynewcollection_0_shard3_replica3]  CLOSING SolrCore org.apache.solr.core.SolrCore@22456fef
   [junit4]   2> 983803 INFO  (coreCloseExecutor-4641-thread-3) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard4 r:core_node17 x:awhollynewcollection_0_shard4_replica3] o.a.s.c.SolrCore [awhollynewcollection_0_shard4_replica3]  CLOSING SolrCore org.apache.solr.core.SolrCore@a4a99af
   [junit4]   2> 983803 INFO  (coreCloseExecutor-4641-thread-5) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard5 r:core_node5 x:awhollynewcollection_0_shard5_replica3] o.a.s.c.SolrCore [awhollynewcollection_0_shard5_replica3]  CLOSING SolrCore org.apache.solr.core.SolrCore@3123ed7e
   [junit4]   2> 983807 INFO  (coreCloseExecutor-4641-thread-1) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard2 r:core_node20 x:awhollynewcollection_0_shard2_replica3] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard2.replica3
   [junit4]   2> 983825 INFO  (coreCloseExecutor-4641-thread-5) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard5 r:core_node5 x:awhollynewcollection_0_shard5_replica3] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard5.replica3
   [junit4]   2> 983826 INFO  (coreCloseExecutor-4641-thread-2) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard1 r:core_node15 x:awhollynewcollection_0_shard1_replica3] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard1.replica3
   [junit4]   2> 983827 INFO  (coreCloseExecutor-4641-thread-4) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard3 r:core_node18 x:awhollynewcollection_0_shard3_replica3] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard3.replica3
   [junit4]   2> 983827 INFO  (zkCallback-1279-thread-4-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 983829 INFO  (coreCloseExecutor-4641-thread-3) [n:127.0.0.1:39469_solr c:awhollynewcollection_0 s:shard4 r:core_node17 x:awhollynewcollection_0_shard4_replica3] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.awhollynewcollection_0.shard4.replica3
   [junit4]   2> 983830 INFO  (jetty-launcher-1259-thread-8) [    ] o.a.s.c.Overseer Overseer (id=97229398172237835-127.0.0.1:39469_solr-n_0000000002) closing
   [junit4]   2> 983831 WARN  (zkCallback-1279-thread-4-processing-n:127.0.0.1:39469_solr) [n:127.0.0.1:39469_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 983831 INFO  (jetty-launcher-1259-thread-8) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 983831 INFO  (jetty-launcher-1259-thread-8) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@46669db{/solr,null,UNAVAILABLE}
   [junit4]   2> 983832 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33441 33441
   [junit4]   2> 983833 INFO  (OverseerStateUpdate-97229398172237835-127.0.0.1:39469_solr-n_0000000002) [n:127.0.0.1:39469_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:39469_solr
   [junit4]   2> 984001 INFO  (Thread-2076) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33441 33441
   [junit4]   2> 984001 WARN  (Thread-2076) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	25	/solr/aliases.json
   [junit4]   2> 	23	/solr/configs/conf
   [junit4]   2> 	5	/solr/configs/conf2
   [junit4]   2> 	4	/solr/security.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	343	/solr/clusterstate.json
   [junit4]   2> 	25	/solr/clusterprops.json
   [junit4]   2> 	6	/solr/collections/awhollynewcollection_0/state.json
   [junit4]   2> 	4	/solr/collections/nodes_used_collection/state.json
   [junit4]   2> 	4	/solr/collections/addReplicaColl/state.json
   [junit4]   2> 	4	/solr/collections/reloaded_collection/state.json
   [junit4]   2> 	3	/solr/collections/acollectionafterbaddelete/state.json
   [junit4]   2> 	2	/solr/collections/onlyinzk/state.json
   [junit4]   2> 	2	/solr/collections/awhollynewcollection_0/leader_elect/shard5/election/97229398172237835-core_node5-n_0000000001
   [junit4]   2> 	2	/solr/collections/addReplicaColl/leader_elect/shard1/election/97229398172237834-core_node1-n_0000000000
   [junit4]   2> 	2	/solr/collections/awhollynewcollection_0/leader_elect/shard2/election/97229398172237835-core_node20-n_0000000000
   [junit4]   2> 	2	/solr/collections/halfdeletedcollection/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	486	/solr/collections
   [junit4]   2> 	148	/solr/overseer/queue
   [junit4]   2> 	68	/solr/overseer/collection-queue-work
   [junit4]   2> 	25	/solr/live_nodes
   [junit4]   2> 	22	/solr/overseer/queue-work
   [junit4]   2> 
   [junit4]   2> 984001 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[F9519BB8BE7BD0E1]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_F9519BB8BE7BD0E1-001
   [junit4]   2> Jan 05, 2017 7:56:44 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): {_version_=PostingsFormat(name=LuceneFixedGap), id=Lucene50(blocksize=128)}, docValues:{}, maxPointsInLeafNode=1791, maxMBSortInHeap=7.00875336578684, sim=RandomSimilarity(queryNorm=false): {}, locale=fr-FR, timezone=NZ
   [junit4]   2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=4,threads=1,free=108181056,total=507510784
   [junit4]   2> NOTE: All tests run in this JVM: [TestConfigSetProperties, AddSchemaFieldsUpdateProcessorFactoryTest, TestFileDictionaryLookup, AliasIntegrationTest, CollectionReloadTest, CSVRequestHandlerTest, AlternateDirectoryTest, BlockJoinFacetRandomTest, DeleteNodeTest, CustomCollectionTest, ClassificationUpdateProcessorIntegrationTest, SchemaVersionSpecificBehaviorTest, IndexSchemaRuntimeFieldTest, TestPartialUpdateDeduplication, TestReloadDeadlock, TestFieldSortValues, MoreLikeThisHandlerTest, TermsComponentTest, TermVectorComponentTest, BasicAuthIntegrationTest, SolrMetricReporterTest, DocumentBuilderTest, SpellCheckComponentTest, LeaderElectionContextKeyTest, ClusterStateUpdateTest, TestSmileRequest, TestRequestForwarding, TestDistributedGrouping, SolrInfoMBeanTest, TestPerFieldSimilarity, TestHashPartitioner, TestBackupRepositoryFactory, TestManagedSchema, ChaosMonkeyNothingIsSafeTest, CloudMLTQParserTest, LoggingHandlerTest, TestMaxScoreQueryParser, DocExpirationUpdateProcessorFactoryTest, TestSchemaManager, DistributedFacetPivotLongTailTest, TestAddFieldRealTimeGet, TestQueryUtils, SpatialFilterTest, HdfsDirectoryTest, EnumFieldTest, DistributedIntervalFacetingTest, SparseHLLTest, QueryParsingTest, WordBreakSolrSpellCheckerTest, ShardRoutingCustomTest, ChangedSchemaMergeTest, RecoveryAfterSoftCommitTest, TestConfigSetsAPIExclusivity, CoreAdminCreateDiscoverTest, HdfsRestartWhileUpdatingTest, TestSurroundQueryParser, TestFastLRUCache, TestDeleteCollectionOnDownNodes, MultiThreadedOCPTest, BasicFunctionalityTest, SuggestComponentTest, ChaosMonkeySafeLeaderTest, TestSortByMinMaxFunction, TestExceedMaxTermLength, TestSolrCloudWithHadoopAuthPlugin, ZkCLITest, IndexBasedSpellCheckerTest, TestRandomRequestDistribution, TestMacros, WrapperMergePolicyFactoryTest, DocValuesTest, TestManagedResourceStorage, DocValuesNotIndexedTest, SpellCheckCollatorTest, SampleTest, InfoHandlerTest, TestClusterProperties, DistanceFunctionTest, TestExactSharedStatsCache, TestSubQueryTransformerCrossCore, AnalysisErrorHandlingTest, TestStressRecovery, TestAuthenticationFramework, TestStandardQParsers, SSLMigrationTest, SpatialRPTFieldTypeTest, TestSchemaVersionResource, TestAuthorizationFramework, DistributedExpandComponentTest, ConvertedLegacyTest, ExitableDirectoryReaderTest, TestBM25SimilarityFactory, TestDynamicFieldCollectionResource, ConfigSetsAPITest, IndexSchemaTest, HighlighterMaxOffsetTest, TestSimpleTrackingShardHandler, AnalyticsMergeStrategyTest, TestHashQParserPlugin, DistributedFacetPivotWhiteBoxTest, TestScoreJoinQPNoScore, ShardRoutingTest, TestExclusionRuleCollectionAccess, DeleteStatusTest, TestBinaryResponseWriter, BasicDistributedZkTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
   [junit4] Completed [324/675 (1!)] on J1 in 127.74s, 20 tests, 1 failure <<< FAILURES!

[...truncated 63543 lines...]