Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Linux/403/
Java: 32bit/jdk1.8.0_144 -server -XX:+UseParallelGC

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

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

Stack Trace:
org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from 
server at http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1: 
ClusterState says we are the leader 
(http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1), but 
locally we don't think so. Request came from null
        at 
__randomizedtesting.SeedInfo.seed([22F645446B8A6553:6A8331F06DB94AC6]:0)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:539)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:993)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
        at 
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
        at 
org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233)
        at 
org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:458)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.lang.Thread.run(Thread.java:748)
Caused by: 
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at 
http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1: 
ClusterState says we are the leader 
(http://127.0.0.1:41577/solr/awhollynewcollection_0_shard4_replica_n1), but 
locally we don't think so. Request came from null
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:627)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:516)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        ... 1 more




Build Log:
[...truncated 11969 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/init-core-data-001
   [junit4]   2> 1294243 WARN  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=9 numCloses=9
   [junit4]   2> 1294243 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 1294244 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1294245 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in 
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001
   [junit4]   2> 1294245 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1294245 INFO  (Thread-3876) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1294245 INFO  (Thread-3876) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1294246 ERROR (Thread-3876) [    ] o.a.z.s.ZooKeeperServer 
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action 
on ERROR or SHUTDOWN server state changes
   [junit4]   2> 1294345 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:46533
   [junit4]   2> 1294349 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1294349 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1294349 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1294349 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1294350 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@16d6b20{/solr,null,AVAILABLE}
   [junit4]   2> 1294350 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@5710ad{/solr,null,AVAILABLE}
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@1b952e3{HTTP/1.1,[http/1.1]}{127.0.0.1:41577}
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@1803eec{/solr,null,AVAILABLE}
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.e.j.s.Server Started @1295980ms
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=41577}
   [junit4]   2> 1294351 ERROR (jetty-launcher-1432-thread-4) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.1
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1294351 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-10-01T19:48:45.936Z
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@1adf4bc{/solr,null,AVAILABLE}
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@c82d0{HTTP/1.1,[http/1.1]}{127.0.0.1:43357}
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.e.j.s.Server Started @1295981ms
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=43357}
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@13e79c5{HTTP/1.1,[http/1.1]}{127.0.0.1:40241}
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.e.j.s.Server Started @1295981ms
   [junit4]   2> 1294352 ERROR (jetty-launcher-1432-thread-3) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=40241}
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.1
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1294352 ERROR (jetty-launcher-1432-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.1
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-10-01T19:48:45.937Z
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1294352 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-10-01T19:48:45.937Z
   [junit4]   2> 1294353 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@590308{HTTP/1.1,[http/1.1]}{127.0.0.1:42951}
   [junit4]   2> 1294353 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.e.j.s.Server Started @1295982ms
   [junit4]   2> 1294353 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=42951}
   [junit4]   2> 1294354 ERROR (jetty-launcher-1432-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1294354 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1294354 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.1
   [junit4]   2> 1294354 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1294354 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1294354 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-10-01T19:48:45.939Z
   [junit4]   2> 1294358 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1294358 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1294359 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1294365 INFO  (jetty-launcher-1432-thread-4) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
   [junit4]   2> 1294369 INFO  (jetty-launcher-1432-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
   [junit4]   2> 1294369 INFO  (jetty-launcher-1432-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
   [junit4]   2> 1294369 INFO  (jetty-launcher-1432-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46533/solr
   [junit4]   2> 1294371 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x15ed97bd8860005, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 1294383 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1294383 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:43357_solr
   [junit4]   2> 1294384 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.Overseer Overseer 
(id=98755367785594891-127.0.0.1:43357_solr-n_0000000000) starting
   [junit4]   2> 1294387 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:43357_solr
   [junit4]   2> 1294387 INFO  
(zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1294411 INFO  (jetty-launcher-1432-thread-4) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1294411 INFO  (jetty-launcher-1432-thread-1) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1294412 INFO  (jetty-launcher-1432-thread-2) 
[n:127.0.0.1:40241_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1294412 INFO  (jetty-launcher-1432-thread-4) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1294412 INFO  (jetty-launcher-1432-thread-1) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1294412 INFO  (jetty-launcher-1432-thread-2) 
[n:127.0.0.1:40241_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1294414 INFO  (jetty-launcher-1432-thread-4) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:41577_solr
   [junit4]   2> 1294417 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1294421 INFO  
(zkCallback-1452-thread-1-processing-n:127.0.0.1:40241_solr) 
[n:127.0.0.1:40241_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1294421 INFO  
(zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1294422 INFO  (jetty-launcher-1432-thread-1) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:42951_solr
   [junit4]   2> 1294422 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1294422 INFO  (jetty-launcher-1432-thread-2) 
[n:127.0.0.1:40241_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:40241_solr
   [junit4]   2> 1294422 INFO  
(zkCallback-1452-thread-1-processing-n:127.0.0.1:40241_solr) 
[n:127.0.0.1:40241_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (4)
   [junit4]   2> 1294422 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (4)
   [junit4]   2> 1294423 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (4)
   [junit4]   2> 1294423 INFO  
(zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (4)
   [junit4]   2> 1294475 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294481 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294481 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294481 INFO  (jetty-launcher-1432-thread-3) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node3
   [junit4]   2> 1294487 INFO  (jetty-launcher-1432-thread-2) 
[n:127.0.0.1:40241_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294495 INFO  (jetty-launcher-1432-thread-2) 
[n:127.0.0.1:40241_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294495 INFO  (jetty-launcher-1432-thread-2) 
[n:127.0.0.1:40241_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294496 INFO  (jetty-launcher-1432-thread-2) 
[n:127.0.0.1:40241_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node2
   [junit4]   2> 1294567 INFO  (jetty-launcher-1432-thread-4) 
[n:127.0.0.1:41577_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294571 INFO  (jetty-launcher-1432-thread-1) 
[n:127.0.0.1:42951_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294574 INFO  (jetty-launcher-1432-thread-4) 
[n:127.0.0.1:41577_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294574 INFO  (jetty-launcher-1432-thread-4) 
[n:127.0.0.1:41577_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294574 INFO  (jetty-launcher-1432-thread-4) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4
   [junit4]   2> 1294580 INFO  (jetty-launcher-1432-thread-1) 
[n:127.0.0.1:42951_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294580 INFO  (jetty-launcher-1432-thread-1) 
[n:127.0.0.1:42951_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1294581 INFO  (jetty-launcher-1432-thread-1) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1
   [junit4]   2> 1294632 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 1294632 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46533/solr ready
   [junit4]   2> 1294653 INFO  
(TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testDeleteNonExistentCollection
   [junit4]   2> 1294654 INFO  
(TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[22F645446B8A6553])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 1294655 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_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> 1294656 INFO  
(OverseerThreadFactory-4007-thread-1-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing 
Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 1294657 ERROR 
(OverseerThreadFactory-4007-thread-1-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_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:109)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:795)
   [junit4]   2>        at 
org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:88)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 1294663 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_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=8
   [junit4]   2> 1294664 INFO  (qtp22071740-11746) [n:127.0.0.1:42951_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1294665 INFO  
(OverseerThreadFactory-4007-thread-2-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
acollectionafterbaddelete
   [junit4]   2> 1294665 INFO  
(OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000)
 [n:127.0.0.1:43357_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> 1294768 INFO  
(OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"acollectionafterbaddelete",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"acollectionafterbaddelete_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:42951/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1294768 INFO  
(OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"acollectionafterbaddelete",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"acollectionafterbaddelete_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:41577/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1294970 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1294970 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1294970 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1294970 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1295073 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1295073 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1295073 INFO  
(zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1295073 INFO  
(zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1295985 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene 
MatchVersion: 7.0.1
   [junit4]   2> 1295986 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene 
MatchVersion: 7.0.1
   [junit4]   2> 1295991 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.IndexSchema 
[acollectionafterbaddelete_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 1295991 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.IndexSchema 
[acollectionafterbaddelete_shard1_replica_n2] Schema name=minimal
   [junit4]   2> 1295993 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.IndexSchema Loaded 
schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1295993 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.IndexSchema Loaded 
schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1295993 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.CoreContainer Creating 
SolrCore 'acollectionafterbaddelete_shard1_replica_n1' using configuration from 
collection acollectionafterbaddelete, trusted=true
   [junit4]   2> 1295993 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.CoreContainer Creating 
SolrCore 'acollectionafterbaddelete_shard1_replica_n2' using configuration from 
collection acollectionafterbaddelete, trusted=true
   [junit4]   2> 1295993 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX 
monitoring for 'solr.core.acollectionafterbaddelete.shard1.replica_n1' 
(registry 'solr.core.acollectionafterbaddelete.shard1.replica_n1') enabled at 
server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1295993 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX 
monitoring for 'solr.core.acollectionafterbaddelete.shard1.replica_n2' 
(registry 'solr.core.acollectionafterbaddelete.shard1.replica_n2') enabled at 
server: com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1295993 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1295993 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1295994 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrCore 
[[acollectionafterbaddelete_shard1_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/acollectionafterbaddelete_shard1_replica_n1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/acollectionafterbaddelete_shard1_replica_n1/data/]
   [junit4]   2> 1295994 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrCore 
[[acollectionafterbaddelete_shard1_replica_n2] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/acollectionafterbaddelete_shard1_replica_n2],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/acollectionafterbaddelete_shard1_replica_n2/data/]
   [junit4]   2> 1296031 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.UpdateHandler Using 
UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1296031 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.UpdateLog Initializing 
UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1296032 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.CommitTracker Hard 
AutoCommit: disabled
   [junit4]   2> 1296032 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.CommitTracker Soft 
AutoCommit: disabled
   [junit4]   2> 1296033 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@199b0fe[acollectionafterbaddelete_shard1_replica_n1] main]
   [junit4]   2> 1296033 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage 
Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 1296033 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.r.ManagedResourceStorage 
Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1296034 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.h.ReplicationHandler 
Commits will be reserved for  10000
   [junit4]   2> 1296034 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.UpdateHandler Using 
UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 1296034 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.UpdateLog Initializing 
UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1296034 INFO  
(searcherExecutor-4016-thread-1-processing-n:127.0.0.1:42951_solr 
x:acollectionafterbaddelete_shard1_replica_n1 s:shard1 
c:acollectionafterbaddelete r:core_node1) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SolrCore 
[acollectionafterbaddelete_shard1_replica_n1] Registered new searcher 
Searcher@199b0fe[acollectionafterbaddelete_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1296034 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.UpdateLog Could not find 
max version in index or recent updates, using new clock 1580085886445420544
   [junit4]   2> 1296035 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.CommitTracker Hard 
AutoCommit: disabled
   [junit4]   2> 1296035 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.CommitTracker Soft 
AutoCommit: disabled
   [junit4]   2> 1296037 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.SolrIndexSearcher 
Opening [Searcher@13730b1[acollectionafterbaddelete_shard1_replica_n2] main]
   [junit4]   2> 1296037 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard1: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 1296037 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.r.ManagedResourceStorage 
Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 1296037 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.r.ManagedResourceStorage 
Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1296038 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.h.ReplicationHandler 
Commits will be reserved for  10000
   [junit4]   2> 1296038 INFO  
(searcherExecutor-4017-thread-1-processing-n:127.0.0.1:41577_solr 
x:acollectionafterbaddelete_shard1_replica_n2 s:shard1 
c:acollectionafterbaddelete r:core_node2) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.SolrCore 
[acollectionafterbaddelete_shard1_replica_n2] Registered new searcher 
Searcher@13730b1[acollectionafterbaddelete_shard1_replica_n2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1296038 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.u.UpdateLog Could not find 
max version in index or recent updates, using new clock 1580085886449614848
   [junit4]   2> 1296138 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1296138 INFO  
(zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1296138 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1296138 INFO  
(zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1296537 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1296537 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1296538 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SyncStrategy Sync 
replicas to 
http://127.0.0.1:42951/solr/acollectionafterbaddelete_shard1_replica_n1/
   [junit4]   2> 1296538 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: 
core=acollectionafterbaddelete_shard1_replica_n1 
url=http://127.0.0.1:42951/solr START 
replicas=[http://127.0.0.1:41577/solr/acollectionafterbaddelete_shard1_replica_n2/]
 nUpdates=100
   [junit4]   2> 1296538 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: 
core=acollectionafterbaddelete_shard1_replica_n1 
url=http://127.0.0.1:42951/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 1296539 INFO  (qtp26363452-11725) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.c.S.Request 
[acollectionafterbaddelete_shard1_replica_n2]  webapp=/solr path=/get 
params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1296539 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's 
attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 1296539 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] 
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> 1296539 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 1296540 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:42951/solr/acollectionafterbaddelete_shard1_replica_n1/ shard1
   [junit4]   2> 1296641 INFO  
(zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1296641 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1296641 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1296642 INFO  
(zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1296691 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.c.ZkController I am the 
leader, no recovery necessary
   [junit4]   2> 1296692 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:acollectionafterbaddelete s:shard1 r:core_node1 
x:acollectionafterbaddelete_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] 
webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1722
   [junit4]   2> 1296793 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1296793 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1296793 INFO  
(zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1296793 INFO  
(zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1297042 INFO  (qtp26363452-11735) [n:127.0.0.1:41577_solr 
c:acollectionafterbaddelete s:shard1 r:core_node2 
x:acollectionafterbaddelete_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] 
webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica_n2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=2072
   [junit4]   2> 1297043 INFO  (qtp22071740-11746) [n:127.0.0.1:42951_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> 1297143 INFO  
(zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1297143 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1297143 INFO  
(zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1297143 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1298043 INFO  (qtp22071740-11746) [n:127.0.0.1:42951_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&nrtReplicas=2&action=CREATE&numShards=1&wt=javabin&version=2}
 status=0 QTime=3378
   [junit4]   2> 1298044 INFO  
(TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testDeleteNonExistentCollection
   [junit4]   2> 1298070 INFO  
(TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
   [junit4]   2> 1298070 INFO  
(TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[22F645446B8A6553])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 1298071 INFO  (qtp22071740-11751) [n:127.0.0.1:42951_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> 1298072 INFO  
(OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000)
 [n:127.0.0.1:43357_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> 1298072 INFO  
(OverseerThreadFactory-4007-thread-3-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing 
Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 1298073 INFO  (qtp26363452-11740) [n:127.0.0.1:41577_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.acollectionafterbaddelete.shard1.replica_n2, tag=null
   [junit4]   2> 1298073 INFO  (qtp26363452-11740) [n:127.0.0.1:41577_solr    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@3033c1: rootName = null, 
domain = solr.core.acollectionafterbaddelete.shard1.replica_n2, service url = 
null, agent id = null] for registry 
solr.core.acollectionafterbaddelete.shard1.replica_n2 / 
com.codahale.metrics.MetricRegistry@1709cb7
   [junit4]   2> 1298074 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.acollectionafterbaddelete.shard1.replica_n1, tag=null
   [junit4]   2> 1298075 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@982c17: rootName = null, 
domain = solr.core.acollectionafterbaddelete.shard1.replica_n1, service url = 
null, agent id = null] for registry 
solr.core.acollectionafterbaddelete.shard1.replica_n1 / 
com.codahale.metrics.MetricRegistry@142b6ea
   [junit4]   2> 1298083 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica_n1]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@fe1856
   [junit4]   2> 1298083 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.acollectionafterbaddelete.shard1.replica_n1, tag=16652374
   [junit4]   2> 1298083 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.collection.acollectionafterbaddelete.shard1.leader, tag=16652374
   [junit4]   2> 1298084 WARN  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.LeaderElector 
   [junit4]   2> org.apache.solr.common.SolrException: SolrCore not 
found:acollectionafterbaddelete_shard1_replica_n2 in []
   [junit4]   2>        at 
org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:297)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:170)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:135)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:56)
   [junit4]   2>        at 
org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:348)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient$3.lambda$process$0(SolrZkClient.java:269)
   [junit4]   2>        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]   2>        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 1298086 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2}
 status=0 QTime=11
   [junit4]   2> 1298088 INFO  (qtp26363452-11740) [n:127.0.0.1:41577_solr    ] 
o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica_n2]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@f2df88
   [junit4]   2> 1298088 INFO  (qtp26363452-11740) [n:127.0.0.1:41577_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.acollectionafterbaddelete.shard1.replica_n2, tag=15916936
   [junit4]   2> 1298088 INFO  (qtp26363452-11740) [n:127.0.0.1:41577_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.collection.acollectionafterbaddelete.shard1.leader, tag=15916936
   [junit4]   2> 1298089 INFO  (qtp26363452-11740) [n:127.0.0.1:41577_solr    ] 
o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader 
parent node, won't remove previous leader registration.
   [junit4]   2> 1298089 INFO  (qtp26363452-11740) [n:127.0.0.1:41577_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica_n2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2}
 status=0 QTime=16
   [junit4]   2> 1298792 INFO  (qtp22071740-11751) [n:127.0.0.1:42951_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2} 
status=0 QTime=720
   [junit4]   2> 1298793 INFO  (qtp22071740-11720) [n:127.0.0.1:42951_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> 1298793 INFO  
(OverseerThreadFactory-4007-thread-4-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
acollection
   [junit4]   2> 1298794 INFO  
(OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000)
 [n:127.0.0.1:43357_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> 1298794 ERROR 
(OverseerThreadFactory-4007-thread-4-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_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:117)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 1298795 INFO  (qtp22071740-11720) [n:127.0.0.1:42951_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=2
   [junit4]   2> 1298795 INFO  
(TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
   [junit4]   2> 1298826 INFO  
(TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
   [junit4]   2> 1298827 INFO  
(TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[22F645446B8A6553])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 1298828 INFO  (qtp22071740-11746) [n:127.0.0.1:42951_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=10&collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1298829 INFO  
(OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
collection
   [junit4]   2> 1298829 INFO  
(OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000)
 [n:127.0.0.1:43357_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> 1298829 WARN  
(OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.CreateCollectionCmd Specified number of 
replicas of 10 on collection collection is higher than the number of Solr 
instances currently live or live and part of your createNodeSet(4). It's 
unusual to run two replica of the same slice on the same Solr-instance.
   [junit4]   2> 1298829 ERROR 
(OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.OverseerCollectionMessageHandler 
Collection: collection operation: create 
failed:org.apache.solr.common.SolrException: Cannot create collection 
collection. Value of maxShardsPerNode is 1, and the number of nodes currently 
live or live and part of your createNodeSet is 4. This allows a maximum of 4 to 
be created. Value of numShards is 2, value of nrtReplicas is 10, value of 
tlogReplicas is 0 and value of pullReplicas is 0. This requires 20 shards to be 
created (higher than the allowed number)
   [junit4]   2>        at 
org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:164)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 1298830 INFO  (qtp22071740-11746) [n:127.0.0.1:42951_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=10&collection.configName=conf&name=collection&nrtReplicas=10&action=CREATE&numShards=2&wt=javabin&version=2}
 status=400 QTime=2
   [junit4]   2> 1298831 INFO  
(TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
   [junit4]   2> 1298860 INFO  
(TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testMaxNodesPerShard
   [junit4]   2> 1298861 INFO  
(TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[22F645446B8A6553])
 [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 1298863 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&name=oversharded&nrtReplicas=2&action=CREATE&numShards=3&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1298867 INFO  
(OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
oversharded
   [junit4]   2> 1298868 INFO  
(OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000)
 [n:127.0.0.1:43357_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> 1298868 ERROR 
(OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.OverseerCollectionMessageHandler 
Collection: oversharded operation: create 
failed:org.apache.solr.common.SolrException: Cannot create collection 
oversharded. Value of maxShardsPerNode is 1, and the number of nodes currently 
live or live and part of your createNodeSet is 4. This allows a maximum of 4 to 
be created. Value of numShards is 3, value of nrtReplicas is 2, value of 
tlogReplicas is 0 and value of pullReplicas is 0. This requires 6 shards to be 
created (higher than the allowed number)
   [junit4]   2>        at 
org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:164)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:227)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 1298869 INFO  (qtp22071740-11743) [n:127.0.0.1:42951_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={replicationFactor=2&collection.configName=conf&name=oversharded&nrtReplicas=2&action=CREATE&numShards=3&wt=javabin&version=2}
 status=400 QTime=5
   [junit4]   2> 1298869 INFO  
(TEST-CollectionsAPIDistributedZkTest.testMaxNodesPerShard-seed#[22F645446B8A6553])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testMaxNodesPerShard
   [junit4]   2> 1298901 INFO  
(TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[22F645446B8A6553]) [ 
   ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
   [junit4]   2> 1298902 INFO  
(TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[22F645446B8A6553]) [ 
   ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
   [junit4]   2> 1298903 INFO  (qtp22071740-11751) [n:127.0.0.1:42951_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1298904 INFO  
(OverseerThreadFactory-4007-thread-5-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
addReplicaColl
   [junit4]   2> 1298904 INFO  
(OverseerCollectionConfigSetProcessor-98755367785594891-127.0.0.1:43357_solr-n_0000000000)
 [n:127.0.0.1:43357_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000010 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 1299108 INFO  
(OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"addReplicaColl",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"addReplicaColl_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:43357/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1299108 INFO  
(OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"addReplicaColl",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"addReplicaColl_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:40241/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1299109 INFO  
(OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"addReplicaColl",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"addReplicaColl_shard2_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:41577/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1299109 INFO  
(OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"addReplicaColl",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"addReplicaColl_shard2_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:42951/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1299311 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica_n1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1299311 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica_n2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1299311 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1299311 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1299311 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica_n1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1299312 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica_n2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1299415 INFO  
(zkCallback-1454-thread-1-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1299415 INFO  
(zkCallback-1452-thread-1-processing-n:127.0.0.1:40241_solr) 
[n:127.0.0.1:40241_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> 1299415 INFO  
(zkCallback-1452-thread-2-processing-n:127.0.0.1:40241_solr) 
[n:127.0.0.1:40241_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> 1299415 INFO  
(zkCallback-1451-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1299415 INFO  
(zkCallback-1451-thread-2-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_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> 1299415 INFO  
(zkCallback-1454-thread-2-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_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> 1299415 INFO  
(zkCallback-1453-thread-2-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_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> 1299415 INFO  
(zkCallback-1453-thread-1-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_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> 1300321 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
   [junit4]   2> 1300321 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr 
c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
   [junit4]   2> 1300321 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
   [junit4]   2> 1300321 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.1
   [junit4]   2> 1300341 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.s.IndexSchema [addReplicaColl_shard2_replica_n2] Schema name=minimal
   [junit4]   2> 1300341 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr 
c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] 
o.a.s.s.IndexSchema [addReplicaColl_shard1_replica_n2] Schema name=minimal
   [junit4]   2> 1300342 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.s.IndexSchema [addReplicaColl_shard2_replica_n1] Schema name=minimal
   [junit4]   2> 1300343 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1300343 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica_n2' 
using configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 1300343 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr 
c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1300343 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr 
c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica_n2' 
using configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 1300343 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1300343 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.s.IndexSchema [addReplicaColl_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 1300343 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica_n1' 
using configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 1300344 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.core.addReplicaColl.shard2.replica_n1' (registry 
'solr.core.addReplicaColl.shard2.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1300344 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr 
c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.core.addReplicaColl.shard1.replica_n2' (registry 
'solr.core.addReplicaColl.shard1.replica_n2') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1300344 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1300344 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.core.addReplicaColl.shard2.replica_n2' (registry 
'solr.core.addReplicaColl.shard2.replica_n2') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1300344 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr 
c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1300344 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.c.SolrCore [[addReplicaColl_shard2_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/addReplicaColl_shard2_replica_n1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node4/addReplicaColl_shard2_replica_n1/data/]
   [junit4]   2> 1300344 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1300344 INFO  (qtp16839552-11744) [n:127.0.0.1:40241_solr 
c:addReplicaColl s:shard1 r:core_node2 x:addReplicaColl_shard1_replica_n2] 
o.a.s.c.SolrCore [[addReplicaColl_shard1_replica_n2] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node2/addReplicaColl_shard1_replica_n2],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node2/addReplicaColl_shard1_replica_n2/data/]
   [junit4]   2> 1300344 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.c.SolrCore [[addReplicaColl_shard2_replica_n2] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/addReplicaColl_shard2_replica_n2],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node1/addReplicaColl_shard2_replica_n2/data/]
   [junit4]   2> 1300345 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1300345 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica_n1' 
using configuration from collection addReplicaColl, trusted=true
   [junit4]   2> 1300346 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.core.addReplicaColl.shard1.replica_n1' (registry 
'solr.core.addReplicaColl.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@197c0cb
   [junit4]   2> 1300346 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1300346 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.c.SolrCore [[addReplicaColl_shard1_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node3/addReplicaColl_shard1_replica_n1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001/tempDir-001/node3/addReplicaColl_shard1_replica_n1/data/]
   [junit4]   2> 1300383 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1300383 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1300384 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1300384 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1300386 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@5552c4[addReplicaColl_shard2_replica_n1] main]
   [junit4]   2> 1300386 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1300403 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1300404 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1300404 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1580085891027697664
   [junit4]   2> 1300406 INFO  
(searcherExecutor-4028-thread-1-processing-n:127.0.0.1:41577_solr 
x:addReplicaColl_shard2_replica_n1 s:shard2 c:addReplicaColl r:core_node3) 
[n:127.0.0.1:41577_solr c:addReplicaColl s:shard2 r:core_node3 
x:addReplicaColl_shard2_replica_n1] o.a.s.c.SolrCore 
[addReplicaColl_shard2_replica_n1] Registered new searcher 
Searcher@5552c4[addReplicaColl_shard2_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1300406 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1300406 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1300407 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1300407 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1300408 INFO  (qtp26363452-11722) [n:127.0.0.1:41577_solr 
c:addReplicaColl s:shard2 r:core_node3 x:addReplicaColl_shard2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for 
shard shard2: total=2 found=1 timeoutin=9999ms
   [junit4]   2> 1300409 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@cde34d[addReplicaColl_shard1_replica_n1] main]
   [junit4]   2> 1300409 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1300410 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1300410 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1 r:core_node1 x:addReplicaColl_shard1_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1300411 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1300411 INFO  (qtp22071740-11724) [n:127.0.0.1:42951_solr 
c:addReplicaColl s:shard2 r:core_node4 x:addReplicaColl_shard2_replica_n2] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1300411 INFO  
(searcherExecutor-4029-thread-1-processing-n:127.0.0.1:43357_solr 
x:addReplicaColl_shard1_replica_n1 s:shard1 c:addReplicaColl r:core_node1) 
[n:127.0.0.1:43357_solr c:addReplicaColl s:shard1 r:core_node1 
x:addReplicaColl_shard1_replica_n1] o.a.s.c.SolrCore 
[addReplicaColl_shard1_replica_n1] Registered new searcher 
Searcher@cde34d[addReplicaColl_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1300411 INFO  (qtp10275674-11742) [n:127.0.0.1:43357_solr 
c:addReplicaColl s:shard1

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

> 1378537 INFO  (coreCloseExecutor-4208-thread-1) [n:127.0.0.1:41577_solr 
> c:nodes_used_collection s:shard2 r:core_node3 
> x:nodes_used_collection_shard2_replica_n1] o.a.s.c.SolrCore 
> [nodes_used_collection_shard2_replica_n1]  CLOSING SolrCore 
> org.apache.solr.core.SolrCore@86d484
   [junit4]   2> 1378537 INFO  (coreCloseExecutor-4208-thread-1) 
[n:127.0.0.1:41577_solr c:nodes_used_collection s:shard2 r:core_node3 
x:nodes_used_collection_shard2_replica_n1] o.a.s.m.SolrMetricManager Closing 
metric reporters for 
registry=solr.core.nodes_used_collection.shard2.replica_n1, tag=8836228
   [junit4]   2> 1378537 INFO  (coreCloseExecutor-4208-thread-1) 
[n:127.0.0.1:41577_solr c:nodes_used_collection s:shard2 r:core_node3 
x:nodes_used_collection_shard2_replica_n1] o.a.s.m.r.SolrJmxReporter Closing 
reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@37161b: rootName = 
null, domain = solr.core.nodes_used_collection.shard2.replica_n1, service url = 
null, agent id = null] for registry 
solr.core.nodes_used_collection.shard2.replica_n1 / 
com.codahale.metrics.MetricRegistry@1c537f6
   [junit4]   2> 1378549 INFO  (coreCloseExecutor-4208-thread-1) 
[n:127.0.0.1:41577_solr c:nodes_used_collection s:shard2 r:core_node3 
x:nodes_used_collection_shard2_replica_n1] o.a.s.m.SolrMetricManager Closing 
metric reporters for 
registry=solr.collection.nodes_used_collection.shard2.leader, tag=8836228
   [junit4]   2> 1378549 INFO  (coreCloseExecutor-4205-thread-1) 
[n:127.0.0.1:43357_solr c:nodes_used_collection s:shard1 r:core_node2 
x:nodes_used_collection_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing 
metric reporters for 
registry=solr.collection.nodes_used_collection.shard1.leader, tag=29569657
   [junit4]   2> 1378549 INFO  (coreCloseExecutor-4206-thread-1) 
[n:127.0.0.1:40241_solr c:nodes_used_collection s:shard2 r:core_node4 
x:nodes_used_collection_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing 
metric reporters for 
registry=solr.collection.nodes_used_collection.shard2.leader, tag=30710527
   [junit4]   2> 1378550 INFO  (coreCloseExecutor-4207-thread-1) 
[n:127.0.0.1:42951_solr c:nodes_used_collection s:shard1 r:core_node1 
x:nodes_used_collection_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing 
metric reporters for 
registry=solr.collection.nodes_used_collection.shard1.leader, tag=14270704
   [junit4]   2> 1378550 INFO  (jetty-closer-1433-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=98755367785594891-127.0.0.1:43357_solr-n_0000000000) closing
   [junit4]   2> 1378550 INFO  
(zkCallback-1454-thread-3-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (2)
   [junit4]   2> 1378550 INFO  
(OverseerStateUpdate-98755367785594891-127.0.0.1:43357_solr-n_0000000000) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 
127.0.0.1:43357_solr
   [junit4]   2> 1378550 WARN  
(zkCallback-1454-thread-3-processing-n:127.0.0.1:42951_solr) 
[n:127.0.0.1:42951_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1378553 INFO  (jetty-closer-1433-thread-4) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@1adf4bc{/solr,null,UNAVAILABLE}
   [junit4]   2> 1380050 WARN  
(zkCallback-1452-thread-5-processing-n:127.0.0.1:40241_solr) 
[n:127.0.0.1:40241_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1380050 WARN  
(zkCallback-1483-thread-1-processing-n:127.0.0.1:41577_solr) 
[n:127.0.0.1:41577_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1380051 INFO  (jetty-closer-1433-thread-2) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@5710ad{/solr,null,UNAVAILABLE}
   [junit4]   2> 1380051 INFO  (jetty-closer-1433-thread-3) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@1840a3c{/solr,null,UNAVAILABLE}
   [junit4]   2> 1380053 WARN  
(zkCallback-1453-thread-5-processing-n:127.0.0.1:43357_solr) 
[n:127.0.0.1:43357_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1380053 INFO  (jetty-closer-1433-thread-1) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@1803eec{/solr,null,UNAVAILABLE}
   [junit4]   2> 1380054 ERROR 
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper 
server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 1380054 INFO  
(SUITE-CollectionsAPIDistributedZkTest-seed#[22F645446B8A6553]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:46533 46533
   [junit4]   2> 1380066 INFO  (Thread-3929) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:46533 46533
   [junit4]   2> 1380068 WARN  (Thread-3929) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        10      /solr/configs/conf
   [junit4]   2>        6       /solr/clusterprops.json
   [junit4]   2>        6       /solr/aliases.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        32      
/solr/collections/nodes_used_collection/state.json
   [junit4]   2>        30      /solr/collections/reloaded_collection/state.json
   [junit4]   2>        8       
/solr/collections/awhollynewcollection_0/state.json
   [junit4]   2>        6       /solr/clusterstate.json
   [junit4]   2>        5       /solr/collections/withconfigset2/state.json
   [junit4]   2>        4       
/solr/collections/halfcollectionblocker/state.json
   [junit4]   2>        4       /solr/collections/halfcollection/state.json
   [junit4]   2>        4       
/solr/collections/halfcollectionblocker2/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        238     /solr/collections
   [junit4]   2>        6       /solr/live_nodes
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-7.0-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CollectionsAPIDistributedZkTest_22F645446B8A6553-001
   [junit4]   2> Oct 01, 2017 7:50:11 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{id=PostingsFormat(name=Memory)}, docValues:{}, maxPointsInLeafNode=880, 
maxMBSortInHeap=5.368270160587303, sim=RandomSimilarity(queryNorm=true): {}, 
locale=fr-LU, timezone=America/Tegucigalpa
   [junit4]   2> NOTE: Linux 4.10.0-33-generic i386/Oracle Corporation 
1.8.0_144 (32-bit)/cpus=8,threads=1,free=145940304,total=417857536
   [junit4]   2> NOTE: All tests run in this JVM: [SolrTestCaseJ4Test, 
BlockJoinFacetDistribTest, TestLockTree, SuggestComponentTest, 
CdcrReplicationDistributedZkTest, SpatialRPTFieldTypeTest, 
LeaderElectionContextKeyTest, DistributedFacetPivotSmallAdvancedTest, 
TestSuggestSpellingConverter, AsyncCallRequestStatusResponseTest, 
LeaderElectionTest, GraphQueryTest, HdfsRecoveryZkTest, TestClusterProperties, 
PreAnalyzedFieldTest, TestNumericTerms32, TestGroupingSearch, 
TestReloadDeadlock, TestSha256AuthenticationProvider, CircularListTest, 
TestStressReorder, ResponseHeaderTest, TestDocBasedVersionConstraints, 
DataDrivenBlockJoinTest, TestExactSharedStatsCache, TestSurroundQueryParser, 
CopyFieldTest, LargeFieldTest, TestMaxTokenLenTokenizer, SortSpecParsingTest, 
TestConfigSets, TestSort, RequiredFieldsTest, TestSchemaResource, 
BasicDistributedZk2Test, TestSolrXml, TestPayloadScoreQParserPlugin, 
CoreAdminCreateDiscoverTest, PrimitiveFieldTypeTest, 
TestAuthorizationFramework, DocumentBuilderTest, TestManagedResourceStorage, 
SolrCloudExampleTest, TlogReplayBufferedWhileIndexingTest, 
NotRequiredUniqueKeyTest, TestStressCloudBlindAtomicUpdates, TestInitParams, 
TestExclusionRuleCollectionAccess, CustomCollectionTest, 
TestHttpShardHandlerFactory, TestConfigOverlay, FastVectorHighlighterTest, 
TimeZoneUtilsTest, TestQuerySenderListener, 
CollectionsAPIAsyncDistributedZkTest, HdfsBasicDistributedZkTest, 
SaslZkACLProviderTest, TestSegmentSorting, MultiTermTest, 
SolrCoreCheckLockOnStartupTest, TestCloudDeleteByQuery, HdfsLockFactoryTest, 
SignatureUpdateProcessorFactoryTest, TestGeoJSONResponseWriter, 
HdfsWriteToMultipleCollectionsTest, TestSystemCollAutoCreate, 
SharedFSAutoReplicaFailoverUtilsTest, TestTlogReplica, TestTrie, 
TestJsonFacetRefinement, AnalyticsMergeStrategyTest, DeleteStatusTest, 
MissingSegmentRecoveryTest, DateMathParserTest, ConfigSetsAPITest, 
TestTrieFacet, IgnoreCommitOptimizeUpdateProcessorFactoryTest, 
HdfsDirectoryFactoryTest, SimplePostToolTest, TestLegacyNumericUtils, 
VersionInfoTest, ActionThrottleTest, TestMaxScoreQueryParser, 
OverseerTaskQueueTest, TestMacros, SpellPossibilityIteratorTest, 
TestDynamicFieldResource, ReturnFieldsTest, ClusterStateTest, 
DirectUpdateHandlerTest, TestApiFramework, TestConfigSetsAPIExclusivity, 
TestDFRSimilarityFactory, TestScoreJoinQPNoScore, BasicAuthIntegrationTest, 
TestInPlaceUpdatesDistrib, OutOfBoxZkACLAndCredentialsProvidersTest, 
TestOrdValues, TestFieldTypeCollectionResource, 
TestSolrCloudWithHadoopAuthPlugin, TestFieldCacheReopen, 
TestSubQueryTransformerCrossCore, TestAnalyzeInfixSuggestions, 
HardAutoCommitTest, TestHalfAndHalfDocValues, TestBinaryResponseWriter, 
TestSolrCloudWithDelegationTokens, TestDynamicLoading, TestPushWriter, 
TestPullReplica, ResponseLogComponentTest, FullSolrCloudDistribCmdsTest, 
TestLFUCache, JavabinLoaderTest, PingRequestHandlerTest, SortByFunctionTest, 
CollectionsAPIDistributedZkTest]
   [junit4] Completed [329/730 (1!)] on J2 in 86.34s, 19 tests, 1 error <<< 
FAILURES!

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

Reply via email to