Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/20003/
Java: 32bit/jdk1.8.0_131 -server -XX:+UseG1GC

1 tests failed.
FAILED:  
org.apache.solr.cloud.autoscaling.TestPolicyCloud.testCreateCollectionAddReplica

Error Message:
Error from server at https://127.0.0.1:37879/solr: delete the collection time 
out:180s

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error 
from server at https://127.0.0.1:37879/solr: delete the collection time out:180s
        at 
__randomizedtesting.SeedInfo.seed([7D4BB7647B75CFAC:FD6BD24A6A36270A]:0)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:624)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:250)
        at 
org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:239)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:470)
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:400)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1102)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:843)
        at 
org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:774)
        at 
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
        at 
org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:195)
        at 
org.apache.solr.cloud.MiniSolrCloudCluster.deleteAllCollections(MiniSolrCloudCluster.java:442)
        at 
org.apache.solr.cloud.autoscaling.TestPolicyCloud.after(TestPolicyCloud.java:63)
        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$10.evaluate(RandomizedRunner.java:965)
        at 
org.junit.rules.ExpectedException$ExpectedExceptionStatement.evaluate(ExpectedException.java:110)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 13075 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.TestPolicyCloud
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/init-core-data-001
   [junit4]   2> 1524039 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) 
w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 1524040 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1524041 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 5 servers in 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001
   [junit4]   2> 1524041 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1524041 INFO  (Thread-3577) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1524041 INFO  (Thread-3577) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1524043 ERROR (Thread-3577) [    ] 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> 1524141 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:35703
   [junit4]   2> 1524149 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1524150 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1524151 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1524151 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1524179 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 1524179 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@84564a{/solr,null,AVAILABLE}
   [junit4]   2> 1524180 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@1d65729{SSL,[ssl, 
http/1.1]}{127.0.0.1:44285}
   [junit4]   2> 1524180 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.e.j.s.Server Started @1525768ms
   [junit4]   2> 1524181 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=44285}
   [junit4]   2> 1524181 ERROR (jetty-launcher-2803-thread-4) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1524181 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 1524181 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1524181 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1524181 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-28T16:42:37.208Z
   [junit4]   2> 1524195 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@eee046{/solr,null,AVAILABLE}
   [junit4]   2> 1524196 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@f25e95{SSL,[ssl, 
http/1.1]}{127.0.0.1:37879}
   [junit4]   2> 1524196 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.e.j.s.Server Started @1525783ms
   [junit4]   2> 1524219 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=37879}
   [junit4]   2> 1524219 ERROR (jetty-launcher-2803-thread-2) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1524219 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 1524219 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1524219 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1524219 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-28T16:42:37.246Z
   [junit4]   2> 1524220 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1524220 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@f5fae1{/solr,null,AVAILABLE}
   [junit4]   2> 1524218 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@cd8091{/solr,null,AVAILABLE}
   [junit4]   2> 1524226 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1524242 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@76c77d{/solr,null,AVAILABLE}
   [junit4]   2> 1524243 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@59b6ac{SSL,[ssl, 
http/1.1]}{127.0.0.1:41939}
   [junit4]   2> 1524243 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.e.j.s.Server Started @1525830ms
   [junit4]   2> 1524243 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=41939}
   [junit4]   2> 1524243 ERROR (jetty-launcher-2803-thread-5) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1524243 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 1524243 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1524243 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1524243 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-28T16:42:37.270Z
   [junit4]   2> 1524245 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@62e2c{SSL,[ssl, 
http/1.1]}{127.0.0.1:35063}
   [junit4]   2> 1524245 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.e.j.s.Server Started @1525833ms
   [junit4]   2> 1524245 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=35063}
   [junit4]   2> 1524246 ERROR (jetty-launcher-2803-thread-3) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1524246 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 1524246 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1524246 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1524246 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-28T16:42:37.273Z
   [junit4]   2> 1524247 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.e.j.s.AbstractConnector Started ServerConnector@1e4619e{SSL,[ssl, 
http/1.1]}{127.0.0.1:45137}
   [junit4]   2> 1524247 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.e.j.s.Server Started @1525834ms
   [junit4]   2> 1524247 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=45137}
   [junit4]   2> 1524247 ERROR (jetty-launcher-2803-thread-1) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1524248 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.0.0
   [junit4]   2> 1524248 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1524248 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null, Default config 
dir: null
   [junit4]   2> 1524248 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-06-28T16:42:37.275Z
   [junit4]   2> 1524250 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1524250 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1524364 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1524364 INFO  (jetty-launcher-2803-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35703/solr
   [junit4]   2> 1524373 INFO  (jetty-launcher-2803-thread-4) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35703/solr
   [junit4]   2> 1524373 INFO  (jetty-launcher-2803-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35703/solr
   [junit4]   2> 1524390 INFO  (jetty-launcher-2803-thread-5) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35703/solr
   [junit4]   2> 1524390 INFO  (jetty-launcher-2803-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35703/solr
   [junit4]   2> 1524393 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 0x15cef95488d0008, 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> 1524424 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1524425 INFO  (jetty-launcher-2803-thread-4) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1524426 INFO  (jetty-launcher-2803-thread-1) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1524426 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:35063_solr
   [junit4]   2> 1524427 INFO  (jetty-launcher-2803-thread-1) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:45137_solr
   [junit4]   2> 1524427 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.Overseer Overseer 
(id=98216716341673999-127.0.0.1:35063_solr-n_0000000000) starting
   [junit4]   2> 1524427 INFO  (jetty-launcher-2803-thread-5) 
[n:127.0.0.1:41939_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1524428 INFO  (jetty-launcher-2803-thread-4) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:44285_solr
   [junit4]   2> 1524437 INFO  
(zkCallback-2830-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1524444 INFO  
(zkCallback-2827-thread-1-processing-n:127.0.0.1:45137_solr) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1524445 INFO  
(zkCallback-2828-thread-2-processing-n:127.0.0.1:44285_solr) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1524444 INFO  
(zkCallback-2828-thread-1-processing-n:127.0.0.1:44285_solr) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1524442 INFO  (jetty-launcher-2803-thread-5) 
[n:127.0.0.1:41939_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:41939_solr
   [junit4]   2> 1524446 INFO  
(zkCallback-2827-thread-2-processing-n:127.0.0.1:45137_solr) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1524446 INFO  
(zkCallback-2830-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1524447 INFO  
(zkCallback-2829-thread-1-processing-n:127.0.0.1:41939_solr) 
[n:127.0.0.1:41939_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 1524450 INFO  
(zkCallback-2829-thread-1-processing-n:127.0.0.1:41939_solr) 
[n:127.0.0.1:41939_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1524453 INFO  
(zkCallback-2828-thread-1-processing-n:127.0.0.1:44285_solr) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1524453 INFO  
(zkCallback-2827-thread-2-processing-n:127.0.0.1:45137_solr) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1524454 INFO  (jetty-launcher-2803-thread-2) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 1524455 INFO  (jetty-launcher-2803-thread-2) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1524456 INFO  (jetty-launcher-2803-thread-2) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:37879_solr
   [junit4]   2> 1524462 INFO  
(zkCallback-2828-thread-1-processing-n:127.0.0.1:44285_solr) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 1524470 INFO  
(zkCallback-2830-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (4)
   [junit4]   2> 1524471 INFO  
(zkCallback-2829-thread-1-processing-n:127.0.0.1:41939_solr) 
[n:127.0.0.1:41939_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 1524471 INFO  
(zkCallback-2827-thread-2-processing-n:127.0.0.1:45137_solr) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 1524478 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 1524482 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:35063_solr
   [junit4]   2> 1524484 INFO  
(zkCallback-2828-thread-1-processing-n:127.0.0.1:44285_solr) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 1524484 INFO  
(zkCallback-2829-thread-1-processing-n:127.0.0.1:41939_solr) 
[n:127.0.0.1:41939_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 1524487 INFO  
(zkCallback-2827-thread-2-processing-n:127.0.0.1:45137_solr) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 1524490 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 1524492 INFO  
(zkCallback-2830-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 1524527 INFO  (jetty-launcher-2803-thread-4) 
[n:127.0.0.1:44285_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44285.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524536 INFO  (jetty-launcher-2803-thread-4) 
[n:127.0.0.1:44285_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44285.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524536 INFO  (jetty-launcher-2803-thread-4) 
[n:127.0.0.1:44285_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44285.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524538 INFO  (jetty-launcher-2803-thread-4) 
[n:127.0.0.1:44285_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node4/.
   [junit4]   2> 1524561 INFO  (jetty-launcher-2803-thread-2) 
[n:127.0.0.1:37879_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_37879.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524565 INFO  (jetty-launcher-2803-thread-2) 
[n:127.0.0.1:37879_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_37879.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524566 INFO  (jetty-launcher-2803-thread-2) 
[n:127.0.0.1:37879_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_37879.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524567 INFO  (jetty-launcher-2803-thread-2) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/.
   [junit4]   2> 1524584 INFO  (jetty-launcher-2803-thread-5) 
[n:127.0.0.1:41939_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_41939.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524601 INFO  (jetty-launcher-2803-thread-5) 
[n:127.0.0.1:41939_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_41939.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524602 INFO  (jetty-launcher-2803-thread-5) 
[n:127.0.0.1:41939_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_41939.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524603 INFO  (jetty-launcher-2803-thread-5) 
[n:127.0.0.1:41939_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node5/.
   [junit4]   2> 1524637 INFO  (jetty-launcher-2803-thread-1) 
[n:127.0.0.1:45137_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_45137.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524640 INFO  (jetty-launcher-2803-thread-1) 
[n:127.0.0.1:45137_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_45137.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524640 INFO  (jetty-launcher-2803-thread-1) 
[n:127.0.0.1:45137_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_45137.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524641 INFO  (jetty-launcher-2803-thread-1) 
[n:127.0.0.1:45137_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node1/.
   [junit4]   2> 1524676 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_35063.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524682 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_35063.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524682 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_35063.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1524683 INFO  (jetty-launcher-2803-thread-3) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node3/.
   [junit4]   2> 1524744 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
   [junit4]   2> 1524744 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35703/solr ready
   [junit4]   2> 1524778 INFO  
(TEST-TestPolicyCloud.testDataProvider-seed#[7D4BB7647B75CFAC]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testDataProvider
   [junit4]   2> 1524856 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
shards=shard1&replicationFactor=2&collection.configName=conf&name=policiesTest&router.name=implicit&nrtReplicas=2&action=CREATE&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1524873 INFO  
(OverseerThreadFactory-7913-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
policiesTest
   [junit4]   2> 1524988 INFO  
(OverseerStateUpdate-98216716341673999-127.0.0.1:35063_solr-n_0000000000) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"policiesTest",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"policiesTest_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:37879/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1524989 INFO  
(OverseerStateUpdate-98216716341673999-127.0.0.1:35063_solr-n_0000000000) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"policiesTest",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"policiesTest_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:35063/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1525222 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=policiesTest_shard1_replica_n2&action=CREATE&numShards=1&collection=policiesTest&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1525223 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1525291 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=policiesTest_shard1_replica_n1&action=CREATE&numShards=1&collection=policiesTest&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1525292 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1525397 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1525397 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1525397 INFO  
(zkCallback-2830-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1525397 INFO  
(zkCallback-2830-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1526238 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 1526258 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.s.IndexSchema [policiesTest_shard1_replica_n2] Schema name=minimal
   [junit4]   2> 1526261 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1526266 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.c.CoreContainer Creating SolrCore 'policiesTest_shard1_replica_n2' using 
configuration from collection policiesTest, trusted=true
   [junit4]   2> 1526267 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_37879.solr.core.policiesTest.shard1.replica_n2' (registry 
'solr.core.policiesTest.shard1.replica_n2') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1526267 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1526267 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.c.SolrCore [[policiesTest_shard1_replica_n2] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/policiesTest_shard1_replica_n2],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/./policiesTest_shard1_replica_n2/data/]
   [junit4]   2> 1526309 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 1526346 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.s.IndexSchema [policiesTest_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 1526358 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1526358 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'policiesTest_shard1_replica_n1' using 
configuration from collection policiesTest, trusted=true
   [junit4]   2> 1526364 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_35063.solr.core.policiesTest.shard1.replica_n1' (registry 
'solr.core.policiesTest.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1526364 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 1526364 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.SolrCore [[policiesTest_shard1_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node3/policiesTest_shard1_replica_n1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node3/./policiesTest_shard1_replica_n1/data/]
   [junit4]   2> 1526547 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1526547 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1526550 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1526550 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1526551 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1526551 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1526553 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1526553 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1526556 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@bd97f7[policiesTest_shard1_replica_n1] main]
   [junit4]   2> 1526557 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1526559 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1526560 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1526560 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1571467464107098112
   [junit4]   2> 1526562 INFO  
(searcherExecutor-7925-thread-1-processing-n:127.0.0.1:35063_solr 
x:policiesTest_shard1_replica_n1 s:shard1 c:policiesTest r:core_node2) 
[n:127.0.0.1:35063_solr c:policiesTest s:shard1 r:core_node2 
x:policiesTest_shard1_replica_n1] o.a.s.c.SolrCore 
[policiesTest_shard1_replica_n1] Registered new searcher 
Searcher@bd97f7[policiesTest_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1526567 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_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> 1526571 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@134844[policiesTest_shard1_replica_n2] main]
   [junit4]   2> 1526572 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1526576 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1526577 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1526577 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1571467464124923904
   [junit4]   2> 1526579 INFO  
(searcherExecutor-7924-thread-1-processing-n:127.0.0.1:37879_solr 
x:policiesTest_shard1_replica_n2 s:shard1 c:policiesTest r:core_node1) 
[n:127.0.0.1:37879_solr c:policiesTest s:shard1 r:core_node1 
x:policiesTest_shard1_replica_n2] o.a.s.c.SolrCore 
[policiesTest_shard1_replica_n2] Registered new searcher 
Searcher@134844[policiesTest_shard1_replica_n2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1526672 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1526672 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1526673 INFO  
(zkCallback-2830-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1526673 INFO  
(zkCallback-2830-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527067 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1527067 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1527068 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
https://127.0.0.1:35063/solr/policiesTest_shard1_replica_n1/
   [junit4]   2> 1527068 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.u.PeerSync PeerSync: core=policiesTest_shard1_replica_n1 
url=https://127.0.0.1:35063/solr START 
replicas=[https://127.0.0.1:37879/solr/policiesTest_shard1_replica_n2/] 
nUpdates=100
   [junit4]   2> 1527069 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.u.PeerSync PeerSync: core=policiesTest_shard1_replica_n1 
url=https://127.0.0.1:35063/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 1527071 INFO  (qtp6343403-16459) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.c.S.Request [policiesTest_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> 1527071 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the 
next candidate
   [junit4]   2> 1527071 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_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> 1527072 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 1527074 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
https://127.0.0.1:35063/solr/policiesTest_shard1_replica_n1/ shard1
   [junit4]   2> 1527177 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527177 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527177 INFO  
(zkCallback-2830-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527177 INFO  
(zkCallback-2830-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527225 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1527227 INFO  (qtp12868722-16479) [n:127.0.0.1:35063_solr 
c:policiesTest s:shard1 r:core_node2 x:policiesTest_shard1_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=policiesTest_shard1_replica_n1&action=CREATE&numShards=1&collection=policiesTest&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1935
   [junit4]   2> 1527333 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527333 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527334 INFO  
(zkCallback-2830-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527334 INFO  
(zkCallback-2830-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527592 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:shard1 r:core_node1 x:policiesTest_shard1_replica_n2] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=policiesTest_shard1_replica_n2&action=CREATE&numShards=1&collection=policiesTest&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=2370
   [junit4]   2> 1527595 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_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> 1527694 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527694 INFO  
(zkCallback-2830-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527694 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1527694 INFO  
(zkCallback-2830-thread-1-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1528595 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={shards=shard1&replicationFactor=2&collection.configName=conf&name=policiesTest&router.name=implicit&nrtReplicas=2&action=CREATE&wt=javabin&version=2}
 status=0 QTime=3739
   [junit4]   2> 1528602 INFO  (qtp6343403-16456) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName,os.systemLoadAverage,memory.heap.usage&wt=javabin&version=2&group=solr.jvm,solr.node,solr.core}
 status=0 QTime=3
   [junit4]   2> 1528603 INFO  (qtp6343403-16458) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :addrole with params 
node=127.0.0.1:35063_solr&role=overseer&action=ADDROLE&wt=javabin&version=2 and 
sendToOCPQueue=true
   [junit4]   2> 1528605 INFO  
(OverseerThreadFactory-7913-thread-2-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.OverseerRoleCmd Overseer role added to 
127.0.0.1:35063_solr
   [junit4]   2> 1528605 INFO  
(OverseerCollectionConfigSetProcessor-98216716341673999-127.0.0.1:35063_solr-n_0000000000)
 [n:127.0.0.1:35063_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> 1528611 INFO  (qtp6343403-16458) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={node=127.0.0.1:35063_solr&role=overseer&action=ADDROLE&wt=javabin&version=2}
 status=0 QTime=7
   [junit4]   2> 1529621 INFO  (qtp12868722-16480) [n:127.0.0.1:35063_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=system.properties&property=java.version&property=java.vendor&wt=javabin&version=2}
 status=0 QTime=4
   [junit4]   2> 1529621 INFO  
(TEST-TestPolicyCloud.testDataProvider-seed#[7D4BB7647B75CFAC]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
   [junit4]   2> 1529622 INFO  (qtp6343403-16595) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params 
name=policiesTest&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 1529623 INFO  
(OverseerCollectionConfigSetProcessor-98216716341673999-127.0.0.1:35063_solr-n_0000000000)
 [n:127.0.0.1:35063_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> 1529623 INFO  
(OverseerThreadFactory-7913-thread-3-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.OverseerCollectionMessageHandler Executing 
Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
   [junit4]   2> 1529623 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.policiesTest.shard1.replica_n1, tag=null
   [junit4]   2> 1529625 INFO  (qtp6343403-16482) [n:127.0.0.1:37879_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.policiesTest.shard1.replica_n2, tag=null
   [junit4]   2> 1529626 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.c.SolrCore [policiesTest_shard1_replica_n1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@109477c
   [junit4]   2> 1529626 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.policiesTest.shard1.replica_n1, tag=17385340
   [junit4]   2> 1529626 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.collection.policiesTest.shard1.leader, tag=17385340
   [junit4]   2> 1529627 WARN  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.LeaderElector 
   [junit4]   2> org.apache.solr.common.SolrException: SolrCore not 
found:policiesTest_shard1_replica_n2 in []
   [junit4]   2>        at 
org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:296)
   [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:1142)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 1529628 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={deleteInstanceDir=true&core=policiesTest_shard1_replica_n1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2}
 status=0 QTime=4
   [junit4]   2> 1529629 INFO  (qtp6343403-16482) [n:127.0.0.1:37879_solr    ] 
o.a.s.c.SolrCore [policiesTest_shard1_replica_n2]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@1f36cee
   [junit4]   2> 1529629 INFO  (qtp6343403-16482) [n:127.0.0.1:37879_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.policiesTest.shard1.replica_n2, tag=32730350
   [junit4]   2> 1529629 INFO  (qtp6343403-16482) [n:127.0.0.1:37879_solr    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.collection.policiesTest.shard1.leader, tag=32730350
   [junit4]   2> 1529630 INFO  (qtp6343403-16482) [n:127.0.0.1:37879_solr    ] 
o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader 
parent node, won't remove previous leader registration.
   [junit4]   2> 1529630 INFO  (qtp6343403-16482) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={deleteInstanceDir=true&core=policiesTest_shard1_replica_n2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2}
 status=0 QTime=4
   [junit4]   2> 1530332 INFO  (qtp6343403-16595) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={name=policiesTest&action=DELETE&wt=javabin&version=2} status=0 QTime=710
   [junit4]   2> 1530333 INFO  
(TEST-TestPolicyCloud.testDataProvider-seed#[7D4BB7647B75CFAC]) [    ] 
o.a.s.SolrTestCaseJ4 ###Ending testDataProvider
   [junit4]   2> 1530375 INFO  
(TEST-TestPolicyCloud.testCreateCollectionAddShardUsingPolicy-seed#[7D4BB7647B75CFAC])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testCreateCollectionAddShardUsingPolicy
   [junit4]   2> 1530443 INFO  (qtp33428153-16465) [n:127.0.0.1:44285_solr    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (5)
   [junit4]   2> 1530443 INFO  (qtp33428153-16465) [n:127.0.0.1:44285_solr    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35703/solr ready
   [junit4]   2> 1530445 INFO  (qtp6343403-16456) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530503 INFO  (qtp14629123-16491) [n:127.0.0.1:45137_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530511 INFO  (qtp33428153-16466) [n:127.0.0.1:44285_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530564 INFO  (qtp5550408-16488) [n:127.0.0.1:41939_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530566 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530567 INFO  (qtp33428153-16465) [n:127.0.0.1:44285_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=138
   [junit4]   2> 1530568 INFO  (qtp6343403-16596) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
shards=s1,s2&replicationFactor=1&collection.configName=conf&name=policiesTest&router.name=implicit&nrtReplicas=1&action=CREATE&wt=javabin&version=2&policy=c1
 and sendToOCPQueue=true
   [junit4]   2> 1530569 INFO  
(OverseerThreadFactory-7913-thread-4-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.CreateCollectionCmd Create collection 
policiesTest
   [junit4]   2> 1530569 INFO  
(OverseerCollectionConfigSetProcessor-98216716341673999-127.0.0.1:35063_solr-n_0000000000)
 [n:127.0.0.1:35063_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> 1530575 INFO  (qtp6343403-16458) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530578 INFO  (qtp14629123-16492) [n:127.0.0.1:45137_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530580 INFO  (qtp33428153-16466) [n:127.0.0.1:44285_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530583 INFO  (qtp5550408-16506) [n:127.0.0.1:41939_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530586 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1530801 INFO  
(OverseerStateUpdate-98216716341673999-127.0.0.1:35063_solr-n_0000000000) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"policiesTest",
   [junit4]   2>   "shard":"s2",
   [junit4]   2>   "core":"policiesTest_s2_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:37879/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1530804 INFO  
(OverseerStateUpdate-98216716341673999-127.0.0.1:35063_solr-n_0000000000) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"policiesTest",
   [junit4]   2>   "shard":"s1",
   [junit4]   2>   "core":"policiesTest_s1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:37879/solr";,
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1530909 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=policiesTest_s2_replica_n1&action=CREATE&numShards=2&collection=policiesTest&shard=s2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1530913 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=policiesTest_s1_replica_n1&action=CREATE&numShards=2&collection=policiesTest&shard=s1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1531015 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1531015 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1531917 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 1531919 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 1531953 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.s.IndexSchema [policiesTest_s2_replica_n1] Schema name=minimal
   [junit4]   2> 1531953 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.s.IndexSchema [policiesTest_s1_replica_n1] Schema name=minimal
   [junit4]   2> 1531955 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1531955 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1531955 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'policiesTest_s2_replica_n1' using 
configuration from collection policiesTest, trusted=true
   [junit4]   2> 1531955 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'policiesTest_s1_replica_n1' using 
configuration from collection policiesTest, trusted=true
   [junit4]   2> 1531956 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_37879.solr.core.policiesTest.s1.replica_n1' (registry 
'solr.core.policiesTest.s1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1531956 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1531956 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_37879.solr.core.policiesTest.s2.replica_n1' (registry 
'solr.core.policiesTest.s2.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1531956 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] o.a.s.c.SolrCore 
[[policiesTest_s1_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/policiesTest_s1_replica_n1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/./policiesTest_s1_replica_n1/data/]
   [junit4]   2> 1531956 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1531957 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] o.a.s.c.SolrCore 
[[policiesTest_s2_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/policiesTest_s2_replica_n1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/./policiesTest_s2_replica_n1/data/]
   [junit4]   2> 1532000 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1532000 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1532001 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1532001 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1532002 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1949fb9[policiesTest_s1_replica_n1] 
main]
   [junit4]   2> 1532003 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1532003 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1532003 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1532004 INFO  
(searcherExecutor-7935-thread-1-processing-n:127.0.0.1:37879_solr 
x:policiesTest_s1_replica_n1 s:s1 c:policiesTest r:core_node2) 
[n:127.0.0.1:37879_solr c:policiesTest s:s1 r:core_node2 
x:policiesTest_s1_replica_n1] o.a.s.c.SolrCore [policiesTest_s1_replica_n1] 
Registered new searcher Searcher@1949fb9[policiesTest_s1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1532004 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1571467469815545856
   [junit4]   2> 1532005 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1532005 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1532007 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1532007 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1532007 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1532007 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1532007 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
https://127.0.0.1:37879/solr/policiesTest_s1_replica_n1/
   [junit4]   2> 1532007 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 1532007 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.SyncStrategy https://127.0.0.1:37879/solr/policiesTest_s1_replica_n1/ 
has no replicas
   [junit4]   2> 1532007 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 1532008 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1661e41[policiesTest_s2_replica_n1] 
main]
   [junit4]   2> 1532014 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1532015 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1532016 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1532016 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
https://127.0.0.1:37879/solr/policiesTest_s1_replica_n1/ s1
   [junit4]   2> 1532016 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1571467469828128768
   [junit4]   2> 1532018 INFO  
(searcherExecutor-7934-thread-1-processing-n:127.0.0.1:37879_solr 
x:policiesTest_s2_replica_n1 s:s2 c:policiesTest r:core_node1) 
[n:127.0.0.1:37879_solr c:policiesTest s:s2 r:core_node1 
x:policiesTest_s2_replica_n1] o.a.s.c.SolrCore [policiesTest_s2_replica_n1] 
Registered new searcher Searcher@1661e41[policiesTest_s2_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1532019 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 1532019 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 1532019 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
https://127.0.0.1:37879/solr/policiesTest_s2_replica_n1/
   [junit4]   2> 1532019 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 1532019 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.SyncStrategy https://127.0.0.1:37879/solr/policiesTest_s2_replica_n1/ 
has no replicas
   [junit4]   2> 1532019 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 1532020 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
https://127.0.0.1:37879/solr/policiesTest_s2_replica_n1/ s2
   [junit4]   2> 1532122 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1532122 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1532167 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1532168 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr 
c:policiesTest s:s1 r:core_node2 x:policiesTest_s1_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=policiesTest_s1_replica_n1&action=CREATE&numShards=2&collection=policiesTest&shard=s1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1255
   [junit4]   2> 1532172 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 1532174 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr 
c:policiesTest s:s2 r:core_node1 x:policiesTest_s2_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=policiesTest_s2_replica_n1&action=CREATE&numShards=2&collection=policiesTest&shard=s2&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=1264
   [junit4]   2> 1532175 INFO  (qtp6343403-16596) [n:127.0.0.1:37879_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> 1532274 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1532274 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1532570 INFO  
(OverseerCollectionConfigSetProcessor-98216716341673999-127.0.0.1:35063_solr-n_0000000000)
 [n:127.0.0.1:35063_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> 1533175 INFO  (qtp6343403-16596) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={shards=s1,s2&replicationFactor=1&collection.configName=conf&name=policiesTest&router.name=implicit&nrtReplicas=1&action=CREATE&wt=javabin&version=2&policy=c1}
 status=0 QTime=2606
   [junit4]   2> 1533176 INFO  (qtp6343403-16595) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :createshard with params 
action=CREATESHARD&collection=policiesTest&shard=s3&wt=javabin&version=2 and 
sendToOCPQueue=true
   [junit4]   2> 1533177 INFO  
(OverseerThreadFactory-7913-thread-5-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.CreateShardCmd Create shard invoked: {
   [junit4]   2>   "collection":"policiesTest",
   [junit4]   2>   "shard":"s3",
   [junit4]   2>   "operation":"createshard"}
   [junit4]   2> 1533181 INFO  (qtp6343403-16463) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1533183 INFO  (qtp14629123-16492) [n:127.0.0.1:45137_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1533185 INFO  (qtp33428153-16468) [n:127.0.0.1:44285_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1533186 INFO  (qtp5550408-16488) [n:127.0.0.1:41939_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1533188 INFO  (qtp12868722-16462) [n:127.0.0.1:35063_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1533291 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1533291 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1534190 INFO  
(OverseerThreadFactory-7913-thread-5-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.CreateShardCmd Creating replica 
policiesTest_s3_replica_n1 as part of slice s3 of collection policiesTest on 
127.0.0.1:37879_solr
   [junit4]   2> 1534190 INFO  
(OverseerThreadFactory-7913-thread-5-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.AddReplicaCmd addReplica() : {
   [junit4]   2>   "collection":"policiesTest",
   [junit4]   2>   "shard":"s3",
   [junit4]   2>   "replicaType":"NRT",
   [junit4]   2>   "node":"127.0.0.1:37879_solr",
   [junit4]   2>   "name":"policiesTest_s3_replica_n1"}
   [junit4]   2> 1534194 INFO  (qtp6343403-16484) [n:127.0.0.1:37879_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1534196 INFO  (qtp14629123-16494) [n:127.0.0.1:45137_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1534197 INFO  (qtp33428153-16472) [n:127.0.0.1:44285_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1534203 INFO  (qtp5550408-16506) [n:127.0.0.1:41939_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1534204 INFO  (qtp12868722-16478) [n:127.0.0.1:35063_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 1534205 INFO  
(OverseerThreadFactory-7913-thread-5-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.AddReplicaCmd Node Identified 
127.0.0.1:37879_solr for creating new replica
   [junit4]   2> 1534206 INFO  
(OverseerStateUpdate-98216716341673999-127.0.0.1:35063_solr-n_0000000000) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"addreplica",
   [junit4]   2>   "collection":"policiesTest",
   [junit4]   2>   "shard":"s3",
   [junit4]   2>   "core":"policiesTest_s3_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:37879/solr";,
   [junit4]   2>   "node_name":"127.0.0.1:37879_solr",
   [junit4]   2>   "type":"NRT"} 
   [junit4]   2> 1534307 INFO  
(zkCallback-2826-thread-1-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1534307 INFO  
(zkCallback-2826-thread-2-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader A cluster state change: 
[WatchedEvent state:SyncConnected type:NodeDataChanged 
path:/collections/policiesTest/state.json] for collection [policiesTest] has 
occurred - updating... (live nodes size: [5])
   [junit4]   2> 1534408 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr    ] 
o.a.s.h.a.CoreAdminOperation core create command 
qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&name=policiesTest_s3_replica_n1&action=CREATE&collection=policiesTest&shard=s3&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1534416 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 1534422 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.s.IndexSchema [policiesTest_s3_replica_n1] Schema name=minimal
   [junit4]   2> 1534425 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 1534425 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'policiesTest_s3_replica_n1' using 
configuration from collection policiesTest, trusted=true
   [junit4]   2> 1534426 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_37879.solr.core.policiesTest.s3.replica_n1' (registry 
'solr.core.policiesTest.s3.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@13e06fe
   [junit4]   2> 1534426 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 1534426 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] o.a.s.c.SolrCore 
[[policiesTest_s3_replica_n1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/policiesTest_s3_replica_n1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001/tempDir-001/node2/./policiesTest_s3_replica_n1/data/]
   [junit4]   2> 1534473 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1534473 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1534474 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1534474 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1534475 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@3ccb3f[policiesTest_s3_replica_n1] 
main]
   [junit4]   2> 1534478 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf
   [junit4]   2> 1534478 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 1534478 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1534479 INFO  (qtp6343403-16460) [n:127.0.0.1:37879_solr 
c:policiesTest s:s3 r:core_node3 x:policiesTest_s3_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1571467472410771456
   [junit4]   2> 1534479 INFO  
(searcherExecutor-7944-thread-1-processing-n:127.0.0.1:37879_solr 
x:policiesTest_s3_replica_n1 s:s3 c:policiesTest r:core_node3) 
[n:127.0.0.1:37879_solr c:policiesTest s:s3 r:core_node3 
x:policiesTest_s3_replica_n1] o.a.s.c.SolrCore [policiesTest_s3_replica_n1] 
Registered new searcher Searcher@3ccb3

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

.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
   [junit4]   2>        at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
   [junit4]   2>        at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 1727200 INFO  (qtp33428153-16466) [n:127.0.0.1:44285_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={nodeName=127.0.0.1:44285_solr&onlyIfLeaderActive=true&core=testCreateCollectionAddReplica_shard1_replica_n1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
 status=400 QTime=10001
   [junit4]   2> 1728462 WARN  
(zkCallback-2826-thread-3-processing-n:127.0.0.1:37879_solr) 
[n:127.0.0.1:37879_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1728462 INFO  (jetty-closer-2804-thread-2) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@eee046{/solr,null,UNAVAILABLE}
   [junit4]   2> 1756994 ERROR 
(OverseerThreadFactory-7913-thread-5-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.OverseerCollectionMessageHandler 
Collection: testCreateCollectionAddReplica operation: delete 
failed:org.apache.solr.common.SolrException: Could not fully remove collection: 
testCreateCollectionAddReplica
   [junit4]   2>        at 
org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:106)
   [junit4]   2>        at 
org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:233)
   [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:1142)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 1756995 INFO  
(OverseerThreadFactory-7913-thread-5-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000022 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 1758496 WARN  
(zkCallback-2830-thread-5-processing-n:127.0.0.1:35063_solr) 
[n:127.0.0.1:35063_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1758496 INFO  (jetty-closer-2804-thread-5) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@f5fae1{/solr,null,UNAVAILABLE}
   [junit4]   2> 1758496 ERROR 
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-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> 1758497 INFO  
(SUITE-TestPolicyCloud-seed#[7D4BB7647B75CFAC]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:35703 35703
   [junit4]   2> 1758532 INFO  (Thread-3577) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:35703 35703
   [junit4]   2> 1758532 WARN  (Thread-3577) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        13      /solr/aliases.json
   [junit4]   2>        6       /solr/configs/conf
   [junit4]   2>        5       /solr/security.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        31      
/solr/collections/testCreateCollectionSplitShard/state.json
   [junit4]   2>        22      /solr/collections/policiesTest/state.json
   [junit4]   2>        13      /solr/clusterprops.json
   [junit4]   2>        13      /solr/clusterstate.json
   [junit4]   2>        7       
/solr/collections/testCreateCollectionAddReplica/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        25      /solr/collections
   [junit4]   2>        13      /solr/live_nodes
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TestPolicyCloud_7D4BB7647B75CFAC-001
   [junit4]   2> Jun 28, 2017 4:46:31 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): {}, 
docValues:{}, maxPointsInLeafNode=705, maxMBSortInHeap=6.896626321966785, 
sim=RandomSimilarity(queryNorm=false): {}, locale=he-IL, 
timezone=Africa/Lubumbashi
   [junit4]   2> NOTE: Linux 4.10.0-21-generic i386/Oracle Corporation 
1.8.0_131 (32-bit)/cpus=8,threads=1,free=228916648,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: 
[DistributedIntervalFacetingTest, TestCharFilters, 
LeaderElectionContextKeyTest, TestHdfsBackupRestoreCore, OverseerStatusTest, 
ConfigSetsAPITest, SegmentsInfoRequestHandlerTest, TestLFUCache, 
TestStressVersions, LukeRequestHandlerTest, TestSchemaNameResource, 
TestDistribIDF, SolrCLIZkUtilsTest, OpenCloseCoreStressTest, 
DocumentBuilderTest, DistanceFunctionTest, TestSolrXml, 
PKIAuthenticationIntegrationTest, TestCryptoKeys, ZkCLITest, ZkControllerTest, 
DistributedTermsComponentTest, DocValuesTest, TestBulkSchemaAPI, 
TestTlogReplica, AddBlockUpdateTest, EchoParamsTest, 
SchemaVersionSpecificBehaviorTest, RankQueryTest, TestSolrDeletionPolicy2, 
ChaosMonkeyNothingIsSafeTest, ActionThrottleTest, BadComponentTest, 
TestSimpleTrackingShardHandler, TestDocBasedVersionConstraints, 
TestMaxTokenLenTokenizer, HdfsWriteToMultipleCollectionsTest, 
DocValuesNotIndexedTest, ClusterStateTest, TestSystemIdResolver, 
IgnoreCommitOptimizeUpdateProcessorFactoryTest, 
SharedFSAutoReplicaFailoverTest, TestSchemaVersionResource, 
CollectionReloadTest, TestClassicSimilarityFactory, TimeZoneUtilsTest, 
SoftAutoCommitTest, SolrPluginUtilsTest, TestJavabinTupleStreamParser, 
ShardRoutingTest, TestLRUStatsCache, TestSolrCLIRunExample, 
TestPHPSerializedResponseWriter, MetricUtilsTest, TestDistributedGrouping, 
TestConfigSetsAPI, RuleEngineTest, RequiredFieldsTest, 
UpdateRequestProcessorFactoryTest, ZkNodePropsTest, ScriptEngineTest, 
SolrCmdDistributorTest, TestCollationFieldDocValues, 
HdfsCollectionsAPIDistributedZkTest, CopyFieldTest, TestElisionMultitermQuery, 
AlternateDirectoryTest, TestFiltering, AutoScalingHandlerTest, 
TlogReplayBufferedWhileIndexingTest, ZkStateReaderTest, TestPullReplica, 
AnalysisAfterCoreReloadTest, TestStressUserVersions, 
TestLocalFSCloudBackupRestore, SpatialHeatmapFacetsTest, TestCloudRecovery, 
TestInitParams, TestLegacyTerms, TestXmlQParserPlugin, SmileWriterTest, 
UninvertDocValuesMergePolicyTest, DisMaxRequestHandlerTest, 
TestRuleBasedAuthorizationPlugin, TestDistributedStatsComponentCardinality, 
ZkSolrClientTest, TestGraphTermsQParserPlugin, HdfsThreadLeakTest, 
ClusterStateUpdateTest, TestExportWriter, SpellCheckComponentTest, 
CurrencyFieldTypeTest, DeleteNodeTest, TestHashPartitioner, 
TestFreeTextSuggestions, TestWriterPerf, QueryParsingTest, TestJsonRequest, 
ClassificationUpdateProcessorTest, TestLeaderElectionWithEmptyReplica, 
TestFieldResource, CustomCollectionTest, 
StatelessScriptUpdateProcessorFactoryTest, SubstringBytesRefFilterTest, 
AsyncCallRequestStatusResponseTest, TestPayloadCheckQParserPlugin, 
TestConfigSets, TestSolrConfigHandlerCloud, CdcrReplicationDistributedZkTest, 
TestRandomRequestDistribution, DistributedFacetPivotSmallTest, TestLegacyField, 
TestSchemaManager, TestFieldCacheReopen, BlockJoinFacetSimpleTest, 
CoreSorterTest, TestMinMaxOnMultiValuedField, TestCoreDiscovery, 
CollectionsAPIDistributedZkTest, TestZkChroot, ShardRoutingCustomTest, 
TestDistributedSearch, AutoCommitTest, TestStressReorder, HardAutoCommitTest, 
TestCoreContainer, SimpleFacetsTest, TestSolr4Spatial, 
QueryElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort, 
TestIndexSearcher, SuggesterFSTTest, SuggesterTSTTest, SuggesterTest, 
SpatialFilterTest, TestCSVLoader, WordBreakSolrSpellCheckerTest, TestUpdate, 
DirectUpdateHandlerOptimizeTest, DocValuesMultiTest, SolrInfoBeanTest, 
DebugComponentTest, TestSurroundQueryParser, TestQueryUtils, TestQueryTypes, 
FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, 
TestIndexingPerformance, FieldAnalysisRequestHandlerTest, LoggingHandlerTest, 
TestCollationField, TestCSVResponseWriter, JsonLoaderTest, 
CSVRequestHandlerTest, TestComponentsName, TestQuerySenderListener, 
UpdateParamsTest, TestSolrIndexConfig, ResponseLogComponentTest, 
TestStressRecovery, ExternalFileFieldSortTest, DirectSolrConnectionTest, 
TestLuceneMatchVersion, SpellPossibilityIteratorTest, SynonymTokenizerTest, 
TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, 
PluginInfoTest, TestSuggestSpellingConverter, TestSolrJ, TestUtils, 
UUIDFieldTest, DistributedMLTComponentTest, TestEmbeddedSolrServerConstructors, 
AliasIntegrationTest, ChaosMonkeySafeLeaderWithPullReplicasTest, 
DeleteInactiveReplicaTest, DeleteShardTest, DistributedVersionInfoTest, 
LeaderFailureAfterFreshStartTest, LeaderInitiatedRecoveryOnCommitTest, 
MissingSegmentRecoveryTest, MoveReplicaTest, 
OutOfBoxZkACLAndCredentialsProvidersTest, 
OverseerCollectionConfigSetProcessorTest, RemoteQueryErrorTest, 
ReplaceNodeTest, ReplicationFactorTest, RestartWhileUpdatingTest, 
RollingRestartTest, TestCloudDeleteByQuery, TestCollectionAPI, 
TestSSLRandomization, TestSolrCloudWithKerberosAlt, 
VMParamsZkACLAndCredentialsProvidersTest, TestPolicyCloud]
   [junit4] Completed [669/724 (1!)] on J1 in 235.02s, 4 tests, 1 error <<< 
FAILURES!

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

Reply via email to