You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2016/10/28 11:38:15 UTC
[JENKINS] Lucene-Solr-master-Linux (32bit/jdk1.8.0_102) - Build #
18160 - Failure!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18160/
Java: 32bit/jdk1.8.0_102 -client -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionReload
Error Message:
Error from server at http://127.0.0.1:39698/solr: Error handling 'status' action
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:39698/solr: Error handling 'status' action
at __randomizedtesting.SeedInfo.seed([2993885EFB7FDAE4:282AA4602EF0757B]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:610)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:262)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:251)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:149)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:166)
at org.apache.solr.client.solrj.request.CoreAdminRequest.getStatus(CoreAdminRequest.java:633)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.collectStartTimes(CollectionsAPIDistributedZkTest.java:595)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.waitForReloads(CollectionsAPIDistributedZkTest.java:563)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionReload(CollectionsAPIDistributedZkTest.java:535)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11614 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/init-core-data-001
[junit4] 2> 891523 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 891524 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001
[junit4] 2> 891524 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 891524 INFO (Thread-1842) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 891524 INFO (Thread-1842) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 891624 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:40451
[junit4] 2> 891633 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 891633 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 891633 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 891633 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
[junit4] 2> 891634 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5fe13{/solr,null,AVAILABLE}
[junit4] 2> 891634 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@236325{/solr,null,AVAILABLE}
[junit4] 2> 891634 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@12ff696{/solr,null,AVAILABLE}
[junit4] 2> 891635 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@492a4f{/solr,null,AVAILABLE}
[junit4] 2> 891636 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.ServerConnector Started ServerConnector@120a707{HTTP/1.1,[http/1.1]}{127.0.0.1:43056}
[junit4] 2> 891636 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.ServerConnector Started ServerConnector@c2fb12{HTTP/1.1,[http/1.1]}{127.0.0.1:39698}
[junit4] 2> 891636 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.Server Started @892944ms
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.Server Started @892944ms
[junit4] 2> 891636 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.ServerConnector Started ServerConnector@10815f5{HTTP/1.1,[http/1.1]}{127.0.0.1:43627}
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39698}
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.Server Started @892944ms
[junit4] 2> 891636 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.ServerConnector Started ServerConnector@4c881a{HTTP/1.1,[http/1.1]}{127.0.0.1:44269}
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43627}
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.Server Started @892944ms
[junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44269}
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43056}
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.303Z
[junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 891638 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.304Z
[junit4] 2> 891638 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.304Z
[junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.304Z
[junit4] 2> 891640 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 891640 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 891641 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 891641 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 891658 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 0x1580b00f9f70001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 891658 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 0x1580b00f9f70002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 891661 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
[junit4] 2> 891661 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
[junit4] 2> 891661 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
[junit4] 2> 891661 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
[junit4] 2> 891664 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 0x1580b00f9f70006, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 891664 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 0x1580b00f9f70007, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 891665 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 0x1580b00f9f70008, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 891686 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44269_solr
[junit4] 2> 891686 INFO (jetty-launcher-1506-thread-2) [n:127.0.0.1:43056_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43056_solr
[junit4] 2> 891686 INFO (jetty-launcher-1506-thread-1) [n:127.0.0.1:39698_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39698_solr
[junit4] 2> 891686 INFO (jetty-launcher-1506-thread-4) [n:127.0.0.1:43627_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43627_solr
[junit4] 2> 891687 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_solr ] o.a.s.c.Overseer Overseer (id=96839490810085386-127.0.0.1:44269_solr-n_0000000000) starting
[junit4] 2> 891688 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 891688 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 891688 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 891688 INFO (zkCallback-1527-thread-1-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 891689 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 891689 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 891692 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 891696 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 891698 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44269_solr
[junit4] 2> 891700 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 891700 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 891700 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 891700 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 891747 INFO (jetty-launcher-1506-thread-4) [n:127.0.0.1:43627_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/.
[junit4] 2> 891750 INFO (jetty-launcher-1506-thread-2) [n:127.0.0.1:43056_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/.
[junit4] 2> 891823 INFO (jetty-launcher-1506-thread-1) [n:127.0.0.1:39698_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node1/.
[junit4] 2> 891843 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/.
[junit4] 2> 891849 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 891875 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection
[junit4] 2> 891876 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[2993885EFB7FDAE4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 891878 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
[junit4] 2> 894879 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2
[junit4] 2> 894881 INFO (OverseerStateUpdate-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 895892 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 895902 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 895906 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 895907 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection
[junit4] 2> 895908 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-002/]
[junit4] 2> 895917 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 895917 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 895918 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 895918 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 895918 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@14b80ea[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 895919 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 895920 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 895920 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 895920 INFO (searcherExecutor-3515-thread-1-processing-n:127.0.0.1:44269_solr x:halfdeletedcollection_shard1_replica1 s:shard2 c:halfdeletedcollection r:core_node1) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@14b80ea[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 895920 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431857569857536
[junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44269/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:44269/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 895928 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44269/solr/halfdeletedcollection_shard1_replica1/ shard2
[junit4] 2> 896078 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 896080 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2} status=0 QTime=4202
[junit4] 2> 896081 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 896082 INFO (OverseerThreadFactory-3506-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 896084 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1de358b
[junit4] 2> 896086 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 896792 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=711
[junit4] 2> 896793 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 896793 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 896794 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 896796 INFO (OverseerThreadFactory-3506-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.CreateCollectionCmd Create collection halfdeletedcollection
[junit4] 2> 896796 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 897001 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
[junit4] 2> 897001 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
[junit4] 2> 900001 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2
[junit4] 2> 900002 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2
[junit4] 2> 900005 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 900005 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 900108 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 900108 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 901015 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 901015 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 901025 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica1] Schema name=minimal
[junit4] 2> 901025 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 901030 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 901030 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 901031 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard2_replica1' using configuration from collection halfdeletedcollection
[junit4] 2> 901031 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection
[junit4] 2> 901032 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/halfdeletedcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/./halfdeletedcollection_shard2_replica1/data/]
[junit4] 2> 901032 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/./halfdeletedcollection_shard1_replica1/data/]
[junit4] 2> 901042 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 901042 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 901043 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 901043 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 901044 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 901044 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 901044 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 901044 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 901044 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@96a92d[halfdeletedcollection_shard2_replica1] main]
[junit4] 2> 901044 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1dd013a[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 901045 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 901045 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 901045 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 901045 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 901045 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 901045 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 901045 INFO (searcherExecutor-3520-thread-1-processing-n:127.0.0.1:43627_solr x:halfdeletedcollection_shard2_replica1 s:shard2 c:halfdeletedcollection r:core_node1) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] Registered new searcher Searcher@96a92d[halfdeletedcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 901045 INFO (searcherExecutor-3521-thread-1-processing-n:127.0.0.1:43056_solr x:halfdeletedcollection_shard1_replica1 s:shard1 c:halfdeletedcollection r:core_node2) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@1dd013a[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 901046 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431862944858112
[junit4] 2> 901046 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431862944858112
[junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43627/solr/halfdeletedcollection_shard2_replica1/
[junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43056/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:43627/solr/halfdeletedcollection_shard2_replica1/ has no replicas
[junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:43056/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 901056 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43627/solr/halfdeletedcollection_shard2_replica1/ shard2
[junit4] 2> 901056 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43056/solr/halfdeletedcollection_shard1_replica1/ shard1
[junit4] 2> 901159 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 901159 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 901207 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 901207 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 901208 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=4207
[junit4] 2> 901208 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=4207
[junit4] 2> 901210 INFO (qtp13402862-7889) [n:127.0.0.1:44269_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> 901311 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 901311 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 902211 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=5417
[junit4] 2> 902212 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 902212 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 902213 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deletePartiallyCreatedCollection
[junit4] 2> 902237 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSpecificConfigsets
[junit4] 2> 902238 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[2993885EFB7FDAE4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 902238 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 902243 INFO (OverseerThreadFactory-3506-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 902243 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 902245 INFO (qtp6349842-7897) [n:127.0.0.1:43056_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@188aed
[junit4] 2> 902246 INFO (qtp18156234-7912) [n:127.0.0.1:43627_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4d4832
[junit4] 2> 902249 INFO (qtp6349842-7897) [n:127.0.0.1:43056_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 902249 INFO (qtp18156234-7912) [n:127.0.0.1:43627_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 902953 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=714
[junit4] 2> 902954 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 902955 INFO (OverseerThreadFactory-3506-thread-4-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.CreateCollectionCmd Create collection withconfigset2
[junit4] 2> 902955 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 903160 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2
[junit4] 2> 903263 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 904184 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 904192 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.IndexSchema [withconfigset2_shard1_replica1] Schema name=minimal
[junit4] 2> 904195 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 904196 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'withconfigset2_shard1_replica1' using configuration from collection withconfigset2
[junit4] 2> 904196 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrCore [[withconfigset2_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/withconfigset2_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/./withconfigset2_shard1_replica1/data/]
[junit4] 2> 904196 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cd9321
[junit4] 2> 904216 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 904216 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 904217 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 904217 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 904218 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1ed9f9c[withconfigset2_shard1_replica1] main]
[junit4] 2> 904219 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2
[junit4] 2> 904219 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2
[junit4] 2> 904219 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 904220 INFO (searcherExecutor-3530-thread-1-processing-n:127.0.0.1:44269_solr x:withconfigset2_shard1_replica1 s:shard1 c:withconfigset2 r:core_node1) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] Registered new searcher Searcher@1ed9f9c[withconfigset2_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 904220 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431866273038336
[junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44269/solr/withconfigset2_shard1_replica1/
[junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:44269/solr/withconfigset2_shard1_replica1/ has no replicas
[junit4] 2> 904227 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44269/solr/withconfigset2_shard1_replica1/ shard1
[junit4] 2> 904328 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 904377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 904379 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2} status=0 QTime=1219
[junit4] 2> 904381 INFO (qtp13402862-7909) [n:127.0.0.1:44269_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> 904481 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 904957 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 905382 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2427
[junit4] 2> 905382 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSpecificConfigsets
[junit4] 2> 905402 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCollectionReload
[junit4] 2> 905403 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[2993885EFB7FDAE4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 905404 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=withconfigset2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 905405 INFO (OverseerThreadFactory-3506-thread-5-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 905407 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@e5cace
[junit4] 2> 905428 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=withconfigset2_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=21
[junit4] 2> 906132 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=withconfigset2&action=DELETE&wt=javabin&version=2} status=0 QTime=728
[junit4] 2> 906133 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=reloaded_collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 906134 INFO (OverseerThreadFactory-3506-thread-5-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.CreateCollectionCmd Create collection reloaded_collection
[junit4] 2> 906134 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 906339 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
[junit4] 2> 906339 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
[junit4] 2> 906340 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2
[junit4] 2> 906341 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
[junit4] 2> 906443 INFO (zkCallback-1525-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 907352 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 907361 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica2] Schema name=minimal
[junit4] 2> 907364 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 907365 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard2_replica2' using configuration from collection reloaded_collection
[junit4] 2> 907366 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/reloaded_collection_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/./reloaded_collection_shard2_replica2/data/]
[junit4] 2> 907374 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 907374 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 907376 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 907376 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 907376 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@43810e[reloaded_collection_shard2_replica2] main]
[junit4] 2> 907377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 907377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 907377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 907378 INFO (searcherExecutor-3535-thread-1-processing-n:127.0.0.1:44269_solr x:reloaded_collection_shard2_replica2 s:shard2 c:reloaded_collection r:core_node1) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [reloaded_collection_shard2_replica2] Registered new searcher Searcher@43810e[reloaded_collection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 907378 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431869584441344
[junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44269/solr/reloaded_collection_shard2_replica2/
[junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SyncStrategy http://127.0.0.1:44269/solr/reloaded_collection_shard2_replica2/ has no replicas
[junit4] 2> 907386 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44269/solr/reloaded_collection_shard2_replica2/ shard2
[junit4] 2> 907488 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 907537 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 907539 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=1198
[junit4] 2> 907640 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 909339 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2
[junit4] 2> 909340 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2
[junit4] 2> 909342 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2
[junit4] 2> 909342 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 909342 INFO (zkCallback-1525-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 909342 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 909448 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 909448 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 909448 INFO (zkCallback-1525-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 909448 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 910350 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 910352 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 910353 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 910369 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica2] Schema name=minimal
[junit4] 2> 910370 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica1] Schema name=minimal
[junit4] 2> 910370 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica1] Schema name=minimal
[junit4] 2> 910373 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 910373 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 910373 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 910374 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard1_replica2' using configuration from collection reloaded_collection
[junit4] 2> 910374 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard2_replica1' using configuration from collection reloaded_collection
[junit4] 2> 910374 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard1_replica1' using configuration from collection reloaded_collection
[junit4] 2> 910374 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node1/reloaded_collection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node1/./reloaded_collection_shard2_replica1/data/]
[junit4] 2> 910374 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/reloaded_collection_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/./reloaded_collection_shard1_replica2/data/]
[junit4] 2> 910374 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/reloaded_collection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/./reloaded_collection_shard1_replica1/data/]
[junit4] 2> 910385 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 910385 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 910385 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 910385 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 910385 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 910385 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 910386 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 910386 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 910386 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 910386 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 910386 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 910386 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 910386 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@8133a3[reloaded_collection_shard1_replica2] main]
[junit4] 2> 910386 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@12c5eaf[reloaded_collection_shard2_replica1] main]
[junit4] 2> 910387 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@10370de[reloaded_collection_shard1_replica1] main]
[junit4] 2> 910388 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 910388 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 910389 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 910389 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 910389 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 910389 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 910389 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 910389 INFO (searcherExecutor-3541-thread-1-processing-n:127.0.0.1:39698_solr x:reloaded_collection_shard2_replica1 s:shard2 c:reloaded_collection r:core_node2) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [reloaded_collection_shard2_replica1] Registered new searcher Searcher@12c5eaf[reloaded_collection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 910389 INFO (searcherExecutor-3540-thread-1-processing-n:127.0.0.1:43056_solr x:reloaded_collection_shard1_replica2 s:shard1 c:reloaded_collection r:core_node3) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [reloaded_collection_shard1_replica2] Registered new searcher Searcher@8133a3[reloaded_collection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 910389 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431872741703680
[junit4] 2> 910389 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431872741703680
[junit4] 2> 910389 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 910389 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 910390 INFO (searcherExecutor-3542-thread-1-processing-n:127.0.0.1:43627_solr x:reloaded_collection_shard1_replica1 s:shard1 c:reloaded_collection r:core_node4) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [reloaded_collection_shard1_replica1] Registered new searcher Searcher@10370de[reloaded_collection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 910390 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431872742752256
[junit4] 2> 910395 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=4056
[junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43627/solr/reloaded_collection_shard1_replica1/
[junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard1_replica1 url=http://127.0.0.1:43627/solr START replicas=[http://127.0.0.1:43056/solr/reloaded_collection_shard1_replica2/] nUpdates=100
[junit4] 2> 910396 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard1_replica1 url=http://127.0.0.1:43627/solr DONE. We have no versions. sync failed.
[junit4] 2> 910397 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.c.S.Request [reloaded_collection_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 910397 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 910397 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloa
[...truncated too long message...]
(coreCloseExecutor-3751-thread-1) [n:127.0.0.1:43056_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@1469cc6
[junit4] 2> 1030781 INFO (jetty-launcher-1506-thread-8) [ ] o.a.s.c.Overseer Overseer (id=96839490810085386-127.0.0.1:44269_solr-n_0000000000) closing
[junit4] 2> 1030782 INFO (OverseerStateUpdate-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44269_solr
[junit4] 2> 1030782 INFO (coreCloseExecutor-3754-thread-1) [n:127.0.0.1:39698_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@15fdfe7
[junit4] 2> 1030786 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:40451) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x1580b00f9f7000c, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1030786 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (2)
[junit4] 2> 1030786 INFO (zkCallback-1526-thread-3-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (2)
[junit4] 2> 1030787 INFO (zkCallback-1526-thread-2-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43056_solr
[junit4] 2> 1030787 WARN (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1030787 WARN (zkCallback-1526-thread-4-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1030787 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:40451) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x1580b00f9f7000b, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1030787 INFO (jetty-launcher-1506-thread-7) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5fe13{/solr,null,UNAVAILABLE}
[junit4] 2> 1032286 WARN (zkCallback-1525-thread-8-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1032286 WARN (zkCallback-1527-thread-6-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1032286 INFO (jetty-launcher-1506-thread-5) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@492a4f{/solr,null,UNAVAILABLE}
[junit4] 2> 1032286 INFO (jetty-launcher-1506-thread-8) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@12ff696{/solr,null,UNAVAILABLE}
[junit4] 2> 1032287 INFO (jetty-launcher-1506-thread-6) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@236325{/solr,null,UNAVAILABLE}
[junit4] 2> 1032288 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40451 40451
[junit4] 2> 1032293 INFO (Thread-1891) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40451 40451
[junit4] 2> 1032294 WARN (Thread-1891) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 6 /solr/configs/conf
[junit4] 2> 6 /solr/clusterprops.json
[junit4] 2> 6 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 339 /solr/clusterstate.json
[junit4] 2> 3 /solr/collections/acollectionafterbaddelete/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 290 /solr/collections
[junit4] 2> 48 /solr/overseer/collection-queue-work
[junit4] 2> 36 /solr/overseer/queue
[junit4] 2> 10 /solr/overseer/queue-work
[junit4] 2> 6 /solr/live_nodes
[junit4] 2>
[junit4] 2> 1032294 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001
[junit4] 2> Oct 28, 2016 11:18:23 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{}, maxPointsInLeafNode=342, maxMBSortInHeap=7.06019445196937, sim=ClassicSimilarity, locale=et, timezone=Pacific/Chuuk
[junit4] 2> NOTE: Linux 4.4.0-42-generic i386/Oracle Corporation 1.8.0_102 (32-bit)/cpus=12,threads=1,free=238609504,total=347602944
[junit4] 2> NOTE: All tests run in this JVM: [SOLR749Test, TestSolrConfigHandler, SpellingQueryConverterTest, IndexBasedSpellCheckerTest, GraphQueryTest, SoftAutoCommitTest, QueryParsingTest, SolrCloudExampleTest, TestGraphTermsQParserPlugin, ConfigSetsAPITest, SolrCmdDistributorTest, DOMUtilTest, TestMiniSolrCloudCluster, CollectionReloadTest, TestManagedSchemaAPI, TestQueryTypes, TestStressVersions, HdfsRecoveryZkTest, TestFileDictionaryLookup, SuggestComponentContextFilterQueryTest, TestJettySolrRunner, TestDistribDocBasedVersion, RemoteQueryErrorTest, DocumentBuilderTest, TestReplicationHandlerBackup, BigEndianAscendingWordSerializerTest, AtomicUpdatesTest, TestFuzzyAnalyzedSuggestions, HdfsBasicDistributedZkTest, TestNRTOpen, TestUseDocValuesAsStored, ConjunctionSolrSpellCheckerTest, SparseHLLTest, TriLevelCompositeIdRoutingTest, TestCloudSchemaless, DeleteNodeTest, TestTestInjection, SpatialFilterTest, SortByFunctionTest, TestSolrCloudWithSecureImpersonation, DistribJoinFromCollectionTest, DirectSolrSpellCheckerTest, HdfsDirectoryTest, SolrIndexSplitterTest, SimplePostToolTest, TermsComponentTest, TestBlobHandler, TestManagedResource, BlockJoinFacetDistribTest, TestSubQueryTransformer, DistributedTermsComponentTest, TestFieldCacheSort, SharedFSAutoReplicaFailoverUtilsTest, HighlighterTest, TestCollectionAPI, ShardRoutingCustomTest, TestJsonFacetRefinement, PKIAuthenticationIntegrationTest, HdfsThreadLeakTest, TestOrdValues, TestRequestStatusCollectionAPI, TestCharFilters, TestPostingsSolrHighlighter, TestCoreContainer, TestFiltering, TestGraphMLResponseWriter, LoggingHandlerTest, ZkSolrClientTest, DocExpirationUpdateProcessorFactoryTest, TestNumericTerms64, OpenExchangeRatesOrgProviderTest, AnalysisErrorHandlingTest, JavabinLoaderTest, RuleEngineTest, TestTrieFacet, TestFieldTypeResource, CoreMergeIndexesAdminHandlerTest, TestSimpleQParserPlugin, CdcrReplicationHandlerTest, TestCustomSort, TestDefaultSearchFieldResource, TestJsonRequest, SampleTest, WordBreakSolrSpellCheckerTest, TestDocumentBuilder, ZkStateReaderTest, IndexSchemaTest, LeaderInitiatedRecoveryOnShardRestartTest, TestLRUStatsCache, TestSolrConfigHandlerConcurrent, TestFieldCacheWithThreads, TestBulkSchemaConcurrent, SpellCheckCollatorTest, TestRandomCollapseQParserPlugin, TestFieldCollectionResource, JsonLoaderTest, SaslZkACLProviderTest, TestQueryUtils, TestCloudDeleteByQuery, TestBinaryResponseWriter, ChaosMonkeyNothingIsSafeTest, RestartWhileUpdatingTest, DistributedMLTComponentTest, BlockCacheTest, TestHdfsUpdateLog, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
[junit4] Completed [320/647 (1!)] on J1 in 141.05s, 20 tests, 1 error <<< FAILURES!
[...truncated 12167 lines...]
-validate-source-patterns:
[source-patterns] nocommit: solr/core/src/test/org/apache/solr/cloud/RecoveryZkTest.java
[source-patterns] invalid logging pattern [not private static final, uses static class name]: solr/core/src/test/org/apache/solr/cloud/RecoveryZkTest.java
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:765: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:130: Found 2 violations in source files (invalid logging pattern [not private static final, uses static class name], nocommit).
Total time: 67 minutes 6 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
Re: [JENKINS] Lucene-Solr-master-Linux (32bit/jdk1.8.0_102) - Build # 18160 - Failure!
Posted by Alan Woodward <al...@flax.co.uk>.
This is an interesting one… if we request a CoreStatus during a core reload, then LukeRequestHandler can find that the IndexWriter it uses to get some information is closed in the middle of the operation, throwing an error.
The test fix is to just not request indexinfo when getting the status. I’ll open a JIRA for a proper fix to the CoreStatus op.
Alan Woodward
www.flax.co.uk
> On 28 Oct 2016, at 12:38, Policeman Jenkins Server <je...@thetaphi.de> wrote:
>
> Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/18160/
> Java: 32bit/jdk1.8.0_102 -client -XX:+UseParallelGC
>
> 1 tests failed.
> FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionReload
>
> Error Message:
> Error from server at http://127.0.0.1:39698/solr: Error handling 'status' action
>
> Stack Trace:
> org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:39698/solr: Error handling 'status' action
> at __randomizedtesting.SeedInfo.seed([2993885EFB7FDAE4:282AA4602EF0757B]:0)
> at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:610)
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:262)
> at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:251)
> at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:149)
> at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:166)
> at org.apache.solr.client.solrj.request.CoreAdminRequest.getStatus(CoreAdminRequest.java:633)
> at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.collectStartTimes(CollectionsAPIDistributedZkTest.java:595)
> at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.waitForReloads(CollectionsAPIDistributedZkTest.java:563)
> at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionReload(CollectionsAPIDistributedZkTest.java:535)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:811)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462)
> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
> at java.lang.Thread.run(Thread.java:745)
>
>
>
>
> Build Log:
> [...truncated 11614 lines...]
> [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
> [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/init-core-data-001
> [junit4] 2> 891523 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
> [junit4] 2> 891524 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001
> [junit4] 2> 891524 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
> [junit4] 2> 891524 INFO (Thread-1842) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
> [junit4] 2> 891524 INFO (Thread-1842) [ ] o.a.s.c.ZkTestServer Starting server
> [junit4] 2> 891624 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:40451
> [junit4] 2> 891633 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
> [junit4] 2> 891633 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
> [junit4] 2> 891633 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
> [junit4] 2> 891633 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.Server jetty-9.3.8.v20160314
> [junit4] 2> 891634 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5fe13{/solr,null,AVAILABLE}
> [junit4] 2> 891634 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@236325{/solr,null,AVAILABLE}
> [junit4] 2> 891634 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@12ff696{/solr,null,AVAILABLE}
> [junit4] 2> 891635 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@492a4f{/solr,null,AVAILABLE}
> [junit4] 2> 891636 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.ServerConnector Started ServerConnector@120a707{HTTP/1.1,[http/1.1]}{127.0.0.1:43056}
> [junit4] 2> 891636 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.ServerConnector Started ServerConnector@c2fb12{HTTP/1.1,[http/1.1]}{127.0.0.1:39698}
> [junit4] 2> 891636 INFO (jetty-launcher-1506-thread-2) [ ] o.e.j.s.Server Started @892944ms
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.e.j.s.Server Started @892944ms
> [junit4] 2> 891636 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.ServerConnector Started ServerConnector@10815f5{HTTP/1.1,[http/1.1]}{127.0.0.1:43627}
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39698}
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.e.j.s.Server Started @892944ms
> [junit4] 2> 891636 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.ServerConnector Started ServerConnector@4c881a{HTTP/1.1,[http/1.1]}{127.0.0.1:44269}
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43627}
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.e.j.s.Server Started @892944ms
> [junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44269}
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43056}
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 891637 ERROR (jetty-launcher-1506-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.303Z
> [junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 891637 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 891638 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.304Z
> [junit4] 2> 891638 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.304Z
> [junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
> [junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
> [junit4] 2> 891638 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-28T11:16:03.304Z
> [junit4] 2> 891640 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 891640 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 891641 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 891641 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
> [junit4] 2> 891658 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 0x1580b00f9f70001, likely client has closed socket
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
> [junit4] 2> at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> 891658 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 0x1580b00f9f70002, likely client has closed socket
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
> [junit4] 2> at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> 891661 INFO (jetty-launcher-1506-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
> [junit4] 2> 891661 INFO (jetty-launcher-1506-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
> [junit4] 2> 891661 INFO (jetty-launcher-1506-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
> [junit4] 2> 891661 INFO (jetty-launcher-1506-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40451/solr
> [junit4] 2> 891664 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 0x1580b00f9f70006, likely client has closed socket
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
> [junit4] 2> at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> 891664 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 0x1580b00f9f70007, likely client has closed socket
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
> [junit4] 2> at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> 891665 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 0x1580b00f9f70008, likely client has closed socket
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
> [junit4] 2> at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> 891686 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44269_solr
> [junit4] 2> 891686 INFO (jetty-launcher-1506-thread-2) [n:127.0.0.1:43056_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43056_solr
> [junit4] 2> 891686 INFO (jetty-launcher-1506-thread-1) [n:127.0.0.1:39698_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39698_solr
> [junit4] 2> 891686 INFO (jetty-launcher-1506-thread-4) [n:127.0.0.1:43627_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43627_solr
> [junit4] 2> 891687 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_solr ] o.a.s.c.Overseer Overseer (id=96839490810085386-127.0.0.1:44269_solr-n_0000000000) starting
> [junit4] 2> 891688 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 891688 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 891688 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 891688 INFO (zkCallback-1527-thread-1-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
> [junit4] 2> 891689 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 891689 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 891692 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 891696 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
> [junit4] 2> 891698 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44269_solr
> [junit4] 2> 891700 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 891700 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 891700 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 891700 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
> [junit4] 2> 891747 INFO (jetty-launcher-1506-thread-4) [n:127.0.0.1:43627_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/.
> [junit4] 2> 891750 INFO (jetty-launcher-1506-thread-2) [n:127.0.0.1:43056_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/.
> [junit4] 2> 891823 INFO (jetty-launcher-1506-thread-1) [n:127.0.0.1:39698_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node1/.
> [junit4] 2> 891843 INFO (jetty-launcher-1506-thread-3) [n:127.0.0.1:44269_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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/.
> [junit4] 2> 891849 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
> [junit4] 2> 891875 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection
> [junit4] 2> 891876 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[2993885EFB7FDAE4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
> [junit4] 2> 891878 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
> [junit4] 2> 894879 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2
> [junit4] 2> 894881 INFO (OverseerStateUpdate-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
> [junit4] 2> 895892 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 895902 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
> [junit4] 2> 895906 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 895907 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection
> [junit4] 2> 895908 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-002/]
> [junit4] 2> 895917 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 895917 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 895918 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 895918 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 895918 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@14b80ea[halfdeletedcollection_shard1_replica1] main]
> [junit4] 2> 895919 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
> [junit4] 2> 895920 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
> [junit4] 2> 895920 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 895920 INFO (searcherExecutor-3515-thread-1-processing-n:127.0.0.1:44269_solr x:halfdeletedcollection_shard1_replica1 s:shard2 c:halfdeletedcollection r:core_node1) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@14b80ea[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 895920 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431857569857536
> [junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
> [junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
> [junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44269/solr/halfdeletedcollection_shard1_replica1/
> [junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
> [junit4] 2> 895925 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:44269/solr/halfdeletedcollection_shard1_replica1/ has no replicas
> [junit4] 2> 895928 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44269/solr/halfdeletedcollection_shard1_replica1/ shard2
> [junit4] 2> 896078 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
> [junit4] 2> 896080 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2} status=0 QTime=4202
> [junit4] 2> 896081 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 896082 INFO (OverseerThreadFactory-3506-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
> [junit4] 2> 896084 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1de358b
> [junit4] 2> 896086 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=2
> [junit4] 2> 896792 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=711
> [junit4] 2> 896793 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 896793 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
> [junit4] 2> 896794 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 896796 INFO (OverseerThreadFactory-3506-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.CreateCollectionCmd Create collection halfdeletedcollection
> [junit4] 2> 896796 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 897001 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
> [junit4] 2> 897001 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
> [junit4] 2> 900001 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2
> [junit4] 2> 900002 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2
> [junit4] 2> 900005 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 900005 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 900108 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 900108 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 901015 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 901015 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 901025 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica1] Schema name=minimal
> [junit4] 2> 901025 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
> [junit4] 2> 901030 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 901030 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 901031 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard2_replica1' using configuration from collection halfdeletedcollection
> [junit4] 2> 901031 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection
> [junit4] 2> 901032 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/halfdeletedcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/./halfdeletedcollection_shard2_replica1/data/]
> [junit4] 2> 901032 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/./halfdeletedcollection_shard1_replica1/data/]
> [junit4] 2> 901042 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 901042 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 901043 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 901043 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 901044 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 901044 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 901044 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 901044 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 901044 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@96a92d[halfdeletedcollection_shard2_replica1] main]
> [junit4] 2> 901044 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1dd013a[halfdeletedcollection_shard1_replica1] main]
> [junit4] 2> 901045 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
> [junit4] 2> 901045 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
> [junit4] 2> 901045 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
> [junit4] 2> 901045 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
> [junit4] 2> 901045 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 901045 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 901045 INFO (searcherExecutor-3520-thread-1-processing-n:127.0.0.1:43627_solr x:halfdeletedcollection_shard2_replica1 s:shard2 c:halfdeletedcollection r:core_node1) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] Registered new searcher Searcher@96a92d[halfdeletedcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 901045 INFO (searcherExecutor-3521-thread-1-processing-n:127.0.0.1:43056_solr x:halfdeletedcollection_shard1_replica1 s:shard1 c:halfdeletedcollection r:core_node2) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@1dd013a[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 901046 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431862944858112
> [junit4] 2> 901046 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431862944858112
> [junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
> [junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
> [junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
> [junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
> [junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43627/solr/halfdeletedcollection_shard2_replica1/
> [junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43056/solr/halfdeletedcollection_shard1_replica1/
> [junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
> [junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
> [junit4] 2> 901053 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:43627/solr/halfdeletedcollection_shard2_replica1/ has no replicas
> [junit4] 2> 901053 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:43056/solr/halfdeletedcollection_shard1_replica1/ has no replicas
> [junit4] 2> 901056 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43627/solr/halfdeletedcollection_shard2_replica1/ shard2
> [junit4] 2> 901056 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43056/solr/halfdeletedcollection_shard1_replica1/ shard1
> [junit4] 2> 901159 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 901159 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 901207 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
> [junit4] 2> 901207 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
> [junit4] 2> 901208 INFO (qtp18156234-7911) [n:127.0.0.1:43627_solr c:halfdeletedcollection s:shard2 r:core_node1 x:halfdeletedcollection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard2_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=4207
> [junit4] 2> 901208 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:halfdeletedcollection s:shard1 r:core_node2 x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=4207
> [junit4] 2> 901210 INFO (qtp13402862-7889) [n:127.0.0.1:44269_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> 901311 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 901311 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/halfdeletedcollection/state.json] for collection [halfdeletedcollection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 902211 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=halfdeletedcollection&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=5417
> [junit4] 2> 902212 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 902212 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=LIST&wt=javabin&version=2} status=0 QTime=0
> [junit4] 2> 902213 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deletePartiallyCreatedCollection
> [junit4] 2> 902237 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSpecificConfigsets
> [junit4] 2> 902238 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[2993885EFB7FDAE4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
> [junit4] 2> 902238 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=halfdeletedcollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 902243 INFO (OverseerThreadFactory-3506-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
> [junit4] 2> 902243 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 902245 INFO (qtp6349842-7897) [n:127.0.0.1:43056_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@188aed
> [junit4] 2> 902246 INFO (qtp18156234-7912) [n:127.0.0.1:43627_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4d4832
> [junit4] 2> 902249 INFO (qtp6349842-7897) [n:127.0.0.1:43056_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=4
> [junit4] 2> 902249 INFO (qtp18156234-7912) [n:127.0.0.1:43627_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=halfdeletedcollection_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=3
> [junit4] 2> 902953 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=714
> [junit4] 2> 902954 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 902955 INFO (OverseerThreadFactory-3506-thread-4-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.CreateCollectionCmd Create collection withconfigset2
> [junit4] 2> 902955 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 903160 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2
> [junit4] 2> 903263 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 904184 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 904192 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.IndexSchema [withconfigset2_shard1_replica1] Schema name=minimal
> [junit4] 2> 904195 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 904196 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'withconfigset2_shard1_replica1' using configuration from collection withconfigset2
> [junit4] 2> 904196 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrCore [[withconfigset2_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/withconfigset2_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/./withconfigset2_shard1_replica1/data/]
> [junit4] 2> 904196 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1cd9321
> [junit4] 2> 904216 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 904216 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 904217 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 904217 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 904218 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1ed9f9c[withconfigset2_shard1_replica1] main]
> [junit4] 2> 904219 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2
> [junit4] 2> 904219 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2
> [junit4] 2> 904219 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 904220 INFO (searcherExecutor-3530-thread-1-processing-n:127.0.0.1:44269_solr x:withconfigset2_shard1_replica1 s:shard1 c:withconfigset2 r:core_node1) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] Registered new searcher Searcher@1ed9f9c[withconfigset2_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 904220 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431866273038336
> [junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
> [junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
> [junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44269/solr/withconfigset2_shard1_replica1/
> [junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
> [junit4] 2> 904225 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:44269/solr/withconfigset2_shard1_replica1/ has no replicas
> [junit4] 2> 904227 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44269/solr/withconfigset2_shard1_replica1/ shard1
> [junit4] 2> 904328 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 904377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
> [junit4] 2> 904379 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:withconfigset2 s:shard1 r:core_node1 x:withconfigset2_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2} status=0 QTime=1219
> [junit4] 2> 904381 INFO (qtp13402862-7909) [n:127.0.0.1:44269_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> 904481 INFO (zkCallback-1525-thread-1-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 904957 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_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> 905382 INFO (qtp13402862-7909) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2427
> [junit4] 2> 905382 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSpecificConfigsets
> [junit4] 2> 905402 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[2993885EFB7FDAE4]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCollectionReload
> [junit4] 2> 905403 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[2993885EFB7FDAE4]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
> [junit4] 2> 905404 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=withconfigset2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 905405 INFO (OverseerThreadFactory-3506-thread-5-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
> [junit4] 2> 905407 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@e5cace
> [junit4] 2> 905428 INFO (qtp13402862-7886) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=withconfigset2_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=21
> [junit4] 2> 906132 INFO (qtp13402862-7889) [n:127.0.0.1:44269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=withconfigset2&action=DELETE&wt=javabin&version=2} status=0 QTime=728
> [junit4] 2> 906133 INFO (qtp13402862-7906) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=reloaded_collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
> [junit4] 2> 906134 INFO (OverseerThreadFactory-3506-thread-5-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.CreateCollectionCmd Create collection reloaded_collection
> [junit4] 2> 906134 INFO (OverseerCollectionConfigSetProcessor-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 doesn't exist. Requestor may have disconnected from ZooKeeper
> [junit4] 2> 906339 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
> [junit4] 2> 906339 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
> [junit4] 2> 906340 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2
> [junit4] 2> 906341 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr ] o.a.s.u.TestInjection Inject random core creation delay of 3s
> [junit4] 2> 906443 INFO (zkCallback-1525-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 907352 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 907361 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica2] Schema name=minimal
> [junit4] 2> 907364 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 907365 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard2_replica2' using configuration from collection reloaded_collection
> [junit4] 2> 907366 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/reloaded_collection_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node3/./reloaded_collection_shard2_replica2/data/]
> [junit4] 2> 907374 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 907374 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 907376 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 907376 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 907376 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@43810e[reloaded_collection_shard2_replica2] main]
> [junit4] 2> 907377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
> [junit4] 2> 907377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
> [junit4] 2> 907377 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 907378 INFO (searcherExecutor-3535-thread-1-processing-n:127.0.0.1:44269_solr x:reloaded_collection_shard2_replica2 s:shard2 c:reloaded_collection r:core_node1) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [reloaded_collection_shard2_replica2] Registered new searcher Searcher@43810e[reloaded_collection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 907378 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431869584441344
> [junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
> [junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
> [junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44269/solr/reloaded_collection_shard2_replica2/
> [junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
> [junit4] 2> 907383 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.SyncStrategy http://127.0.0.1:44269/solr/reloaded_collection_shard2_replica2/ has no replicas
> [junit4] 2> 907386 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44269/solr/reloaded_collection_shard2_replica2/ shard2
> [junit4] 2> 907488 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 907537 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
> [junit4] 2> 907539 INFO (qtp13402862-7904) [n:127.0.0.1:44269_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=1198
> [junit4] 2> 907640 INFO (zkCallback-1525-thread-2-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 909339 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2
> [junit4] 2> 909340 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2
> [junit4] 2> 909342 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2
> [junit4] 2> 909342 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 909342 INFO (zkCallback-1525-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 909342 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 909448 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 909448 INFO (zkCallback-1527-thread-2-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 909448 INFO (zkCallback-1525-thread-3-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 909448 INFO (zkCallback-1526-thread-1-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
> [junit4] 2> 910350 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 910352 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 910353 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
> [junit4] 2> 910369 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica2] Schema name=minimal
> [junit4] 2> 910370 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica1] Schema name=minimal
> [junit4] 2> 910370 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica1] Schema name=minimal
> [junit4] 2> 910373 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 910373 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 910373 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
> [junit4] 2> 910374 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard1_replica2' using configuration from collection reloaded_collection
> [junit4] 2> 910374 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard2_replica1' using configuration from collection reloaded_collection
> [junit4] 2> 910374 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard1_replica1' using configuration from collection reloaded_collection
> [junit4] 2> 910374 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node1/reloaded_collection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node1/./reloaded_collection_shard2_replica1/data/]
> [junit4] 2> 910374 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/reloaded_collection_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node2/./reloaded_collection_shard1_replica2/data/]
> [junit4] 2> 910374 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/reloaded_collection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001/tempDir-001/node4/./reloaded_collection_shard1_replica1/data/]
> [junit4] 2> 910385 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 910385 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 910385 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
> [junit4] 2> 910385 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 910385 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 910385 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
> [junit4] 2> 910386 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 910386 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 910386 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 910386 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 910386 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
> [junit4] 2> 910386 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
> [junit4] 2> 910386 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@8133a3[reloaded_collection_shard1_replica2] main]
> [junit4] 2> 910386 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@12c5eaf[reloaded_collection_shard2_replica1] main]
> [junit4] 2> 910387 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@10370de[reloaded_collection_shard1_replica1] main]
> [junit4] 2> 910388 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
> [junit4] 2> 910388 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
> [junit4] 2> 910389 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
> [junit4] 2> 910389 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 910389 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
> [junit4] 2> 910389 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
> [junit4] 2> 910389 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 910389 INFO (searcherExecutor-3541-thread-1-processing-n:127.0.0.1:39698_solr x:reloaded_collection_shard2_replica1 s:shard2 c:reloaded_collection r:core_node2) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [reloaded_collection_shard2_replica1] Registered new searcher Searcher@12c5eaf[reloaded_collection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 910389 INFO (searcherExecutor-3540-thread-1-processing-n:127.0.0.1:43056_solr x:reloaded_collection_shard1_replica2 s:shard1 c:reloaded_collection r:core_node3) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [reloaded_collection_shard1_replica2] Registered new searcher Searcher@8133a3[reloaded_collection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 910389 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431872741703680
> [junit4] 2> 910389 INFO (qtp6349842-7901) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431872741703680
> [junit4] 2> 910389 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
> [junit4] 2> 910389 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
> [junit4] 2> 910390 INFO (searcherExecutor-3542-thread-1-processing-n:127.0.0.1:43627_solr x:reloaded_collection_shard1_replica1 s:shard1 c:reloaded_collection r:core_node4) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [reloaded_collection_shard1_replica1] Registered new searcher Searcher@10370de[reloaded_collection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
> [junit4] 2> 910390 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1549431872742752256
> [junit4] 2> 910395 INFO (qtp30058236-7894) [n:127.0.0.1:39698_solr c:reloaded_collection s:shard2 r:core_node2 x:reloaded_collection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=4056
> [junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
> [junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
> [junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43627/solr/reloaded_collection_shard1_replica1/
> [junit4] 2> 910395 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard1_replica1 url=http://127.0.0.1:43627/solr START replicas=[http://127.0.0.1:43056/solr/reloaded_collection_shard1_replica2/] nUpdates=100
> [junit4] 2> 910396 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard1_replica1 url=http://127.0.0.1:43627/solr DONE. We have no versions. sync failed.
> [junit4] 2> 910397 INFO (qtp6349842-7895) [n:127.0.0.1:43056_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica2] o.a.s.c.S.Request [reloaded_collection_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
> [junit4] 2> 910397 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloaded_collection s:shard1 r:core_node4 x:reloaded_collection_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
> [junit4] 2> 910397 INFO (qtp18156234-7914) [n:127.0.0.1:43627_solr c:reloa
>
> [...truncated too long message...]
>
> (coreCloseExecutor-3751-thread-1) [n:127.0.0.1:43056_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@1469cc6
> [junit4] 2> 1030781 INFO (jetty-launcher-1506-thread-8) [ ] o.a.s.c.Overseer Overseer (id=96839490810085386-127.0.0.1:44269_solr-n_0000000000) closing
> [junit4] 2> 1030782 INFO (OverseerStateUpdate-96839490810085386-127.0.0.1:44269_solr-n_0000000000) [n:127.0.0.1:44269_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44269_solr
> [junit4] 2> 1030782 INFO (coreCloseExecutor-3754-thread-1) [n:127.0.0.1:39698_solr c:acollectionafterbaddelete s:shard1 r:core_node2 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@15fdfe7
> [junit4] 2> 1030786 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:40451) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
> [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x1580b00f9f7000c, likely client has closed socket
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
> [junit4] 2> at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> 1030786 INFO (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (2)
> [junit4] 2> 1030786 INFO (zkCallback-1526-thread-3-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (2)
> [junit4] 2> 1030787 INFO (zkCallback-1526-thread-2-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43056_solr
> [junit4] 2> 1030787 WARN (zkCallback-1524-thread-1-processing-n:127.0.0.1:39698_solr) [n:127.0.0.1:39698_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
> [junit4] 2> 1030787 WARN (zkCallback-1526-thread-4-processing-n:127.0.0.1:43056_solr) [n:127.0.0.1:43056_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
> [junit4] 2> 1030787 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:40451) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
> [junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x1580b00f9f7000b, likely client has closed socket
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
> [junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
> [junit4] 2> at java.lang.Thread.run(Thread.java:745)
> [junit4] 2> 1030787 INFO (jetty-launcher-1506-thread-7) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5fe13{/solr,null,UNAVAILABLE}
> [junit4] 2> 1032286 WARN (zkCallback-1525-thread-8-processing-n:127.0.0.1:44269_solr) [n:127.0.0.1:44269_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
> [junit4] 2> 1032286 WARN (zkCallback-1527-thread-6-processing-n:127.0.0.1:43627_solr) [n:127.0.0.1:43627_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
> [junit4] 2> 1032286 INFO (jetty-launcher-1506-thread-5) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@492a4f{/solr,null,UNAVAILABLE}
> [junit4] 2> 1032286 INFO (jetty-launcher-1506-thread-8) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@12ff696{/solr,null,UNAVAILABLE}
> [junit4] 2> 1032287 INFO (jetty-launcher-1506-thread-6) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@236325{/solr,null,UNAVAILABLE}
> [junit4] 2> 1032288 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40451 40451
> [junit4] 2> 1032293 INFO (Thread-1891) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40451 40451
> [junit4] 2> 1032294 WARN (Thread-1891) [ ] o.a.s.c.ZkTestServer Watch limit violations:
> [junit4] 2> Maximum concurrent create/delete watches above limit:
> [junit4] 2>
> [junit4] 2> 6 /solr/configs/conf
> [junit4] 2> 6 /solr/clusterprops.json
> [junit4] 2> 6 /solr/aliases.json
> [junit4] 2>
> [junit4] 2> Maximum concurrent data watches above limit:
> [junit4] 2>
> [junit4] 2> 339 /solr/clusterstate.json
> [junit4] 2> 3 /solr/collections/acollectionafterbaddelete/state.json
> [junit4] 2>
> [junit4] 2> Maximum concurrent children watches above limit:
> [junit4] 2>
> [junit4] 2> 290 /solr/collections
> [junit4] 2> 48 /solr/overseer/collection-queue-work
> [junit4] 2> 36 /solr/overseer/queue
> [junit4] 2> 10 /solr/overseer/queue-work
> [junit4] 2> 6 /solr/live_nodes
> [junit4] 2>
> [junit4] 2> 1032294 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[2993885EFB7FDAE4]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
> [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.CollectionsAPIDistributedZkTest_2993885EFB7FDAE4-001
> [junit4] 2> Oct 28, 2016 11:18:23 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
> [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
> [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{}, maxPointsInLeafNode=342, maxMBSortInHeap=7.06019445196937, sim=ClassicSimilarity, locale=et, timezone=Pacific/Chuuk
> [junit4] 2> NOTE: Linux 4.4.0-42-generic i386/Oracle Corporation 1.8.0_102 (32-bit)/cpus=12,threads=1,free=238609504,total=347602944
> [junit4] 2> NOTE: All tests run in this JVM: [SOLR749Test, TestSolrConfigHandler, SpellingQueryConverterTest, IndexBasedSpellCheckerTest, GraphQueryTest, SoftAutoCommitTest, QueryParsingTest, SolrCloudExampleTest, TestGraphTermsQParserPlugin, ConfigSetsAPITest, SolrCmdDistributorTest, DOMUtilTest, TestMiniSolrCloudCluster, CollectionReloadTest, TestManagedSchemaAPI, TestQueryTypes, TestStressVersions, HdfsRecoveryZkTest, TestFileDictionaryLookup, SuggestComponentContextFilterQueryTest, TestJettySolrRunner, TestDistribDocBasedVersion, RemoteQueryErrorTest, DocumentBuilderTest, TestReplicationHandlerBackup, BigEndianAscendingWordSerializerTest, AtomicUpdatesTest, TestFuzzyAnalyzedSuggestions, HdfsBasicDistributedZkTest, TestNRTOpen, TestUseDocValuesAsStored, ConjunctionSolrSpellCheckerTest, SparseHLLTest, TriLevelCompositeIdRoutingTest, TestCloudSchemaless, DeleteNodeTest, TestTestInjection, SpatialFilterTest, SortByFunctionTest, TestSolrCloudWithSecureImpersonation, DistribJoinFromCollectionTest, DirectSolrSpellCheckerTest, HdfsDirectoryTest, SolrIndexSplitterTest, SimplePostToolTest, TermsComponentTest, TestBlobHandler, TestManagedResource, BlockJoinFacetDistribTest, TestSubQueryTransformer, DistributedTermsComponentTest, TestFieldCacheSort, SharedFSAutoReplicaFailoverUtilsTest, HighlighterTest, TestCollectionAPI, ShardRoutingCustomTest, TestJsonFacetRefinement, PKIAuthenticationIntegrationTest, HdfsThreadLeakTest, TestOrdValues, TestRequestStatusCollectionAPI, TestCharFilters, TestPostingsSolrHighlighter, TestCoreContainer, TestFiltering, TestGraphMLResponseWriter, LoggingHandlerTest, ZkSolrClientTest, DocExpirationUpdateProcessorFactoryTest, TestNumericTerms64, OpenExchangeRatesOrgProviderTest, AnalysisErrorHandlingTest, JavabinLoaderTest, RuleEngineTest, TestTrieFacet, TestFieldTypeResource, CoreMergeIndexesAdminHandlerTest, TestSimpleQParserPlugin, CdcrReplicationHandlerTest, TestCustomSort, TestDefaultSearchFieldResource, TestJsonRequest, SampleTest, WordBreakSolrSpellCheckerTest, TestDocumentBuilder, ZkStateReaderTest, IndexSchemaTest, LeaderInitiatedRecoveryOnShardRestartTest, TestLRUStatsCache, TestSolrConfigHandlerConcurrent, TestFieldCacheWithThreads, TestBulkSchemaConcurrent, SpellCheckCollatorTest, TestRandomCollapseQParserPlugin, TestFieldCollectionResource, JsonLoaderTest, SaslZkACLProviderTest, TestQueryUtils, TestCloudDeleteByQuery, TestBinaryResponseWriter, ChaosMonkeyNothingIsSafeTest, RestartWhileUpdatingTest, DistributedMLTComponentTest, BlockCacheTest, TestHdfsUpdateLog, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
> [junit4] Completed [320/647 (1!)] on J1 in 141.05s, 20 tests, 1 error <<< FAILURES!
>
> [...truncated 12167 lines...]
> -validate-source-patterns:
> [source-patterns] nocommit: solr/core/src/test/org/apache/solr/cloud/RecoveryZkTest.java
> [source-patterns] invalid logging pattern [not private static final, uses static class name]: solr/core/src/test/org/apache/solr/cloud/RecoveryZkTest.java
>
> BUILD FAILED
> /home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:765: The following error occurred while executing this line:
> /home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:130: Found 2 violations in source files (invalid logging pattern [not private static final, uses static class name], nocommit).
>
> Total time: 67 minutes 6 seconds
> Build step 'Invoke Ant' marked build as failure
> Archiving artifacts
> [WARNINGS] Skipping publisher since build result is FAILURE
> Recording test results
> Email was triggered for: Failure - Any
> Sending email for trigger: Failure - Any
>
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org