You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/09/01 23:27:20 UTC
[JENKINS] Lucene-Solr-6.6-Linux (64bit/jdk1.8.0_144) - Build # 126
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Linux/126/
Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
Stack Trace:
java.lang.AssertionError: Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
at __randomizedtesting.SeedInfo.seed([3BAACB4C89E0B94E:73DFBFF88FD396DB]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.checkNoTwoShardsUseTheSameIndexDir(CollectionsAPIDistributedZkTest.java:646)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:524)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 11691 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/init-core-data-001
[junit4] 2> 535274 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 535274 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 535274 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 535275 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001
[junit4] 2> 535275 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 535275 INFO (Thread-944) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 535275 INFO (Thread-944) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 535277 ERROR (Thread-944) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 535375 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34785
[junit4] 2> 535380 INFO (jetty-launcher-578-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 535380 INFO (jetty-launcher-578-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 535380 INFO (jetty-launcher-578-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 535382 INFO (jetty-launcher-578-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 535383 INFO (jetty-launcher-578-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@42cdfd6f{/solr,null,AVAILABLE}
[junit4] 2> 535385 INFO (jetty-launcher-578-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@75a63c62{/solr,null,AVAILABLE}
[junit4] 2> 535386 INFO (jetty-launcher-578-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@b7f7378{/solr,null,AVAILABLE}
[junit4] 2> 535387 INFO (jetty-launcher-578-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1e4b42e2{HTTP/1.1,[http/1.1]}{127.0.0.1:39241}
[junit4] 2> 535387 INFO (jetty-launcher-578-thread-4) [ ] o.e.j.s.Server Started @537461ms
[junit4] 2> 535387 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39241}
[junit4] 2> 535387 ERROR (jetty-launcher-578-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 535387 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 535387 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 535387 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 535387 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-01T22:44:32.394Z
[junit4] 2> 535390 INFO (jetty-launcher-578-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4114d789{/solr,null,AVAILABLE}
[junit4] 2> 535390 INFO (jetty-launcher-578-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6af18f0c{HTTP/1.1,[http/1.1]}{127.0.0.1:36239}
[junit4] 2> 535390 INFO (jetty-launcher-578-thread-2) [ ] o.e.j.s.Server Started @537465ms
[junit4] 2> 535390 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36239}
[junit4] 2> 535391 ERROR (jetty-launcher-578-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@68bdb174{HTTP/1.1,[http/1.1]}{127.0.0.1:41535}
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-3) [ ] o.e.j.s.Server Started @537465ms
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@11792081{HTTP/1.1,[http/1.1]}{127.0.0.1:45497}
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-01T22:44:32.398Z
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-1) [ ] o.e.j.s.Server Started @537465ms
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45497}
[junit4] 2> 535391 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41535}
[junit4] 2> 535392 ERROR (jetty-launcher-578-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 535392 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 535392 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 535392 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 535392 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-01T22:44:32.399Z
[junit4] 2> 535392 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 535391 ERROR (jetty-launcher-578-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 535393 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 535393 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 535394 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 535394 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 535394 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-01T22:44:32.401Z
[junit4] 2> 535395 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 535395 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 0x15e3f9dfd9b0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 535402 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 535403 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 535404 INFO (jetty-launcher-578-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34785/solr
[junit4] 2> 535405 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 535405 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 0x15e3f9dfd9b0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 535408 INFO (jetty-launcher-578-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34785/solr
[junit4] 2> 535409 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 535410 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 535413 INFO (jetty-launcher-578-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34785/solr
[junit4] 2> 535413 INFO (jetty-launcher-578-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34785/solr
[junit4] 2> 535426 INFO (jetty-launcher-578-thread-4) [n:127.0.0.1:39241_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 535426 INFO (jetty-launcher-578-thread-3) [n:127.0.0.1:41535_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 535426 INFO (jetty-launcher-578-thread-1) [n:127.0.0.1:45497_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 535426 INFO (jetty-launcher-578-thread-2) [n:127.0.0.1:36239_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 535427 INFO (jetty-launcher-578-thread-4) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:39241_solr
[junit4] 2> 535427 INFO (jetty-launcher-578-thread-1) [n:127.0.0.1:45497_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45497_solr
[junit4] 2> 535427 INFO (jetty-launcher-578-thread-3) [n:127.0.0.1:41535_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41535_solr
[junit4] 2> 535427 INFO (jetty-launcher-578-thread-2) [n:127.0.0.1:36239_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36239_solr
[junit4] 2> 535427 INFO (jetty-launcher-578-thread-4) [n:127.0.0.1:39241_solr ] o.a.s.c.Overseer Overseer (id=98586189645938698-127.0.0.1:39241_solr-n_0000000000) starting
[junit4] 2> 535427 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 535427 INFO (zkCallback-599-thread-1-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 535430 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 535430 INFO (zkCallback-600-thread-1-processing-n:127.0.0.1:45497_solr) [n:127.0.0.1:45497_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 535430 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 535430 INFO (zkCallback-599-thread-1-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 535430 INFO (zkCallback-600-thread-2-processing-n:127.0.0.1:45497_solr) [n:127.0.0.1:45497_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 535433 INFO (OverseerStateUpdate-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 535438 INFO (jetty-launcher-578-thread-4) [n:127.0.0.1:39241_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39241_solr
[junit4] 2> 535439 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 535439 INFO (zkCallback-599-thread-1-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 535441 INFO (zkCallback-600-thread-2-processing-n:127.0.0.1:45497_solr) [n:127.0.0.1:45497_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 535441 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 535456 INFO (jetty-launcher-578-thread-2) [n:127.0.0.1:36239_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node2/.
[junit4] 2> 535457 INFO (jetty-launcher-578-thread-3) [n:127.0.0.1:41535_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node3/.
[junit4] 2> 535477 INFO (jetty-launcher-578-thread-4) [n:127.0.0.1:39241_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node4/.
[junit4] 2> 535492 INFO (jetty-launcher-578-thread-1) [n:127.0.0.1:45497_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node1/.
[junit4] 2> 535503 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 535504 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34785/solr ready
[junit4] 2> 535523 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionOnlyInZk
[junit4] 2> 535524 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 535527 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=onlyinzk&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 535532 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 535535 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 535535 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_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> 535536 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=onlyinzk&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 535537 INFO (OverseerThreadFactory-1477-thread-2-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd Create collection onlyinzk
[junit4] 2> 535537 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_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> 535641 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard1_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard1&wt=javabin&version=2
[junit4] 2> 535641 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard2_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard2&wt=javabin&version=2
[junit4] 2> 535641 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 535641 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 535744 INFO (zkCallback-599-thread-1-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 535744 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 536656 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 536656 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 536677 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.IndexSchema [onlyinzk_shard1_replica1] Schema name=minimal
[junit4] 2> 536677 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.IndexSchema [onlyinzk_shard2_replica1] Schema name=minimal
[junit4] 2> 536680 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 536680 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 536680 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'onlyinzk_shard2_replica1' using configuration from collection onlyinzk, trusted=true
[junit4] 2> 536680 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'onlyinzk_shard1_replica1' using configuration from collection onlyinzk, trusted=true
[junit4] 2> 536681 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 536681 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 536681 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SolrCore [[onlyinzk_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node3/onlyinzk_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node3/./onlyinzk_shard2_replica1/data/]
[junit4] 2> 536681 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SolrCore [[onlyinzk_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node2/onlyinzk_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node2/./onlyinzk_shard1_replica1/data/]
[junit4] 2> 536711 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 536711 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 536711 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 536711 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 536712 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 536712 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 536712 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 536712 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 536712 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5bea798b[onlyinzk_shard1_replica1] main]
[junit4] 2> 536712 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@30a66170[onlyinzk_shard2_replica1] main]
[junit4] 2> 536713 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 536713 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 536713 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 536713 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 536713 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 536713 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 536718 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577379035847065600
[junit4] 2> 536718 INFO (searcherExecutor-1487-thread-1-processing-n:127.0.0.1:36239_solr x:onlyinzk_shard1_replica1 s:shard1 c:onlyinzk) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SolrCore [onlyinzk_shard1_replica1] Registered new searcher Searcher@5bea798b[onlyinzk_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 536718 INFO (searcherExecutor-1486-thread-1-processing-n:127.0.0.1:41535_solr x:onlyinzk_shard2_replica1 s:shard2 c:onlyinzk) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SolrCore [onlyinzk_shard2_replica1] Registered new searcher Searcher@30a66170[onlyinzk_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 536718 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577379035847065600
[junit4] 2> 536721 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 536721 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 536721 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 536721 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41535/solr/onlyinzk_shard2_replica1/
[junit4] 2> 536721 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 536721 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 536721 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36239/solr/onlyinzk_shard1_replica1/
[junit4] 2> 536721 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:41535/solr/onlyinzk_shard2_replica1/ has no replicas
[junit4] 2> 536721 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 536721 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 536721 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:36239/solr/onlyinzk_shard1_replica1/ has no replicas
[junit4] 2> 536721 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 536723 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36239/solr/onlyinzk_shard1_replica1/ shard1
[junit4] 2> 536723 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41535/solr/onlyinzk_shard2_replica1/ shard2
[junit4] 2> 536824 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 536824 INFO (zkCallback-599-thread-1-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 536873 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 536873 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 536876 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:onlyinzk s:shard1 x:onlyinzk_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard1_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard1&wt=javabin&version=2} status=0 QTime=1236
[junit4] 2> 536879 INFO (qtp1746577863-3635) [n:127.0.0.1:41535_solr c:onlyinzk s:shard2 x:onlyinzk_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=onlyinzk_shard2_replica1&action=CREATE&numShards=2&collection=onlyinzk&shard=shard2&wt=javabin&version=2} status=0 QTime=1238
[junit4] 2> 536884 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_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> 536986 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 536986 INFO (zkCallback-599-thread-1-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/onlyinzk/state.json] for collection [onlyinzk] has occurred - updating... (live nodes size: [4])
[junit4] 2> 537539 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_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> 537884 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=onlyinzk&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=2348
[junit4] 2> 537886 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 537886 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_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> 537887 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionOnlyInZk-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionOnlyInZk
[junit4] 2> 537916 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection
[junit4] 2> 537917 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 537919 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=onlyinzk&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 537920 INFO (OverseerThreadFactory-1477-thread-3-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 537922 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk.shard1.replica1
[junit4] 2> 537923 INFO (qtp1746577863-3662) [n:127.0.0.1:41535_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk.shard2.replica1
[junit4] 2> 537923 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.c.SolrCore [onlyinzk_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@53bccac8
[junit4] 2> 537924 INFO (qtp1746577863-3662) [n:127.0.0.1:41535_solr ] o.a.s.c.SolrCore [onlyinzk_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@6ac5400f
[junit4] 2> 537931 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk.shard1.replica1
[junit4] 2> 537938 INFO (qtp1746577863-3662) [n:127.0.0.1:41535_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.onlyinzk.shard2.replica1
[junit4] 2> 537939 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=onlyinzk_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=17
[junit4] 2> 537940 INFO (qtp1746577863-3662) [n:127.0.0.1:41535_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=onlyinzk_shard2_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=17
[junit4] 2> 538550 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=onlyinzk&action=DELETE&wt=javabin&version=2} status=0 QTime=631
[junit4] 2> 538552 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr ] o.a.s.u.TestInjection Inject random core creation delay of 0s
[junit4] 2> 538552 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2
[junit4] 2> 538553 INFO (OverseerStateUpdate-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 539559 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 539563 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 539565 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 539565 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 539565 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 539566 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node2/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-002/]
[junit4] 2> 539598 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 539598 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 539599 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 539599 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 539599 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4dadfc7e[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 539600 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 539601 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 539601 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 539601 INFO (searcherExecutor-1496-thread-1-processing-n:127.0.0.1:36239_solr x:halfdeletedcollection_shard1_replica1 c:halfdeletedcollection) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@4dadfc7e[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 539601 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577379038870110208
[junit4] 2> 539606 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 539606 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 539606 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36239/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 539606 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 539606 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:36239/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 539606 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 539608 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36239/solr/halfdeletedcollection_shard1_replica1/ shard2
[junit4] 2> 539713 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 539714 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-002&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2} status=0 QTime=1161
[junit4] 2> 539715 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_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> 539716 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_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> 539716 INFO (OverseerThreadFactory-1477-thread-4-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 539718 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 539718 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4e12e2dc
[junit4] 2> 539720 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 539721 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_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=3
[junit4] 2> 540424 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=708
[junit4] 2> 540425 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 540425 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_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> 540427 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_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> 540428 INFO (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd Create collection halfdeletedcollection
[junit4] 2> 540428 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_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> 540643 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_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> 540644 INFO (qtp973042556-3637) [n:127.0.0.1:39241_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> 540644 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 540747 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_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> 540747 INFO (zkCallback-593-thread-2-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_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> 541650 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 541651 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 541656 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 541658 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica1] Schema name=minimal
[junit4] 2> 541658 INFO (qtp973042556-3637) [n:127.0.0.1:39241_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> 541658 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 541658 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 541658 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node4/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node4/./halfdeletedcollection_shard1_replica1/data/]
[junit4] 2> 541659 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_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> 541659 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard2_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 541660 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 541660 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node2/halfdeletedcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001/tempDir-001/node2/./halfdeletedcollection_shard2_replica1/data/]
[junit4] 2> 541686 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 541686 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 541687 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 541687 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 541687 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2de02c0d[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 541688 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 541688 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 541688 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 541688 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 541688 INFO (searcherExecutor-1501-thread-1-processing-n:127.0.0.1:39241_solr x:halfdeletedcollection_shard1_replica1 s:shard1 c:halfdeletedcollection) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@2de02c0d[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 541688 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 541689 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577379041059536896
[junit4] 2> 541689 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 541689 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 541690 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@46bb9549[halfdeletedcollection_shard2_replica1] main]
[junit4] 2> 541691 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 541692 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 541692 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 541693 INFO (searcherExecutor-1502-thread-1-processing-n:127.0.0.1:36239_solr x:halfdeletedcollection_shard2_replica1 s:shard2 c:halfdeletedcollection) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] Registered new searcher Searcher@46bb9549[halfdeletedcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 541693 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 541693 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 541693 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577379041063731200
[junit4] 2> 541693 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:39241/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 541693 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 541693 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:39241/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 541693 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 541694 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:39241/solr/halfdeletedcollection_shard1_replica1/ shard1
[junit4] 2> 541696 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 541696 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 541696 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36239/solr/halfdeletedcollection_shard2_replica1/
[junit4] 2> 541696 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 541696 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:36239/solr/halfdeletedcollection_shard2_replica1/ has no replicas
[junit4] 2> 541696 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 541697 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36239/solr/halfdeletedcollection_shard2_replica1/ shard2
[junit4] 2> 541799 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_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> 541799 INFO (zkCallback-593-thread-2-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_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> 541845 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 541846 INFO (qtp973042556-3637) [n:127.0.0.1:39241_solr c:halfdeletedcollection s:shard1 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=1202
[junit4] 2> 541848 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 541848 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr c:halfdeletedcollection s:shard2 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=1205
[junit4] 2> 541850 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_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> 541949 INFO (zkCallback-593-thread-2-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_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> 541949 INFO (zkCallback-598-thread-1-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_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> 542429 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_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> 542850 INFO (qtp2081668885-3653) [n:127.0.0.1:36239_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=2423
[junit4] 2> 542852 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 542852 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_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> 542852 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deletePartiallyCreatedCollection
[junit4] 2> 542872 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMissingNumShards
[junit4] 2> 542873 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 542874 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_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> 542875 INFO (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 542877 INFO (qtp973042556-3656) [n:127.0.0.1:39241_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 542877 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard2.replica1
[junit4] 2> 542877 INFO (qtp973042556-3656) [n:127.0.0.1:39241_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@3b2b2bb4
[junit4] 2> 542877 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@3a5ddad5
[junit4] 2> 542879 INFO (qtp973042556-3656) [n:127.0.0.1:39241_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 542880 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard2.replica1
[junit4] 2> 542880 INFO (qtp973042556-3656) [n:127.0.0.1:39241_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=3
[junit4] 2> 542881 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_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=4
[junit4] 2> 543583 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=708
[junit4] 2> 543585 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 543586 INFO (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd Create collection acollection
[junit4] 2> 543586 ERROR (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards is a required param (when using CompositeId router).
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:112)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:226)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 543588 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000010 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 543595 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&wt=javabin&version=2} status=400 QTime=9
[junit4] 2> 543596 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingNumShards-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingNumShards
[junit4] 2> 543621 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMissingRequiredParameters
[junit4] 2> 543622 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 543624 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 543624 ERROR (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Missing required parameter: name
[junit4] 2> at org.apache.solr.common.params.RequiredSolrParams.getParams(RequiredSolrParams.java:90)
[junit4] 2> at org.apache.solr.common.params.SolrParams.getAll(SolrParams.java:462)
[junit4] 2> at org.apache.solr.common.params.SolrParams.getAll(SolrParams.java:479)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler$CollectionOperation.lambda$static$0(CollectionsHandler.java:396)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler$CollectionOperation.execute(CollectionsHandler.java:922)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:228)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:215)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:361)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:305)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:462)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 543626 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=1
[junit4] 2> 543626 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingRequiredParameters
[junit4] 2> 543650 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateNodeSet
[junit4] 2> 543650 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 543652 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=nodeset_collection&action=CREATE&numShards=2&createNodeSet=http://127.0.0.1:39241/solr,http://127.0.0.1:45497/solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 543653 INFO (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd Create collection nodeset_collection
[junit4] 2> 543653 WARN (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd It is unusual to create a collection (nodeset_collection) without cores.
[junit4] 2> 543653 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000012 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 543857 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_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> 543857 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=nodeset_collection&action=CREATE&numShards=2&createNodeSet=http://127.0.0.1:39241/solr,http://127.0.0.1:45497/solr&wt=javabin&version=2} status=0 QTime=205
[junit4] 2> 543858 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreateNodeSet
[junit4] 2> 543887 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deleteCollectionRemovesStaleZkCollectionsNode
[junit4] 2> 543888 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 543890 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=nodeset_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 543891 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000014 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 543891 INFO (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 544593 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=nodeset_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=703
[junit4] 2> 544596 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=out_of_sync_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 544597 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000016 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 544599 INFO (qtp2081668885-3638) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=out_of_sync_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 544600 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 544600 INFO (qtp2081668885-3663) [n:127.0.0.1:36239_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> 544601 INFO (TEST-CollectionsAPIDistributedZkTest.deleteCollectionRemovesStaleZkCollectionsNode-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deleteCollectionRemovesStaleZkCollectionsNode
[junit4] 2> 544626 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
[junit4] 2> 544627 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 544629 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 544630 INFO (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd Create collection collection
[junit4] 2> 544630 WARN (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd Specified replicationFactor of 10 on collection collection is higher than or equal to the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 544630 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000018 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 544630 ERROR (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2 and value of replicationFactor is 10. This requires 20 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:226)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 544635 INFO (qtp2081668885-3634) [n:127.0.0.1:36239_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=5
[junit4] 2> 544635 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
[junit4] 2> 544665 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreationAndDeletion
[junit4] 2> 544665 INFO (TEST-CollectionsAPIDistributedZkTest.testCreationAndDeletion-seed#[3BAACB4C89E0B94E]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 544667 INFO (qtp2081668885-3658) [n:127.0.0.1:36239_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=created_and_deleted&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 544668 INFO (OverseerThreadFactory-1477-thread-5-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.CreateCollectionCmd Create collection created_and_deleted
[junit4] 2> 544668 INFO (OverseerCollectionConfigSetProcessor-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000020 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 544873 INFO (qtp973042556-3664) [n:127.0.0.1:39241_solr ] o.a.s.h.a.CoreAdminOperation core cr
[...truncated too long message...]
er-579-thread-4) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@11792081{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 622308 INFO (jetty-closer-579-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@68bdb174{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 622308 INFO (jetty-closer-579-thread-4) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1953275479
[junit4] 2> 622311 INFO (jetty-closer-579-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2108192106
[junit4] 2> 622311 INFO (jetty-closer-579-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 622311 INFO (jetty-closer-579-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 622311 INFO (jetty-closer-579-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 622311 INFO (jetty-closer-579-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 622311 INFO (jetty-closer-579-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 622311 INFO (jetty-closer-579-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 622311 INFO (jetty-closer-579-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@6af18f0c{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 622312 INFO (jetty-closer-579-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1504273034
[junit4] 2> 622312 INFO (jetty-closer-579-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 622312 INFO (jetty-closer-579-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 622312 INFO (jetty-closer-579-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 622312 INFO (jetty-closer-579-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1e4b42e2{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 622314 INFO (jetty-closer-579-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1429940474
[junit4] 2> 622314 INFO (jetty-closer-579-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 622314 INFO (jetty-closer-579-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 622314 INFO (jetty-closer-579-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 622318 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 622318 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 622318 INFO (zkCallback-599-thread-3-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 622321 INFO (zkCallback-598-thread-2-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 622321 INFO (zkCallback-593-thread-1-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 622322 INFO (jetty-closer-579-thread-3) [ ] o.a.s.c.Overseer Overseer (id=98586189645938698-127.0.0.1:39241_solr-n_0000000000) closing
[junit4] 2> 622327 INFO (OverseerStateUpdate-98586189645938698-127.0.0.1:39241_solr-n_0000000000) [n:127.0.0.1:39241_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:39241_solr
[junit4] 2> 623818 WARN (zkCallback-600-thread-2-processing-n:127.0.0.1:45497_solr) [n:127.0.0.1:45497_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 623818 INFO (jetty-closer-579-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@b7f7378{/solr,null,UNAVAILABLE}
[junit4] 2> 623820 WARN (zkCallback-599-thread-3-processing-n:127.0.0.1:41535_solr) [n:127.0.0.1:41535_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 623820 INFO (jetty-closer-579-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@42cdfd6f{/solr,null,UNAVAILABLE}
[junit4] 2> 623828 WARN (zkCallback-593-thread-2-processing-n:127.0.0.1:36239_solr) [n:127.0.0.1:36239_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 623828 WARN (zkCallback-598-thread-2-processing-n:127.0.0.1:39241_solr) [n:127.0.0.1:39241_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 623828 INFO (jetty-closer-579-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4114d789{/solr,null,UNAVAILABLE}
[junit4] 2> 623828 INFO (jetty-closer-579-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@75a63c62{/solr,null,UNAVAILABLE}
[junit4] 2> 623830 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 623830 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34785 34785
[junit4] 2> 633872 INFO (Thread-944) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:34785 34785
[junit4] 2> 633874 WARN (Thread-944) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/aliases.json
[junit4] 2> 25 /solr/clusterprops.json
[junit4] 2> 23 /solr/configs/conf
[junit4] 2> 5 /solr/configs/conf2
[junit4] 2> 4 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 292 /solr/clusterstate.json
[junit4] 2> 5 /solr/collections/awhollynewcollection_0/state.json
[junit4] 2> 4 /solr/collections/nodes_used_collection/state.json
[junit4] 2> 4 /solr/collections/addReplicaColl/state.json
[junit4] 2> 4 /solr/collections/reloaded_collection/state.json
[junit4] 2> 3 /solr/collections/acollectionafterbaddelete/state.json
[junit4] 2> 2 /solr/collections/onlyinzk/state.json
[junit4] 2> 2 /solr/overseer_elect/election/98586189645938698-127.0.0.1:39241_solr-n_0000000000
[junit4] 2> 2 /solr/overseer_elect/election/98586189645938699-127.0.0.1:41535_solr-n_0000000001
[junit4] 2> 2 /solr/collections/halfdeletedcollection/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 441 /solr/collections
[junit4] 2> 25 /solr/live_nodes
[junit4] 2>
[junit4] 2> 633877 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[3BAACB4C89E0B94E]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_3BAACB4C89E0B94E-001
[junit4] 2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=1, maxDocsPerChunk=588, blockSize=202), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=1, blockSize=202)), sim=RandomSimilarity(queryNorm=true,coord=crazy): {}, locale=es-HN, timezone=Africa/Dar_es_Salaam
[junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=283394384,total=523239424
[junit4] 2> NOTE: All tests run in this JVM: [TestGraphTermsQParserPlugin, TestUseDocValuesAsStored2, SampleTest, SolrJmxReporterCloudTest, AssignTest, ShardRoutingTest, SortByFunctionTest, WordBreakSolrSpellCheckerTest, TestSolrQueryParserDefaultOperatorResource, TestSmileRequest, IndexBasedSpellCheckerTest, BlockJoinFacetDistribTest, GraphQueryTest, TestPerFieldSimilarityWithDefaultOverride, DistribCursorPagingTest, SimplePostToolTest, TestExceedMaxTermLength, TestFieldCache, ParsingFieldUpdateProcessorsTest, DocValuesTest, TestCollationFieldDocValues, TestClusterProperties, UpdateRequestProcessorFactoryTest, TestManagedSchemaAPI, TestDynamicLoading, ConnectionReuseTest, JSONWriterTest, TestFieldCacheWithThreads, TestRTGBase, ZkStateReaderTest, DistributedQueueTest, TestConfigReload, TestQueryUtils, DistributedMLTComponentTest, TestDistributedStatsComponentCardinality, TestFastOutputStream, TestStressCloudBlindAtomicUpdates, ConnectionManagerTest, BooleanFieldTest, TestLeaderElectionZkExpiry, TestFuzzyAnalyzedSuggestions, TestSchemaManager, LeaderInitiatedRecoveryOnShardRestartTest, TestSimpleTrackingShardHandler, DistributedFacetPivotLargeTest, SparseHLLTest, DistributedFacetPivotSmallTest, OpenCloseCoreStressTest, ShardRoutingCustomTest, CopyFieldTest, TestElisionMultitermQuery, TestInPlaceUpdatesStandalone, TestSQLHandlerNonCloud, TestSearchPerf, CollectionsAPIDistributedZkTest]
[junit4] Completed [228/713 (1!)] on J1 in 98.61s, 20 tests, 1 failure <<< FAILURES!
[...truncated 45061 lines...]
[JENKINS] Lucene-Solr-6.6-Linux (64bit/jdk1.8.0_144) - Build # 127
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Linux/127/
Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
Stack Trace:
java.lang.AssertionError: Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
at __randomizedtesting.SeedInfo.seed([997017E60CC6587A:D10563520AF577EF]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.checkNoTwoShardsUseTheSameIndexDir(CollectionsAPIDistributedZkTest.java:646)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:524)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12132 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/init-core-data-001
[junit4] 2> 886326 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=11 numCloses=11
[junit4] 2> 886326 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 886327 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 886328 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001
[junit4] 2> 886328 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 886328 INFO (Thread-4430) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 886328 INFO (Thread-4430) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 886330 ERROR (Thread-4430) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 886428 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:36213
[junit4] 2> 886434 INFO (jetty-launcher-1573-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 886434 INFO (jetty-launcher-1573-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 886434 INFO (jetty-launcher-1573-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 886434 INFO (jetty-launcher-1573-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 886447 INFO (jetty-launcher-1573-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2decfae1{/solr,null,AVAILABLE}
[junit4] 2> 886447 INFO (jetty-launcher-1573-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@11d2f132{/solr,null,AVAILABLE}
[junit4] 2> 886447 INFO (jetty-launcher-1573-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2c9310da{/solr,null,AVAILABLE}
[junit4] 2> 886447 INFO (jetty-launcher-1573-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@577233ea{/solr,null,AVAILABLE}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@f3d03f0{SSL,[ssl, http/1.1]}{127.0.0.1:46337}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@491f458c{SSL,[ssl, http/1.1]}{127.0.0.1:45995}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@61f678df{SSL,[ssl, http/1.1]}{127.0.0.1:41209}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-4) [ ] o.e.j.s.Server Started @887865ms
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-2) [ ] o.e.j.s.Server Started @887865ms
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45995}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41209}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-1) [ ] o.e.j.s.Server Started @887865ms
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@333c8f9a{SSL,[ssl, http/1.1]}{127.0.0.1:41137}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46337}
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-3) [ ] o.e.j.s.Server Started @887865ms
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41137}
[junit4] 2> 886449 ERROR (jetty-launcher-1573-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 886449 ERROR (jetty-launcher-1573-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-02T04:35:31.983Z
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-02T04:35:31.983Z
[junit4] 2> 886449 ERROR (jetty-launcher-1573-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 886449 ERROR (jetty-launcher-1573-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 886449 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 886450 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-02T04:35:31.984Z
[junit4] 2> 886450 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-02T04:35:31.984Z
[junit4] 2> 886455 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 886456 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 886456 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 886457 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 886460 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 886460 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 886460 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 886460 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 886463 INFO (jetty-launcher-1573-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36213/solr
[junit4] 2> 886463 INFO (jetty-launcher-1573-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36213/solr
[junit4] 2> 886463 INFO (jetty-launcher-1573-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36213/solr
[junit4] 2> 886463 INFO (jetty-launcher-1573-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:36213/solr
[junit4] 2> 886471 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 0x15e40df55970007, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 886484 INFO (jetty-launcher-1573-thread-3) [n:127.0.0.1:41137_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 886484 INFO (jetty-launcher-1573-thread-4) [n:127.0.0.1:45995_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 886484 INFO (jetty-launcher-1573-thread-1) [n:127.0.0.1:46337_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 886484 INFO (jetty-launcher-1573-thread-2) [n:127.0.0.1:41209_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 886485 INFO (jetty-launcher-1573-thread-3) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41137_solr
[junit4] 2> 886485 INFO (jetty-launcher-1573-thread-2) [n:127.0.0.1:41209_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41209_solr
[junit4] 2> 886485 INFO (jetty-launcher-1573-thread-1) [n:127.0.0.1:46337_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46337_solr
[junit4] 2> 886485 INFO (jetty-launcher-1573-thread-4) [n:127.0.0.1:45995_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45995_solr
[junit4] 2> 886485 INFO (jetty-launcher-1573-thread-3) [n:127.0.0.1:41137_solr ] o.a.s.c.Overseer Overseer (id=98587569806573579-127.0.0.1:41137_solr-n_0000000000) starting
[junit4] 2> 886485 INFO (zkCallback-1593-thread-1-processing-n:127.0.0.1:45995_solr) [n:127.0.0.1:45995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 886486 INFO (zkCallback-1595-thread-1-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 886486 INFO (zkCallback-1593-thread-1-processing-n:127.0.0.1:45995_solr) [n:127.0.0.1:45995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 886487 INFO (zkCallback-1592-thread-1-processing-n:127.0.0.1:46337_solr) [n:127.0.0.1:46337_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 886487 INFO (zkCallback-1594-thread-1-processing-n:127.0.0.1:41209_solr) [n:127.0.0.1:41209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 886486 INFO (zkCallback-1595-thread-1-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 886495 INFO (jetty-launcher-1573-thread-3) [n:127.0.0.1:41137_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41137_solr
[junit4] 2> 886496 INFO (zkCallback-1594-thread-1-processing-n:127.0.0.1:41209_solr) [n:127.0.0.1:41209_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 886496 INFO (zkCallback-1595-thread-1-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 886499 INFO (zkCallback-1593-thread-1-processing-n:127.0.0.1:45995_solr) [n:127.0.0.1:45995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 886502 INFO (zkCallback-1592-thread-2-processing-n:127.0.0.1:46337_solr) [n:127.0.0.1:46337_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 886536 INFO (jetty-launcher-1573-thread-2) [n:127.0.0.1:41209_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node2/.
[junit4] 2> 886548 INFO (jetty-launcher-1573-thread-1) [n:127.0.0.1:46337_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node1/.
[junit4] 2> 886548 INFO (jetty-launcher-1573-thread-3) [n:127.0.0.1:41137_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node3/.
[junit4] 2> 886552 INFO (jetty-launcher-1573-thread-4) [n:127.0.0.1:45995_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node4/.
[junit4] 2> 886557 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 886557 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:36213/solr ready
[junit4] 2> 886572 INFO (TEST-CollectionsAPIDistributedZkTest.testNoCollectionSpecified-seed#[997017E60CC6587A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNoCollectionSpecified
[junit4] 2> 886573 INFO (TEST-CollectionsAPIDistributedZkTest.testNoCollectionSpecified-seed#[997017E60CC6587A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 886628 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-002&collection.configName=conf&name=corewithnocollection&action=CREATE&numShards=1&collection=&wt=javabin&version=2
[junit4] 2> 886629 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 886630 INFO (OverseerStateUpdate-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 887635 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 887638 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.IndexSchema [corewithnocollection] Schema name=minimal
[junit4] 2> 887639 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 887639 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.CoreContainer Creating SolrCore 'corewithnocollection' using configuration from collection corewithnocollection, trusted=true
[junit4] 2> 887640 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 887640 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SolrCore [[corewithnocollection] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node3/corewithnocollection], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-002/]
[junit4] 2> 887663 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 887663 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 887663 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 887664 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 887664 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.SolrIndexSearcher Opening [Searcher@45e732e3[corewithnocollection] main]
[junit4] 2> 887664 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 887665 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 887665 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 887665 INFO (searcherExecutor-3642-thread-1-processing-n:127.0.0.1:41137_solr x:corewithnocollection c:corewithnocollection) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SolrCore [corewithnocollection] Registered new searcher Searcher@45e732e3[corewithnocollection] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 887665 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577401118306074624
[junit4] 2> 887667 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 887667 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 887667 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:41137/solr/corewithnocollection/
[junit4] 2> 887668 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 887668 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.SyncStrategy https://127.0.0.1:41137/solr/corewithnocollection/ has no replicas
[junit4] 2> 887668 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 887669 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:41137/solr/corewithnocollection/ shard1
[junit4] 2> 887819 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 887820 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr c:corewithnocollection x:corewithnocollection] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-002&collection.configName=conf&name=corewithnocollection&action=CREATE&numShards=1&collection=&wt=javabin&version=2} status=0 QTime=1191
[junit4] 2> 887822 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-002&collection.configName=conf&name=corewithnocollection2&action=CREATE&numShards=1&wt=javabin&version=2
[junit4] 2> 887823 INFO (OverseerStateUpdate-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 888831 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 888835 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.IndexSchema [corewithnocollection2] Schema name=minimal
[junit4] 2> 888836 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 888836 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.CoreContainer Creating SolrCore 'corewithnocollection2' using configuration from collection corewithnocollection2, trusted=true
[junit4] 2> 888836 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 888836 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SolrCore [[corewithnocollection2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node3/corewithnocollection2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-002/]
[junit4] 2> 888856 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 888856 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 888856 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 888856 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 888857 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.SolrIndexSearcher Opening [Searcher@32a43c21[corewithnocollection2] main]
[junit4] 2> 888857 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 888858 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 888858 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 888858 INFO (searcherExecutor-3647-thread-1-processing-n:127.0.0.1:41137_solr x:corewithnocollection2 c:corewithnocollection2) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SolrCore [corewithnocollection2] Registered new searcher Searcher@32a43c21[corewithnocollection2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 888858 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577401119557025792
[junit4] 2> 888861 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 888861 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 888861 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:41137/solr/corewithnocollection2/
[junit4] 2> 888861 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 888861 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.SyncStrategy https://127.0.0.1:41137/solr/corewithnocollection2/ has no replicas
[junit4] 2> 888861 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 888863 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:41137/solr/corewithnocollection2/ shard1
[junit4] 2> 889014 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 889014 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr c:corewithnocollection2 x:corewithnocollection2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-002&collection.configName=conf&name=corewithnocollection2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=1192
[junit4] 2> 889015 INFO (TEST-CollectionsAPIDistributedZkTest.testNoCollectionSpecified-seed#[997017E60CC6587A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNoCollectionSpecified
[junit4] 2> 889037 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[997017E60CC6587A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting deletePartiallyCreatedCollection
[junit4] 2> 889037 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[997017E60CC6587A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 889039 INFO (qtp234892850-11397) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=corewithnocollection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 889040 INFO (OverseerThreadFactory-3633-thread-1-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 889043 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.corewithnocollection
[junit4] 2> 889043 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.c.SolrCore [corewithnocollection] CLOSING SolrCore org.apache.solr.core.SolrCore@22fbecbe
[junit4] 2> 889043 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.corewithnocollection
[junit4] 2> 889044 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=corewithnocollection&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 889747 INFO (qtp234892850-11397) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=corewithnocollection&action=DELETE&wt=javabin&version=2} status=0 QTime=708
[junit4] 2> 889749 INFO (qtp234892850-11399) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=corewithnocollection2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 889751 INFO (OverseerCollectionConfigSetProcessor-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_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> 889751 INFO (OverseerThreadFactory-3633-thread-2-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 889752 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.corewithnocollection2
[junit4] 2> 889752 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.c.SolrCore [corewithnocollection2] CLOSING SolrCore org.apache.solr.core.SolrCore@12012d4e
[junit4] 2> 889753 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.corewithnocollection2
[junit4] 2> 889753 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=corewithnocollection2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 890455 INFO (qtp234892850-11399) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=corewithnocollection2&action=DELETE&wt=javabin&version=2} status=0 QTime=706
[junit4] 2> 890458 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-003&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2
[junit4] 2> 890459 INFO (OverseerStateUpdate-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 891463 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 891466 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 891468 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 891468 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 891468 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 891468 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node3/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-003/]
[junit4] 2> 891493 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 891493 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 891493 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 891493 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 891494 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@68d9b300[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 891494 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 891495 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 891495 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 891495 INFO (searcherExecutor-3652-thread-1-processing-n:127.0.0.1:41137_solr x:halfdeletedcollection_shard1_replica1 c:halfdeletedcollection) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@68d9b300[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 891495 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577401122322120704
[junit4] 2> 891498 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 891498 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 891498 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:41137/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 891498 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 891498 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:41137/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 891498 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 891499 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:41137/solr/halfdeletedcollection_shard1_replica1/ shard2
[junit4] 2> 891604 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 891611 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr c:halfdeletedcollection x:halfdeletedcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-003&collection.configName=conf&name=halfdeletedcollection_shard1_replica1&action=CREATE&numShards=2&collection=halfdeletedcollection&wt=javabin&version=2} status=0 QTime=1153
[junit4] 2> 891613 INFO (qtp234892850-11397) [n:127.0.0.1:41137_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> 891614 INFO (OverseerCollectionConfigSetProcessor-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_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> 891614 INFO (OverseerThreadFactory-3633-thread-3-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 891616 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 891616 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4b0a3d37
[junit4] 2> 891618 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 891619 INFO (qtp234892850-11365) [n:127.0.0.1:41137_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=3
[junit4] 2> 892321 INFO (qtp234892850-11397) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=halfdeletedcollection&action=DELETE&wt=javabin&version=2} status=0 QTime=708
[junit4] 2> 892323 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 892323 INFO (qtp234892850-11393) [n:127.0.0.1:41137_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> 892324 INFO (qtp234892850-11373) [n:127.0.0.1:41137_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> 892325 INFO (OverseerThreadFactory-3633-thread-4-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.CreateCollectionCmd Create collection halfdeletedcollection
[junit4] 2> 892325 INFO (OverseerCollectionConfigSetProcessor-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_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> 892580 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_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> 892581 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 892584 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_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> 892584 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 892686 INFO (zkCallback-1593-thread-2-processing-n:127.0.0.1:45995_solr) [n:127.0.0.1:45995_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> 892686 INFO (zkCallback-1594-thread-1-processing-n:127.0.0.1:41209_solr) [n:127.0.0.1:41209_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> 893587 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 893599 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 893600 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard2_replica1] Schema name=minimal
[junit4] 2> 893601 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_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> 893601 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard2_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 893602 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 893602 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node4/halfdeletedcollection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node4/./halfdeletedcollection_shard2_replica1/data/]
[junit4] 2> 893603 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.IndexSchema [halfdeletedcollection_shard1_replica1] Schema name=minimal
[junit4] 2> 893604 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_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> 893604 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'halfdeletedcollection_shard1_replica1' using configuration from collection halfdeletedcollection, trusted=true
[junit4] 2> 893604 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 893604 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [[halfdeletedcollection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node2/halfdeletedcollection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node2/./halfdeletedcollection_shard1_replica1/data/]
[junit4] 2> 893619 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 893619 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 893619 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 893619 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 893620 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7e4450a4[halfdeletedcollection_shard2_replica1] main]
[junit4] 2> 893620 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 893620 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 893620 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 893621 INFO (searcherExecutor-3657-thread-1-processing-n:127.0.0.1:45995_solr x:halfdeletedcollection_shard2_replica1 s:shard2 c:halfdeletedcollection) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] Registered new searcher Searcher@7e4450a4[halfdeletedcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 893621 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577401124551393280
[junit4] 2> 893624 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 893624 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 893624 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:45995/solr/halfdeletedcollection_shard2_replica1/
[junit4] 2> 893624 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 893624 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:45995/solr/halfdeletedcollection_shard2_replica1/ has no replicas
[junit4] 2> 893624 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 893625 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:45995/solr/halfdeletedcollection_shard2_replica1/ shard2
[junit4] 2> 893627 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 893627 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 893627 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 893627 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 893628 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@ad402c7[halfdeletedcollection_shard1_replica1] main]
[junit4] 2> 893628 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 893628 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 893628 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 893629 INFO (searcherExecutor-3658-thread-1-processing-n:127.0.0.1:41209_solr x:halfdeletedcollection_shard1_replica1 s:shard1 c:halfdeletedcollection) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] Registered new searcher Searcher@ad402c7[halfdeletedcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 893629 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577401124559781888
[junit4] 2> 893631 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 893631 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 893631 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:41209/solr/halfdeletedcollection_shard1_replica1/
[junit4] 2> 893631 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 893631 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:41209/solr/halfdeletedcollection_shard1_replica1/ has no replicas
[junit4] 2> 893631 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 893632 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:41209/solr/halfdeletedcollection_shard1_replica1/ shard1
[junit4] 2> 893733 INFO (zkCallback-1594-thread-1-processing-n:127.0.0.1:41209_solr) [n:127.0.0.1:41209_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> 893733 INFO (zkCallback-1593-thread-2-processing-n:127.0.0.1:45995_solr) [n:127.0.0.1:45995_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> 893776 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 x:halfdeletedcollection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 893776 INFO (qtp1743994996-11364) [n:127.0.0.1:45995_solr c:halfdeletedcollection s:shard2 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=1196
[junit4] 2> 893782 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 x:halfdeletedcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 893783 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr c:halfdeletedcollection s:shard1 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=1199
[junit4] 2> 893784 INFO (qtp234892850-11373) [n:127.0.0.1:41137_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> 893885 INFO (zkCallback-1594-thread-1-processing-n:127.0.0.1:41209_solr) [n:127.0.0.1:41209_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> 893885 INFO (zkCallback-1593-thread-2-processing-n:127.0.0.1:45995_solr) [n:127.0.0.1:45995_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> 894326 INFO (OverseerCollectionConfigSetProcessor-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_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> 894785 INFO (qtp234892850-11373) [n:127.0.0.1:41137_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=2460
[junit4] 2> 894786 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 894787 INFO (qtp234892850-11365) [n:127.0.0.1:41137_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> 894787 INFO (TEST-CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection-seed#[997017E60CC6587A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending deletePartiallyCreatedCollection
[junit4] 2> 894805 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[997017E60CC6587A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateNodeSet
[junit4] 2> 894806 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[997017E60CC6587A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 894807 INFO (qtp234892850-11397) [n:127.0.0.1:41137_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> 894811 INFO (OverseerThreadFactory-3633-thread-5-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 894813 INFO (qtp1743994996-11374) [n:127.0.0.1:45995_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard2.replica1
[junit4] 2> 894813 INFO (qtp1069893369-11381) [n:127.0.0.1:41209_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 894813 INFO (qtp1743994996-11374) [n:127.0.0.1:45995_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@49284e74
[junit4] 2> 894814 INFO (qtp1069893369-11381) [n:127.0.0.1:41209_solr ] o.a.s.c.SolrCore [halfdeletedcollection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1fbe4b3
[junit4] 2> 894816 INFO (qtp1069893369-11381) [n:127.0.0.1:41209_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard1.replica1
[junit4] 2> 894816 INFO (qtp1743994996-11374) [n:127.0.0.1:45995_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.halfdeletedcollection.shard2.replica1
[junit4] 2> 894817 INFO (qtp1743994996-11374) [n:127.0.0.1:45995_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=4
[junit4] 2> 894817 INFO (qtp1069893369-11381) [n:127.0.0.1:41209_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> 895519 INFO (qtp234892850-11397) [n:127.0.0.1:41137_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> 895521 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf&name=nodeset_collection&action=CREATE&numShards=2&createNodeSet=https://127.0.0.1:45995/solr,https://127.0.0.1:45995/solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 895522 INFO (OverseerThreadFactory-3633-thread-5-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.CreateCollectionCmd Create collection nodeset_collection
[junit4] 2> 895522 INFO (OverseerCollectionConfigSetProcessor-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_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> 895522 WARN (OverseerThreadFactory-3633-thread-5-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.CreateCollectionCmd It is unusual to create a collection (nodeset_collection) without cores.
[junit4] 2> 895724 INFO (qtp234892850-11393) [n:127.0.0.1:41137_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> 895724 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf&name=nodeset_collection&action=CREATE&numShards=2&createNodeSet=https://127.0.0.1:45995/solr,https://127.0.0.1:45995/solr&wt=javabin&version=2} status=0 QTime=203
[junit4] 2> 895725 INFO (TEST-CollectionsAPIDistributedZkTest.testCreateNodeSet-seed#[997017E60CC6587A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCreateNodeSet
[junit4] 2> 895748 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionsAPI-seed#[997017E60CC6587A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCollectionsAPI
[junit4] 2> 895748 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionsAPI-seed#[997017E60CC6587A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 895750 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=nodeset_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 895751 INFO (OverseerCollectionConfigSetProcessor-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000010 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 895751 INFO (OverseerThreadFactory-3633-thread-5-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 896453 INFO (qtp234892850-11373) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=nodeset_collection&action=DELETE&wt=javabin&version=2} status=0 QTime=703
[junit4] 2> 896455 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params async=5ecf74db-09f9-4694-a6ac-59222ad78035&replicationFactor=3&collection.configName=conf2&maxShardsPerNode=3&name=awhollynewcollection_0&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 896455 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=5ecf74db-09f9-4694-a6ac-59222ad78035&replicationFactor=3&collection.configName=conf2&maxShardsPerNode=3&name=awhollynewcollection_0&action=CREATE&numShards=3&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 896456 INFO (OverseerThreadFactory-3633-thread-5-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.CreateCollectionCmd Create collection awhollynewcollection_0
[junit4] 2> 896456 INFO (OverseerCollectionConfigSetProcessor-98587569806573579-127.0.0.1:41137_solr-n_0000000000) [n:127.0.0.1:41137_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000012 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 896558 INFO (zkCallback-1603-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 896662 INFO (qtp234892850-11399) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780411486072&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard2_replica1&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard2&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 896663 INFO (parallelCoreAdminExecutor-3637-thread-1-processing-n:127.0.0.1:41137_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411486072 CREATE) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780411486072&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard2_replica1&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard2&wt=javabin&version=2
[junit4] 2> 896663 INFO (qtp1743994996-11382) [n:127.0.0.1:45995_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard3_replica1&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard3&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 896663 INFO (parallelCoreAdminExecutor-3640-thread-1-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091 CREATE) [n:127.0.0.1:45995_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard3_replica1&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard3&wt=javabin&version=2
[junit4] 2> 896672 INFO (qtp1069893369-11384) [n:127.0.0.1:41209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard1_replica2&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 896673 INFO (parallelCoreAdminExecutor-3634-thread-1-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873 CREATE) [n:127.0.0.1:41209_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard1_replica2&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard1&wt=javabin&version=2
[junit4] 2> 896694 INFO (qtp1743994996-11380) [n:127.0.0.1:45995_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780411511351&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard1_replica3&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard1&wt=javabin&version=2} status=0 QTime=22
[junit4] 2> 896695 INFO (parallelCoreAdminExecutor-3640-thread-2-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411511351 CREATE) [n:127.0.0.1:45995_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780411511351&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard1_replica3&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard1&wt=javabin&version=2
[junit4] 2> 896695 INFO (qtp1069893369-11367) [n:127.0.0.1:41209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412784510&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard2_replica3&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard2&wt=javabin&version=2} status=0 QTime=18
[junit4] 2> 896695 INFO (parallelCoreAdminExecutor-3634-thread-2-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412784510 CREATE) [n:127.0.0.1:41209_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412784510&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard2_replica3&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard2&wt=javabin&version=2
[junit4] 2> 896695 INFO (qtp234892850-11365) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412627018&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard3_replica2&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard3&wt=javabin&version=2} status=0 QTime=23
[junit4] 2> 896696 INFO (parallelCoreAdminExecutor-3637-thread-2-processing-n:127.0.0.1:41137_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412627018 CREATE) [n:127.0.0.1:41137_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412627018&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard3_replica2&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard3&wt=javabin&version=2
[junit4] 2> 896728 INFO (qtp1483100737-11394) [n:127.0.0.1:46337_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412720513&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard1_replica1&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 896728 INFO (parallelCoreAdminExecutor-3636-thread-1-processing-n:127.0.0.1:46337_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412720513 CREATE) [n:127.0.0.1:46337_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412720513&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard1_replica1&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard1&wt=javabin&version=2
[junit4] 2> 896729 INFO (parallelCoreAdminExecutor-3636-thread-1-processing-n:127.0.0.1:46337_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412720513 CREATE) [n:127.0.0.1:46337_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 896733 INFO (qtp1483100737-11362) [n:127.0.0.1:46337_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412840581&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard2_replica2&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 896733 INFO (parallelCoreAdminExecutor-3636-thread-2-processing-n:127.0.0.1:46337_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412840581 CREATE) [n:127.0.0.1:46337_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412840581&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard2_replica2&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard2&wt=javabin&version=2
[junit4] 2> 896734 INFO (qtp1483100737-11368) [n:127.0.0.1:46337_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412895138&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard3_replica3&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard3&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 896735 INFO (parallelCoreAdminExecutor-3636-thread-3-processing-n:127.0.0.1:46337_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412895138 CREATE) [n:127.0.0.1:46337_solr ] o.a.s.h.a.CoreAdminOperation core create command async=5ecf74db-09f9-4694-a6ac-59222ad78035245780412895138&qt=/admin/cores&collection.configName=conf2&newCollection=true&name=awhollynewcollection_0_shard3_replica3&action=CREATE&numShards=3&collection=awhollynewcollection_0&shard=shard3&wt=javabin&version=2
[junit4] 2> 896738 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : 5ecf74db-09f9-4694-a6ac-59222ad78035245780412784510
[junit4] 2> 896738 INFO (qtp1069893369-11363) [n:127.0.0.1:41209_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=5ecf74db-09f9-4694-a6ac-59222ad78035245780412784510&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 896839 INFO (zkCallback-1593-thread-2-processing-n:127.0.0.1:45995_solr) [n:127.0.0.1:45995_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 896839 INFO (zkCallback-1592-thread-2-processing-n:127.0.0.1:46337_solr) [n:127.0.0.1:46337_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 896839 INFO (zkCallback-1595-thread-1-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 896839 INFO (zkCallback-1594-thread-1-processing-n:127.0.0.1:41209_solr) [n:127.0.0.1:41209_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 896839 INFO (zkCallback-1603-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/awhollynewcollection_0/state.json] for collection [awhollynewcollection_0] has occurred - updating... (live nodes size: [4])
[junit4] 2> 897680 INFO (parallelCoreAdminExecutor-3640-thread-1-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091 CREATE) [n:127.0.0.1:45995_solr c:awhollynewcollection_0 s:shard3 x:awhollynewcollection_0_shard3_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 897682 INFO (parallelCoreAdminExecutor-3634-thread-1-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873 CREATE) [n:127.0.0.1:41209_solr c:awhollynewcollection_0 s:shard1 x:awhollynewcollection_0_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 897709 INFO (parallelCoreAdminExecutor-3640-thread-1-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091 CREATE) [n:127.0.0.1:45995_solr c:awhollynewcollection_0 s:shard3 x:awhollynewcollection_0_shard3_replica1] o.a.s.s.IndexSchema [awhollynewcollection_0_shard3_replica1] Schema name=minimal
[junit4] 2> 897710 INFO (parallelCoreAdminExecutor-3634-thread-1-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873 CREATE) [n:127.0.0.1:41209_solr c:awhollynewcollection_0 s:shard1 x:awhollynewcollection_0_shard1_replica2] o.a.s.s.IndexSchema [awhollynewcollection_0_shard1_replica2] Schema name=minimal
[junit4] 2> 897711 INFO (parallelCoreAdminExecutor-3640-thread-1-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091 CREATE) [n:127.0.0.1:45995_solr c:awhollynewcollection_0 s:shard3 x:awhollynewcollection_0_shard3_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 897711 INFO (parallelCoreAdminExecutor-3640-thread-1-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091 CREATE) [n:127.0.0.1:45995_solr c:awhollynewcollection_0 s:shard3 x:awhollynewcollection_0_shard3_replica1] o.a.s.c.CoreContainer Creating SolrCore 'awhollynewcollection_0_shard3_replica1' using configuration from collection awhollynewcollection_0, trusted=true
[junit4] 2> 897711 INFO (parallelCoreAdminExecutor-3640-thread-1-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091 CREATE) [n:127.0.0.1:45995_solr c:awhollynewcollection_0 s:shard3 x:awhollynewcollection_0_shard3_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 897712 INFO (parallelCoreAdminExecutor-3640-thread-1-processing-n:127.0.0.1:45995_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780412134091 CREATE) [n:127.0.0.1:45995_solr c:awhollynewcollection_0 s:shard3 x:awhollynewcollection_0_shard3_replica1] o.a.s.c.SolrCore [[awhollynewcollection_0_shard3_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node4/awhollynewcollection_0_shard3_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node4/./awhollynewcollection_0_shard3_replica1/data/]
[junit4] 2> 897712 INFO (parallelCoreAdminExecutor-3634-thread-1-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873 CREATE) [n:127.0.0.1:41209_solr c:awhollynewcollection_0 s:shard1 x:awhollynewcollection_0_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 897712 INFO (parallelCoreAdminExecutor-3634-thread-1-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873 CREATE) [n:127.0.0.1:41209_solr c:awhollynewcollection_0 s:shard1 x:awhollynewcollection_0_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'awhollynewcollection_0_shard1_replica2' using configuration from collection awhollynewcollection_0, trusted=true
[junit4] 2> 897712 INFO (parallelCoreAdminExecutor-3634-thread-1-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873 CREATE) [n:127.0.0.1:41209_solr c:awhollynewcollection_0 s:shard1 x:awhollynewcollection_0_shard1_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 897712 INFO (parallelCoreAdminExecutor-3634-thread-1-processing-n:127.0.0.1:41209_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411415873 CREATE) [n:127.0.0.1:41209_solr c:awhollynewcollection_0 s:shard1 x:awhollynewcollection_0_shard1_replica2] o.a.s.c.SolrCore [[awhollynewcollection_0_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node2/awhollynewcollection_0_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001/tempDir-001/node2/./awhollynewcollection_0_shard1_replica2/data/]
[junit4] 2> 897712 INFO (parallelCoreAdminExecutor-3637-thread-1-processing-n:127.0.0.1:41137_solr 5ecf74db-09f9-4694-a6ac-59222ad78035245780411486072 CREATE) [n:127.0.0.1:41137_solr c:awhollynewcollection_0 s:shard2 x:awhollynewcollection_0_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 897713 INFO (parallelCoreAdminExecutor-36
[...truncated too long message...]
etHandler.java:1699)
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:462)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
[junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 971856 INFO (qtp234892850-11393) [n:127.0.0.1:41137_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:45995_solr&onlyIfLeaderActive=true&core=addReplicaColl_shard1_replica1&coreNodeName=core_node7&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=400 QTime=14010
[junit4] 2> 973261 WARN (zkCallback-1594-thread-4-processing-n:127.0.0.1:41209_solr) [n:127.0.0.1:41209_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 973261 INFO (jetty-closer-1574-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@11d2f132{/solr,null,UNAVAILABLE}
[junit4] 2> 973266 WARN (zkCallback-1595-thread-1-processing-n:127.0.0.1:41137_solr) [n:127.0.0.1:41137_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 973266 INFO (jetty-closer-1574-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@577233ea{/solr,null,UNAVAILABLE}
[junit4] 2> 973272 WARN (zkCallback-1592-thread-4-processing-n:127.0.0.1:46337_solr) [n:127.0.0.1:46337_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 973272 INFO (jetty-closer-1574-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2c9310da{/solr,null,UNAVAILABLE}
[junit4] 2> 973273 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 973273 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:36213 36213
[junit4] 2> 974245 INFO (Thread-4470) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:36213 36213
[junit4] 2> 974246 WARN (Thread-4470) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 19 /solr/configs/conf
[junit4] 2> 16 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 105 /solr/clusterstate.json
[junit4] 2> 16 /solr/clusterprops.json
[junit4] 2> 4 /solr/collections/nodes_used_collection/state.json
[junit4] 2> 4 /solr/collections/addReplicaColl/state.json
[junit4] 2> 4 /solr/collections/reloaded_collection/state.json
[junit4] 2> 3 /solr/collections/acollectionafterbaddelete/state.json
[junit4] 2> 2 /solr/collections/onlyinzk/state.json
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard1/election/98587569806573579-core_node2-n_0000000000
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard1/election/98587569806573578-core_node3-n_0000000001
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard2/election/98587569806573577-core_node4-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 265 /solr/collections
[junit4] 2> 16 /solr/live_nodes
[junit4] 2>
[junit4] 2> 974247 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[997017E60CC6587A]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_997017E60CC6587A-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=FST50}, docValues:{}, maxPointsInLeafNode=1528, maxMBSortInHeap=6.015960292801973, sim=RandomSimilarity(queryNorm=false,coord=crazy): {}, locale=fr-CH, timezone=America/Rio_Branco
[junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=339850992,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [SpatialHeatmapFacetsTest, TestFieldCollectionResource, TestCloudManagedSchema, AnalysisErrorHandlingTest, UUIDUpdateProcessorFallbackTest, PeerSyncWithIndexFingerprintCachingTest, TestFastOutputStream, LeaderFailoverAfterPartitionTest, TestFiltering, MultiTermTest, DistanceFunctionTest, ShardRoutingCustomTest, TestConfigSets, TestLeaderElectionZkExpiry, TestUnifiedSolrHighlighter, TestCharFilters, CloneFieldUpdateProcessorFactoryTest, HdfsDirectoryTest, SegmentsInfoRequestHandlerTest, UpdateRequestProcessorFactoryTest, TestFuzzyAnalyzedSuggestions, DistributedFacetPivotSmallTest, CSVRequestHandlerTest, TestIntervalFaceting, OverseerModifyCollectionTest, ForceLeaderTest, TestManagedStopFilterFactory, TestCollationFieldDocValues, TestNumericTerms64, CollectionStateFormat2Test, TermVectorComponentTest, TestFieldCache, TestSchemaManager, TestOrdValues, TestFieldCacheSort, CoreAdminRequestStatusTest, URLClassifyProcessorTest, TestGraphTermsQParserPlugin, ZkStateReaderTest, PreAnalyzedFieldManagedSchemaCloudTest, SpellCheckCollatorTest, TestReqParamsAPI, TestSweetSpotSimilarityFactory, SolrCloudExampleTest, SampleTest, TestSmileRequest, DistributedFacetPivotLargeTest, LeaderInitiatedRecoveryOnShardRestartTest, TestRTGBase, TestChildDocTransformer, TestRandomRequestDistribution, TestCollectionAPIs, InfixSuggestersTest, SpellCheckCollatorWithCollapseTest, TestReloadDeadlock, SortByFunctionTest, JSONWriterTest, TestSearchPerf, HdfsThreadLeakTest, CheckHdfsIndexTest, TestConfigOverlay, BlockJoinFacetDistribTest, TestSystemCollAutoCreate, CdcrBootstrapTest, DeleteInactiveReplicaTest, RemoteQueryErrorTest, DocValuesTest, RestartWhileUpdatingTest, HighlighterTest, DistributedDebugComponentTest, DocumentBuilderTest, EchoParamsTest, ZkCLITest, TestLRUCache, SystemInfoHandlerTest, TestFileDictionaryLookup, BasicFunctionalityTest, TestQueryTypes, ChaosMonkeySafeLeaderTest, CdcrRequestHandlerTest, BlockCacheTest, CopyFieldTest, TestMiniSolrCloudClusterSSL, SharedFSAutoReplicaFailoverUtilsTest, TestObjectReleaseTracker, TestDynamicLoading, TestSimpleTrackingShardHandler, TestFieldCacheWithThreads, TestCopyFieldCollectionResource, TestElisionMultitermQuery, TestSuggestSpellingConverter, TestTestInjection, TestCloudPivotFacet, SliceStateTest, TestExclusionRuleCollectionAccess, TestStressCloudBlindAtomicUpdates, PKIAuthenticationIntegrationTest, TestSolrQueryParserDefaultOperatorResource, DistributedQueryComponentOptimizationTest, SpellingQueryConverterTest, MoreLikeThisHandlerTest, TermsComponentTest, TestSolrCoreSnapshots, IndexSchemaRuntimeFieldTest, TestSchemaSimilarityResource, SolrJmxReporterCloudTest, TestSurroundQueryParser, TestMaxScoreQueryParser, TestClusterProperties, DistributedQueueTest, TestCloudDeleteByQuery, TestCustomSort, SpatialFilterTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [365/713 (1!)] on J1 in 87.93s, 20 tests, 1 failure <<< FAILURES!
[...truncated 44613 lines...]