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/03/10 02:50:51 UTC
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1183 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1183/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Error from server at http://127.0.0.1:48825/solr/awhollynewcollection_0: Expected mime type application/octet-stream but got text/html. <html> <head> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/> <title>Error 510 </title> </head> <body> <h2>HTTP ERROR: 510</h2> <p>Problem accessing /solr/awhollynewcollection_0/select. Reason: <pre> {metadata={error-class=org.apache.solr.common.SolrException,root-error-class=org.apache.solr.common.SolrException},msg={"awhollynewcollection_0":6},code=510}</pre></p> <hr /><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.3.14.v20161028</a><hr/> </body> </html>
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:48825/solr/awhollynewcollection_0: Expected mime type application/octet-stream but got text/html. <html>
<head>
<meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
<title>Error 510 </title>
</head>
<body>
<h2>HTTP ERROR: 510</h2>
<p>Problem accessing /solr/awhollynewcollection_0/select. Reason:
<pre> {metadata={error-class=org.apache.solr.common.SolrException,root-error-class=org.apache.solr.common.SolrException},msg={"awhollynewcollection_0":6},code=510}</pre></p>
<hr /><a href="http://eclipse.org/jetty">Powered by Jetty:// 9.3.14.v20161028</a><hr/>
</body>
</html>
at __randomizedtesting.SeedInfo.seed([EF11849929B5888A:A764F02D2F86A71F]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:595)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:279)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:268)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:439)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:391)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1361)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1112)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1215)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1215)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1215)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1215)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1215)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:1042)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:160)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:942)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:523)
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:745)
Build Log:
[...truncated 11935 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/init-core-data-001
[junit4] 2> 1567980 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=358 numCloses=358
[junit4] 2> 1567980 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 1567982 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-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> 1567984 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001
[junit4] 2> 1567984 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1567984 INFO (Thread-8456) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1567984 INFO (Thread-8456) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1568096 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:59505
[junit4] 2> 1568111 INFO (jetty-launcher-2275-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1568113 INFO (jetty-launcher-2275-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1568114 INFO (jetty-launcher-2275-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1568126 INFO (jetty-launcher-2275-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4c395ca5{/solr,null,AVAILABLE}
[junit4] 2> 1568130 INFO (jetty-launcher-2275-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@45392166{HTTP/1.1,[http/1.1]}{127.0.0.1:48825}
[junit4] 2> 1568130 INFO (jetty-launcher-2275-thread-1) [ ] o.e.j.s.Server Started @1573087ms
[junit4] 2> 1568130 INFO (jetty-launcher-2275-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=48825}
[junit4] 2> 1568130 ERROR (jetty-launcher-2275-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1568131 INFO (jetty-launcher-2275-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1568131 INFO (jetty-launcher-2275-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1568131 INFO (jetty-launcher-2275-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1568131 INFO (jetty-launcher-2275-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-10T02:08:42.450Z
[junit4] 2> 1568138 INFO (jetty-launcher-2275-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@51362e8{/solr,null,AVAILABLE}
[junit4] 2> 1568138 INFO (jetty-launcher-2275-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@12c485c4{HTTP/1.1,[http/1.1]}{127.0.0.1:61489}
[junit4] 2> 1568138 INFO (jetty-launcher-2275-thread-4) [ ] o.e.j.s.Server Started @1573096ms
[junit4] 2> 1568139 INFO (jetty-launcher-2275-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=61489}
[junit4] 2> 1568139 ERROR (jetty-launcher-2275-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1568139 INFO (jetty-launcher-2275-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1568139 INFO (jetty-launcher-2275-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1568139 INFO (jetty-launcher-2275-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1568139 INFO (jetty-launcher-2275-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-10T02:08:42.458Z
[junit4] 2> 1568142 INFO (jetty-launcher-2275-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1568144 INFO (jetty-launcher-2275-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@713a58b5{/solr,null,AVAILABLE}
[junit4] 2> 1568145 INFO (jetty-launcher-2275-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@392ab69d{HTTP/1.1,[http/1.1]}{127.0.0.1:46227}
[junit4] 2> 1568145 INFO (jetty-launcher-2275-thread-3) [ ] o.e.j.s.Server Started @1573103ms
[junit4] 2> 1568145 INFO (jetty-launcher-2275-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46227}
[junit4] 2> 1568146 ERROR (jetty-launcher-2275-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1568146 INFO (jetty-launcher-2275-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1568146 INFO (jetty-launcher-2275-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1568146 INFO (jetty-launcher-2275-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1568146 INFO (jetty-launcher-2275-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-10T02:08:42.465Z
[junit4] 2> 1568153 INFO (jetty-launcher-2275-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5739f0cb{/solr,null,AVAILABLE}
[junit4] 2> 1568154 INFO (jetty-launcher-2275-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@13b777ee{HTTP/1.1,[http/1.1]}{127.0.0.1:52775}
[junit4] 2> 1568154 INFO (jetty-launcher-2275-thread-2) [ ] o.e.j.s.Server Started @1573111ms
[junit4] 2> 1568154 INFO (jetty-launcher-2275-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52775}
[junit4] 2> 1568154 ERROR (jetty-launcher-2275-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1568154 INFO (jetty-launcher-2275-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0
[junit4] 2> 1568155 INFO (jetty-launcher-2275-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1568155 INFO (jetty-launcher-2275-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1568155 INFO (jetty-launcher-2275-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-03-10T02:08:42.474Z
[junit4] 2> 1568162 INFO (jetty-launcher-2275-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1568167 INFO (jetty-launcher-2275-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1568175 INFO (jetty-launcher-2275-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1568185 INFO (jetty-launcher-2275-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1568185 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 0x15ab5f9a9410001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1568194 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 0x15ab5f9a9410004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1568195 INFO (jetty-launcher-2275-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59505/solr
[junit4] 2> 1568196 INFO (jetty-launcher-2275-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59505/solr
[junit4] 2> 1568210 INFO (jetty-launcher-2275-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59505/solr
[junit4] 2> 1568213 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 0x15ab5f9a9410005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 1568217 INFO (jetty-launcher-2275-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59505/solr
[junit4] 2> 1568267 INFO (jetty-launcher-2275-thread-1) [n:127.0.0.1:48825_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1568268 INFO (jetty-launcher-2275-thread-2) [n:127.0.0.1:52775_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1568269 INFO (jetty-launcher-2275-thread-1) [n:127.0.0.1:48825_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:48825_solr
[junit4] 2> 1568269 INFO (jetty-launcher-2275-thread-3) [n:127.0.0.1:46227_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1568269 INFO (jetty-launcher-2275-thread-4) [n:127.0.0.1:61489_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1568271 INFO (jetty-launcher-2275-thread-1) [n:127.0.0.1:48825_solr ] o.a.s.c.Overseer Overseer (id=97590425832980488-127.0.0.1:48825_solr-n_0000000000) starting
[junit4] 2> 1568272 INFO (jetty-launcher-2275-thread-3) [n:127.0.0.1:46227_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46227_solr
[junit4] 2> 1568272 INFO (jetty-launcher-2275-thread-2) [n:127.0.0.1:52775_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52775_solr
[junit4] 2> 1568272 INFO (jetty-launcher-2275-thread-4) [n:127.0.0.1:61489_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61489_solr
[junit4] 2> 1568278 INFO (zkCallback-2296-thread-1-processing-n:127.0.0.1:52775_solr) [n:127.0.0.1:52775_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 1568296 INFO (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 1568296 INFO (zkCallback-2292-thread-1-processing-n:127.0.0.1:61489_solr) [n:127.0.0.1:61489_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 1568326 INFO (zkCallback-2291-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 1568351 INFO (jetty-launcher-2275-thread-1) [n:127.0.0.1:48825_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48825_solr
[junit4] 2> 1568354 INFO (zkCallback-2296-thread-1-processing-n:127.0.0.1:52775_solr) [n:127.0.0.1:52775_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1568354 INFO (zkCallback-2292-thread-1-processing-n:127.0.0.1:61489_solr) [n:127.0.0.1:61489_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1568355 INFO (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1568356 INFO (zkCallback-2291-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1568449 INFO (jetty-launcher-2275-thread-4) [n:127.0.0.1:61489_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node3/.
[junit4] 2> 1568579 INFO (jetty-launcher-2275-thread-1) [n:127.0.0.1:48825_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node1/.
[junit4] 2> 1568580 INFO (jetty-launcher-2275-thread-3) [n:127.0.0.1:46227_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node4/.
[junit4] 2> 1568712 INFO (jetty-launcher-2275-thread-2) [n:127.0.0.1:52775_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node2/.
[junit4] 2> 1568932 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1568934 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:59505/solr ready
[junit4] 2> 1568993 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBadActionNames
[junit4] 2> 1568995 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[EF11849929B5888A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1569003 ERROR (qtp1281078435-19053) [n:127.0.0.1:61489_solr ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Unknown action: BADACTION
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:208)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:747)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:728)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:509)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298)
[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:139)
[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:745)
[junit4] 2>
[junit4] 2> 1569004 INFO (qtp1281078435-19053) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=badactioncollection&action=BADACTION&numShards=2&wt=javabin&version=2} status=400 QTime=0
[junit4] 2> 1569004 INFO (TEST-CollectionsAPIDistributedZkTest.testBadActionNames-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBadActionNames
[junit4] 2> 1569047 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMissingRequiredParameters
[junit4] 2> 1569049 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[EF11849929B5888A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1569053 INFO (qtp1281078435-19054) [n:127.0.0.1:61489_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> 1569054 ERROR (qtp1281078435-19054) [n:127.0.0.1:61489_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:461)
[junit4] 2> at org.apache.solr.common.params.SolrParams.getAll(SolrParams.java:478)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler$CollectionOperation.lambda$static$0(CollectionsHandler.java:394)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler$CollectionOperation.execute(CollectionsHandler.java:888)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:226)
[junit4] 2> at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:213)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:747)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:728)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:509)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298)
[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:139)
[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:745)
[junit4] 2>
[junit4] 2> 1569054 INFO (qtp1281078435-19054) [n:127.0.0.1:61489_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> 1569054 INFO (TEST-CollectionsAPIDistributedZkTest.testMissingRequiredParameters-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingRequiredParameters
[junit4] 2> 1569112 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testDeleteNonExistentCollection
[junit4] 2> 1569114 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[EF11849929B5888A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1569119 INFO (qtp1281078435-19055) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=unknown_collection&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1569124 INFO (OverseerThreadFactory-6156-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 1569125 ERROR (OverseerThreadFactory-6156-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: unknown_collection operation: delete failed:org.apache.solr.common.SolrException: Could not find collection : unknown_collection
[junit4] 2> at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:194)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.collectionCmd(OverseerCollectionMessageHandler.java:843)
[junit4] 2> at org.apache.solr.cloud.DeleteCollectionCmd.call(DeleteCollectionCmd.java:88)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1569137 INFO (qtp1281078435-19055) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=unknown_collection&action=DELETE&wt=javabin&version=2} status=400 QTime=18
[junit4] 2> 1569145 INFO (qtp1281078435-19056) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1569148 INFO (OverseerThreadFactory-6156-thread-2-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.CreateCollectionCmd Create collection acollectionafterbaddelete
[junit4] 2> 1569149 INFO (OverseerCollectionConfigSetProcessor-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_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> 1569265 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2
[junit4] 2> 1569265 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2
[junit4] 2> 1569375 INFO (zkCallback-2291-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1569375 INFO (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1570283 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1570283 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1570292 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica1] Schema name=minimal
[junit4] 2> 1570292 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.IndexSchema [acollectionafterbaddelete_shard1_replica2] Schema name=minimal
[junit4] 2> 1570297 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1570297 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1570299 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica1' using configuration from collection acollectionafterbaddelete
[junit4] 2> 1570299 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'acollectionafterbaddelete_shard1_replica2' using configuration from collection acollectionafterbaddelete
[junit4] 2> 1570299 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node1/acollectionafterbaddelete_shard1_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node1/./acollectionafterbaddelete_shard1_replica1/data/]
[junit4] 2> 1570299 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [[acollectionafterbaddelete_shard1_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node4/acollectionafterbaddelete_shard1_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node4/./acollectionafterbaddelete_shard1_replica2/data/]
[junit4] 2> 1570372 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1570372 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1570373 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1570373 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1570374 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3276799d[acollectionafterbaddelete_shard1_replica1] main]
[junit4] 2> 1570376 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 1570376 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 1570376 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1570376 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561446815833784320
[junit4] 2> 1570380 INFO (searcherExecutor-6165-thread-1-processing-n:127.0.0.1:48825_solr x:acollectionafterbaddelete_shard1_replica1 s:shard1 c:acollectionafterbaddelete) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] Registered new searcher Searcher@3276799d[acollectionafterbaddelete_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1570386 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 1570399 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1570399 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1570400 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1570400 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1570401 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@43b0fffe[acollectionafterbaddelete_shard1_replica2] main]
[junit4] 2> 1570402 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 1570403 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 1570403 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1570403 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561446815862095872
[junit4] 2> 1570408 INFO (searcherExecutor-6166-thread-1-processing-n:127.0.0.1:46227_solr x:acollectionafterbaddelete_shard1_replica2 s:shard1 c:acollectionafterbaddelete) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] Registered new searcher Searcher@43b0fffe[acollectionafterbaddelete_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1570490 INFO (zkCallback-2291-thread-3-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1570490 INFO (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1570888 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1570888 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1570888 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48825/solr/acollectionafterbaddelete_shard1_replica1/
[junit4] 2> 1570888 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica1 url=http://127.0.0.1:48825/solr START replicas=[http://127.0.0.1:46227/solr/acollectionafterbaddelete_shard1_replica2/] nUpdates=100
[junit4] 2> 1570889 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=acollectionafterbaddelete_shard1_replica1 url=http://127.0.0.1:48825/solr DONE. We have no versions. sync failed.
[junit4] 2> 1570892 INFO (qtp1792954279-19078) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 r:core_node1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.c.S.Request [acollectionafterbaddelete_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 1570893 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 1570893 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 1570893 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1570900 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48825/solr/acollectionafterbaddelete_shard1_replica1/ shard1
[junit4] 2> 1571007 INFO (zkCallback-2291-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1571007 INFO (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1571054 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1571059 INFO (qtp1930759545-19044) [n:127.0.0.1:48825_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica1&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=1795
[junit4] 2> 1571162 INFO (zkCallback-2291-thread-3-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1571162 INFO (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1571414 INFO (qtp1792954279-19076) [n:127.0.0.1:46227_solr c:acollectionafterbaddelete s:shard1 x:acollectionafterbaddelete_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=acollectionafterbaddelete_shard1_replica2&action=CREATE&numShards=1&collection=acollectionafterbaddelete&shard=shard1&wt=javabin&version=2} status=0 QTime=2150
[junit4] 2> 1571418 INFO (qtp1281078435-19056) [n:127.0.0.1:61489_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> 1571517 INFO (zkCallback-2291-thread-2-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1571517 INFO (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/acollectionafterbaddelete/state.json] for collection [acollectionafterbaddelete] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1572424 INFO (qtp1281078435-19056) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=acollectionafterbaddelete&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=3280
[junit4] 2> 1572427 INFO (TEST-CollectionsAPIDistributedZkTest.testDeleteNonExistentCollection-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testDeleteNonExistentCollection
[junit4] 2> 1572495 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSpecificConfigsets
[junit4] 2> 1572497 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[EF11849929B5888A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1572500 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1572505 INFO (OverseerCollectionConfigSetProcessor-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_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> 1572505 INFO (OverseerThreadFactory-6156-thread-3-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 1572508 INFO (qtp1792954279-19064) [n:127.0.0.1:46227_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica2, tag=null
[junit4] 2> 1572508 INFO (qtp1792954279-19064) [n:127.0.0.1:46227_solr ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@a08878c
[junit4] 2> 1572509 INFO (qtp1792954279-19064) [n:127.0.0.1:46227_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica2, tag=168331148
[junit4] 2> 1572510 INFO (qtp1930759545-19046) [n:127.0.0.1:48825_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica1, tag=null
[junit4] 2> 1572510 INFO (qtp1930759545-19046) [n:127.0.0.1:48825_solr ] o.a.s.c.SolrCore [acollectionafterbaddelete_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@6984f725
[junit4] 2> 1572511 INFO (qtp1930759545-19046) [n:127.0.0.1:48825_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.acollectionafterbaddelete.shard1.replica1, tag=1770321701
[junit4] 2> 1572512 INFO (qtp1792954279-19064) [n:127.0.0.1:46227_solr ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral leader parent node, won't remove previous leader registration.
[junit4] 2> 1572512 INFO (qtp1792954279-19064) [n:127.0.0.1:46227_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica2&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 1572514 WARN (zkCallback-2297-thread-1-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.LeaderElector Our node is no longer in line to be leader
[junit4] 2> 1572515 INFO (qtp1930759545-19046) [n:127.0.0.1:48825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=acollectionafterbaddelete_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1573230 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=acollectionafterbaddelete&action=DELETE&wt=javabin&version=2} status=0 QTime=730
[junit4] 2> 1573232 INFO (qtp1281078435-19058) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1573237 INFO (OverseerThreadFactory-6156-thread-4-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.CreateCollectionCmd Create collection withconfigset2
[junit4] 2> 1573237 INFO (OverseerCollectionConfigSetProcessor-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_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> 1573448 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2
[junit4] 2> 1573557 INFO (zkCallback-2291-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1574462 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1574471 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.IndexSchema [withconfigset2_shard1_replica1] Schema name=minimal
[junit4] 2> 1574474 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1574476 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'withconfigset2_shard1_replica1' using configuration from collection withconfigset2
[junit4] 2> 1574477 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrCore [[withconfigset2_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node1/withconfigset2_shard1_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node1/./withconfigset2_shard1_replica1/data/]
[junit4] 2> 1574477 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3c033d2b
[junit4] 2> 1574537 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1574537 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1574538 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1574538 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1574539 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1f2034d6[withconfigset2_shard1_replica1] main]
[junit4] 2> 1574550 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf2
[junit4] 2> 1574551 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf2
[junit4] 2> 1574551 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1574552 INFO (searcherExecutor-6175-thread-1-processing-n:127.0.0.1:48825_solr x:withconfigset2_shard1_replica1 s:shard1 c:withconfigset2) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] Registered new searcher Searcher@1f2034d6[withconfigset2_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1574552 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561446820212637696
[junit4] 2> 1574569 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1574569 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1574569 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48825/solr/withconfigset2_shard1_replica1/
[junit4] 2> 1574569 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1574569 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.SyncStrategy http://127.0.0.1:48825/solr/withconfigset2_shard1_replica1/ has no replicas
[junit4] 2> 1574569 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1574575 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48825/solr/withconfigset2_shard1_replica1/ shard1
[junit4] 2> 1574684 INFO (zkCallback-2291-thread-1-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1574728 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1574733 INFO (qtp1930759545-19042) [n:127.0.0.1:48825_solr c:withconfigset2 s:shard1 x:withconfigset2_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf2&newCollection=true&name=withconfigset2_shard1_replica1&action=CREATE&numShards=1&collection=withconfigset2&shard=shard1&wt=javabin&version=2} status=0 QTime=1286
[junit4] 2> 1574736 INFO (qtp1281078435-19058) [n:127.0.0.1:61489_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> 1574834 INFO (zkCallback-2291-thread-3-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/withconfigset2/state.json] for collection [withconfigset2] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1575242 INFO (OverseerCollectionConfigSetProcessor-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_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> 1575743 INFO (qtp1281078435-19058) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=conf2&name=withconfigset2&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=2513
[junit4] 2> 1575745 INFO (TEST-CollectionsAPIDistributedZkTest.testSpecificConfigsets-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSpecificConfigsets
[junit4] 2> 1575810 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNoConfigSetExist
[junit4] 2> 1575812 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[EF11849929B5888A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1575815 INFO (qtp1281078435-19075) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=withconfigset2&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1575819 INFO (OverseerThreadFactory-6156-thread-5-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 1575822 INFO (qtp1930759545-19045) [n:127.0.0.1:48825_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.withconfigset2.shard1.replica1, tag=null
[junit4] 2> 1575822 INFO (qtp1930759545-19045) [n:127.0.0.1:48825_solr ] o.a.s.c.SolrCore [withconfigset2_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4c7a875f
[junit4] 2> 1575849 INFO (qtp1930759545-19045) [n:127.0.0.1:48825_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.withconfigset2.shard1.replica1, tag=1283098463
[junit4] 2> 1575853 INFO (qtp1930759545-19045) [n:127.0.0.1:48825_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&core=withconfigset2_shard1_replica1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=31
[junit4] 2> 1576565 INFO (qtp1281078435-19075) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=withconfigset2&action=DELETE&wt=javabin&version=2} status=0 QTime=750
[junit4] 2> 1576568 INFO (qtp1281078435-19093) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CoreAdminOperation core create command dataDir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-002&collection.configName=conf123&name=corewithnocollection3&action=CREATE&numShards=1&collection=&wt=javabin&version=2
[junit4] 2> 1576571 INFO (OverseerStateUpdate-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_solr ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1577579 ERROR (qtp1281078435-19093) [n:127.0.0.1:61489_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.c.c.ZkStateReader Specified config=[conf123] does not exist in ZooKeeper at location=[/configs/conf123]
[junit4] 2> 1577581 ERROR (qtp1281078435-19093) [n:127.0.0.1:61489_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Error CREATEing SolrCore 'corewithnocollection3': Unable to create core [corewithnocollection3] Caused by: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:919)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:370)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388)
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174)
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:173)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:747)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:728)
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:509)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347)
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298)
[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:139)
[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:745)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: Unable to create core [corewithnocollection3]
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:964)
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:885)
[junit4] 2> ... 34 more
[junit4] 2> Caused by: org.apache.solr.common.cloud.ZooKeeperException: Specified config does not exist in ZooKeeper: conf123
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.readConfigName(ZkStateReader.java:189)
[junit4] 2> at org.apache.solr.cloud.CloudConfigSetService.createCoreResourceLoader(CloudConfigSetService.java:54)
[junit4] 2> at org.apache.solr.core.ConfigSetService.getConfig(ConfigSetService.java:74)
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:946)
[junit4] 2> ... 35 more
[junit4] 2>
[junit4] 2> 1577581 INFO (qtp1281078435-19093) [n:127.0.0.1:61489_solr c:corewithnocollection3 x:corewithnocollection3] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={dataDir=/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-002&collection.configName=conf123&name=corewithnocollection3&action=CREATE&numShards=1&collection=&wt=javabin&version=2} status=400 QTime=1014
[junit4] 2> 1577821 INFO (OverseerCollectionConfigSetProcessor-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_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> 1578585 INFO (qtp1281078435-19059) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :list with params action=LIST&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1578585 INFO (qtp1281078435-19059) [n:127.0.0.1:61489_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> 1578586 INFO (TEST-CollectionsAPIDistributedZkTest.testNoConfigSetExist-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNoConfigSetExist
[junit4] 2> 1578627 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testZeroNumShards
[junit4] 2> 1578628 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[EF11849929B5888A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1578634 INFO (qtp1281078435-19053) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=corewithnocollection3&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1578642 INFO (OverseerThreadFactory-6156-thread-5-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true
[junit4] 2> 1579353 INFO (qtp1281078435-19053) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=corewithnocollection3&action=DELETE&wt=javabin&version=2} status=0 QTime=719
[junit4] 2> 1579355 INFO (qtp1281078435-19054) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1579358 INFO (OverseerThreadFactory-6156-thread-5-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.CreateCollectionCmd Create collection acollection
[junit4] 2> 1579359 ERROR (OverseerThreadFactory-6156-thread-5-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: acollection operation: create failed:org.apache.solr.common.SolrException: numShards must be > 0
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:124)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:224)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:463)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1579359 INFO (OverseerCollectionConfigSetProcessor-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_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> 1579363 INFO (qtp1281078435-19054) [n:127.0.0.1:61489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=acollection&action=CREATE&numShards=0&wt=javabin&version=2} status=400 QTime=8
[junit4] 2> 1579363 INFO (TEST-CollectionsAPIDistributedZkTest.testZeroNumShards-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testZeroNumShards
[junit4] 2> 1579421 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[EF11849929B5888A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting addReplicaTest
[junit4] 2> 1579423 INFO (TEST-CollectionsAPIDistributedZkTest.addReplicaTest-seed#[EF11849929B5888A]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1579426 INFO (qtp1281078435-19055) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&maxShardsPerNode=4&name=addReplicaColl&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1579430 INFO (OverseerThreadFactory-6156-thread-5-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.CreateCollectionCmd Create collection addReplicaColl
[junit4] 2> 1579431 INFO (OverseerCollectionConfigSetProcessor-97590425832980488-127.0.0.1:48825_solr-n_0000000000) [n:127.0.0.1:48825_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> 1579643 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
[junit4] 2> 1579644 INFO (qtp1792954279-19065) [n:127.0.0.1:46227_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard1_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard1&wt=javabin&version=2
[junit4] 2> 1579648 INFO (qtp1930759545-19043) [n:127.0.0.1:48825_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica2&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
[junit4] 2> 1579648 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=addReplicaColl_shard2_replica1&action=CREATE&numShards=2&collection=addReplicaColl&shard=shard2&wt=javabin&version=2
[junit4] 2> 1579765 INFO (zkCallback-2296-thread-1-processing-n:127.0.0.1:52775_solr) [n:127.0.0.1:52775_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1579765 INFO (zkCallback-2297-thread-2-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1579765 INFO (zkCallback-2292-thread-2-processing-n:127.0.0.1:61489_solr) [n:127.0.0.1:61489_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1579766 INFO (zkCallback-2291-thread-4-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/addReplicaColl/state.json] for collection [addReplicaColl] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1580661 INFO (qtp1792954279-19065) [n:127.0.0.1:46227_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1580661 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1580683 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1580690 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica1] Schema name=minimal
[junit4] 2> 1580690 INFO (qtp1792954279-19065) [n:127.0.0.1:46227_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.s.IndexSchema [addReplicaColl_shard1_replica2] Schema name=minimal
[junit4] 2> 1580693 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica1] Schema name=minimal
[junit4] 2> 1580694 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1580694 INFO (qtp1792954279-19065) [n:127.0.0.1:46227_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1580696 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica1' using configuration from collection addReplicaColl
[junit4] 2> 1580697 INFO (qtp1792954279-19065) [n:127.0.0.1:46227_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard1_replica2' using configuration from collection addReplicaColl
[junit4] 2> 1580697 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1580697 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node3/addReplicaColl_shard1_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node3/./addReplicaColl_shard1_replica1/data/]
[junit4] 2> 1580697 INFO (qtp1792954279-19065) [n:127.0.0.1:46227_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica2] o.a.s.c.SolrCore [[addReplicaColl_shard1_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node4/addReplicaColl_shard1_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node4/./addReplicaColl_shard1_replica2/data/]
[junit4] 2> 1580700 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica1' using configuration from collection addReplicaColl
[junit4] 2> 1580700 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node2/addReplicaColl_shard2_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node2/./addReplicaColl_shard2_replica1/data/]
[junit4] 2> 1580714 INFO (qtp1930759545-19043) [n:127.0.0.1:48825_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 1580733 INFO (qtp1930759545-19043) [n:127.0.0.1:48825_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.s.IndexSchema [addReplicaColl_shard2_replica2] Schema name=minimal
[junit4] 2> 1580736 INFO (qtp1930759545-19043) [n:127.0.0.1:48825_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 1580737 INFO (qtp1930759545-19043) [n:127.0.0.1:48825_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'addReplicaColl_shard2_replica2' using configuration from collection addReplicaColl
[junit4] 2> 1580737 INFO (qtp1930759545-19043) [n:127.0.0.1:48825_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica2] o.a.s.c.SolrCore [[addReplicaColl_shard2_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node1/addReplicaColl_shard2_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001/tempDir-001/node1/./addReplicaColl_shard2_replica2/data/]
[junit4] 2> 1580785 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1580785 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1580786 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1580786 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1580787 INFO (qtp1281078435-19057) [n:127.0.0.1:61489_solr c:addReplicaColl s:shard1 x:addReplicaColl_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@774cf3f9[addReplicaColl_shard1_replica1] main]
[junit4] 2> 1580791 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1580792 INFO (qtp716179532-19082) [n:127.0.0.1:52775_solr c:addReplicaColl s:shard2 x:addReplicaColl_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1580793 INFO (qtp716179532-19082) [n:127.0
[...truncated too long message...]
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1667579 INFO (jetty-closer-2276-thread-4) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@13b777ee{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1667588 INFO (jetty-closer-2276-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1667588 INFO (jetty-closer-2276-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1667598 WARN (zkCallback-2331-thread-2-processing-n:127.0.0.1:48825_solr) [n:127.0.0.1:48825_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1667599 INFO (jetty-closer-2276-thread-4) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1829669838
[junit4] 2> 1667600 INFO (zkCallback-2297-thread-5-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 1667600 INFO (jetty-closer-2276-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1667601 WARN (zkCallback-2297-thread-5-processing-n:127.0.0.1:46227_solr) [n:127.0.0.1:46227_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1667601 INFO (zkCallback-2292-thread-18-processing-n:127.0.0.1:61489_solr) [n:127.0.0.1:61489_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (2)
[junit4] 2> 1667604 INFO (zkCallback-2296-thread-11-processing-n:127.0.0.1:52775_solr) [n:127.0.0.1:52775_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (2)
[junit4] 2> 1667608 INFO (jetty-closer-2276-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1667610 INFO (jetty-closer-2276-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@713a58b5{/solr,null,UNAVAILABLE}
[junit4] 2> 1667617 INFO (jetty-closer-2276-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3f9a921b{/solr,null,UNAVAILABLE}
[junit4] 2> 1667621 INFO (zkCallback-2296-thread-11-processing-n:127.0.0.1:52775_solr) [n:127.0.0.1:52775_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1667664 INFO (jetty-closer-2276-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1667671 INFO (jetty-closer-2276-thread-4) [ ] o.a.s.c.Overseer Overseer (id=97590425832980491-127.0.0.1:52775_solr-n_0000000001) closing
[junit4] 2> 1667671 INFO (OverseerStateUpdate-97590425832980491-127.0.0.1:52775_solr-n_0000000001) [n:127.0.0.1:52775_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:52775_solr
[junit4] 2> 1669120 WARN (zkCallback-2292-thread-16-processing-n:127.0.0.1:61489_solr) [n:127.0.0.1:61489_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1669121 INFO (jetty-closer-2276-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@51362e8{/solr,null,UNAVAILABLE}
[junit4] 2> 1669176 WARN (zkCallback-2296-thread-14-processing-n:127.0.0.1:52775_solr) [n:127.0.0.1:52775_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1669176 INFO (jetty-closer-2276-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5739f0cb{/solr,null,UNAVAILABLE}
[junit4] 2> 1669180 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59505 59505
[junit4] 2> 1669184 INFO (Thread-8520) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59505 59505
[junit4] 2> 1669186 WARN (Thread-8520) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2> 2 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 21 /solr/collections
[junit4] 2> 4 /solr/overseer/queue
[junit4] 2> 2 /solr/live_nodes
[junit4] 2>
[junit4] 2> 1669187 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[EF11849929B5888A]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_EF11849929B5888A-001
[junit4] 2> Mar 10, 2017 2:10:23 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {_version_=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=Lucene50(blocksize=128)}, docValues:{}, maxPointsInLeafNode=831, maxMBSortInHeap=5.796328600761168, sim=RandomSimilarity(queryNorm=true): {}, locale=no-NO, timezone=Europe/London
[junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=3,threads=1,free=137751416,total=524288000
[junit4] 2> NOTE: All tests run in this JVM: [TestXmlQParserPlugin, TestComponentsName, TestFiltering, TestCollapseQParserPlugin, TestNoOpRegenerator, VersionInfoTest, SpellCheckCollatorTest, CreateCollectionCleanupTest, FieldAnalysisRequestHandlerTest, CdcrReplicationHandlerTest, SparseHLLTest, LeaderFailureAfterFreshStartTest, UpdateParamsTest, ExternalFileFieldSortTest, TestSolrCoreProperties, CSVRequestHandlerTest, BlockCacheTest, TestFieldTypeResource, CloudMLTQParserTest, TestRequestStatusCollectionAPI, RulesTest, TestImpersonationWithHadoopAuth, TestRangeQuery, CollectionReloadTest, TestRandomRequestDistribution, CloneFieldUpdateProcessorFactoryTest, TestRestManager, SignatureUpdateProcessorFactoryTest, AtomicUpdatesTest, SpellPossibilityIteratorTest, TestLuceneMatchVersion, StatsComponentTest, TestMacroExpander, FacetPivotSmallTest, TestClassicSimilarityFactory, TestCollectionAPIs, TestShardHandlerFactory, JvmMetricsTest, DistributedFacetPivotLargeTest, AutoCommitTest, CdcrBootstrapTest, ClusterStateTest, CacheHeaderTest, TestQueryUtils, TestSchemalessBufferedUpdates, TestZkChroot, LukeRequestHandlerTest, UUIDFieldTest, SuggesterTSTTest, ShardSplitTest, AsyncCallRequestStatusResponseTest, TestAtomicUpdateErrorCases, TestTolerantUpdateProcessorRandomCloud, BlockJoinFacetRandomTest, SpellingQueryConverterTest, JSONWriterTest, TestJmxMonitoredMap, DateRangeFieldTest, TestHdfsUpdateLog, TestDynamicLoading, SolrSlf4jReporterTest, DeleteShardTest, LeaderInitiatedRecoveryOnShardRestartTest, TestSolrCloudSnapshots, DirectUpdateHandlerOptimizeTest, ConnectionReuseTest, TestExportWriter, BufferStoreTest, ShowFileRequestHandlerTest, HdfsLockFactoryTest, TestLMDirichletSimilarityFactory, FieldMutatingUpdateProcessorTest, TestSolrDynamicMBean, TriLevelCompositeIdRoutingTest, TestRealTimeGet, TestFuzzyAnalyzedSuggestions, ReplaceNodeTest, QueryParsingTest, TestValueSourceCache, SolrGraphiteReporterTest, TermVectorComponentDistributedTest, SuggesterTest, RegexBoostProcessorTest, TestObjectReleaseTracker, CircularListTest, ShardRoutingCustomTest, TestReload, CdcrVersionReplicationTest, TestReplicationHandlerBackup, TestTrieFacet, TestRandomFaceting, TestReplicaProperties, CdcrUpdateLogTest, SolrCoreCheckLockOnStartupTest, FileBasedSpellCheckerTest, SharedFSAutoReplicaFailoverUtilsTest, HdfsBasicDistributedZk2Test, TestClassNameShortening, TestIndexSearcher, TestConfigSetProperties, HLLSerializationTest, DistribCursorPagingTest, DistributedQueryComponentOptimizationTest, TestJsonFacets, TestUseDocValuesAsStored2, OverseerRolesTest, UtilsToolTest, TestQueryTypes, DeleteInactiveReplicaTest, SolrMetricsIntegrationTest, TestSegmentSorting, TestPHPSerializedResponseWriter, TestSchemaResource, OverseerTaskQueueTest, TestUtils, TestInPlaceUpdatesStandalone, BJQParserTest, TestCoreDiscovery, TestSolrDeletionPolicy2, TestJoin, TestExactStatsCache, BigEndianAscendingWordSerializerTest, EnumFieldTest, SolrXmlInZkTest, HdfsUnloadDistributedZkTest, SolrMetricManagerTest, DistribJoinFromCollectionTest, TestDocSet, SuggesterWFSTTest, SSLMigrationTest, IndexSchemaTest, PreAnalyzedFieldManagedSchemaCloudTest, ExitableDirectoryReaderTest, SpatialHeatmapFacetsTest, PKIAuthenticationIntegrationTest, BadComponentTest, DeleteNodeTest, TestFieldCacheSort, TestSearchPerf, TestSizeLimitedDistributedMap, SortSpecParsingTest, TestDocBasedVersionConstraints, TestRecoveryHdfs, TestConfigReload, TestRestoreCore, TestSlowCompositeReaderWrapper, LeaderElectionIntegrationTest, TestMaxScoreQueryParser, BooleanFieldTest, TestSolrQueryParser, TestManagedSchemaAPI, TestSmileRequest, SolrShardReporterTest, TestOnReconnectListenerSupport, TestFieldResource, TestSolrQueryParserDefaultOperatorResource, DistanceUnitsTest, PeerSyncWithIndexFingerprintCachingTest, BasicZkTest, TestConfig, ReturnFieldsTest, TemplateUpdateProcessorTest, CheckHdfsIndexTest, TestCoreAdminApis, NoCacheHeaderTest, TestPushWriter, BasicDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4] Completed [354/695 (1!)] on J1 in 101.73s, 20 tests, 1 error <<< FAILURES!
[...truncated 63768 lines...]
[JENKINS] Lucene-Solr-master-Solaris (64bit/jdk1.8.0) - Build #
1184 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/1184/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
4 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicZkTest
Error Message:
SolrCore.getOpenCount()==2
Stack Trace:
java.lang.RuntimeException: SolrCore.getOpenCount()==2
at __randomizedtesting.SeedInfo.seed([83BEEA3C9BC5EFBB]:0)
at org.apache.solr.util.TestHarness.close(TestHarness.java:373)
at org.apache.solr.SolrTestCaseJ4.deleteCore(SolrTestCaseJ4.java:792)
at org.apache.solr.cloud.AbstractZkTestCase.azt_afterClass(AbstractZkTestCase.java:143)
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$7.evaluate(RandomizedRunner.java:870)
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:745)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicZkTest
Error Message:
SolrCore.getOpenCount()==2
Stack Trace:
java.lang.RuntimeException: SolrCore.getOpenCount()==2
at __randomizedtesting.SeedInfo.seed([83BEEA3C9BC5EFBB]:0)
at org.apache.solr.util.TestHarness.close(TestHarness.java:373)
at org.apache.solr.SolrTestCaseJ4.deleteCore(SolrTestCaseJ4.java:792)
at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:294)
at sun.reflect.GeneratedMethodAccessor26.invoke(Unknown Source)
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$7.evaluate(RandomizedRunner.java:870)
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:745)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicZkTest
Error Message:
26 threads leaked from SUITE scope at org.apache.solr.cloud.BasicZkTest: 1) Thread[id=13392, name=searcherExecutor-4646-thread-1, state=WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 2) Thread[id=13393, name=coreZkRegister-4638-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 3) Thread[id=13396, name=zkCallback-2326-thread-4, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 4) Thread[id=13400, name=zkCallback-2326-thread-8, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 5) Thread[id=13385, name=OverseerStateUpdate-97592888458149891-192.168.57.18:8983_-n_0000000000, state=TIMED_WAITING, group=Overseer state updater.] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:164) at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:138) at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:181) at java.lang.Thread.run(Thread.java:745) 6) Thread[id=13401, name=zkCallback-2326-thread-9, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 7) Thread[id=13402, name=Thread-3355, state=WAITING, group=TGRP-BasicZkTest] at java.lang.Object.wait(Native Method) at java.lang.Thread.join(Thread.java:1249) at java.lang.Thread.join(Thread.java:1323) at org.apache.zookeeper.server.NIOServerCnxnFactory.join(NIOServerCnxnFactory.java:302) at org.apache.solr.cloud.ZkTestServer$ZKServerMain.runFromConfig(ZkTestServer.java:309) at org.apache.solr.cloud.ZkTestServer$2.run(ZkTestServer.java:490) 8) Thread[id=13404, name=SessionTracker, state=TIMED_WAITING, group=TGRP-BasicZkTest] at java.lang.Object.wait(Native Method) at org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:146) 9) Thread[id=13387, name=OverseerHdfsCoreFailoverThread-97592888458149891-192.168.57.18:8983_-n_0000000000, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.] at java.lang.Thread.sleep(Native Method) at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139) at java.lang.Thread.run(Thread.java:745) 10) Thread[id=13394, name=zkCallback-2326-thread-2, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 11) Thread[id=13407, name=zkCallback-2326-thread-10, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 12) Thread[id=13377, name=Connection evictor, state=TIMED_WAITING, group=TGRP-BasicZkTest] at java.lang.Thread.sleep(Native Method) at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) at java.lang.Thread.run(Thread.java:745) 13) Thread[id=13382, name=SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker-SendThread(127.0.0.1:58634), state=RUNNABLE, group=TGRP-BasicZkTest] at sun.nio.ch.DevPollArrayWrapper.poll0(Native Method) at sun.nio.ch.DevPollArrayWrapper.poll(DevPollArrayWrapper.java:223) at sun.nio.ch.DevPollSelectorImpl.doSelect(DevPollSelectorImpl.java:98) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:349) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081) 14) Thread[id=13386, name=OverseerCollectionConfigSetProcessor-97592888458149891-192.168.57.18:8983_-n_0000000000, state=TIMED_WAITING, group=Overseer collection creation process.] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078) at org.apache.solr.cloud.DistributedQueue.peekElements(DistributedQueue.java:343) at org.apache.solr.cloud.OverseerTaskQueue.peekTopN(OverseerTaskQueue.java:235) at org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:227) at java.lang.Thread.run(Thread.java:745) 15) Thread[id=13406, name=ProcessThread(sid:0 cport:-1):, state=WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:120) 16) Thread[id=13408, name=zkCallback-2326-thread-11, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 17) Thread[id=13397, name=zkCallback-2326-thread-5, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 18) Thread[id=13384, name=zkCallback-2326-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 19) Thread[id=13399, name=zkCallback-2326-thread-7, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 20) Thread[id=13378, name=Connection evictor, state=TIMED_WAITING, group=TGRP-BasicZkTest] at java.lang.Thread.sleep(Native Method) at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) at java.lang.Thread.run(Thread.java:745) 21) Thread[id=13398, name=zkCallback-2326-thread-6, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 22) Thread[id=13389, name=Thread-3354, state=WAITING, group=TGRP-BasicZkTest] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at org.apache.solr.core.CloserThread.run(CoreContainer.java:1488) 23) Thread[id=13390, name=watches-2327-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 24) Thread[id=13403, name=NIOServerCxn.Factory:0.0.0.0/0.0.0.0:58634, state=RUNNABLE, group=TGRP-BasicZkTest] at sun.nio.ch.DevPollArrayWrapper.poll0(Native Method) at sun.nio.ch.DevPollArrayWrapper.poll(DevPollArrayWrapper.java:223) at sun.nio.ch.DevPollSelectorImpl.doSelect(DevPollSelectorImpl.java:98) at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86) at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97) at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:178) at java.lang.Thread.run(Thread.java:745) 25) Thread[id=13383, name=SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker-EventThread, state=WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494) 26) Thread[id=13395, name=zkCallback-2326-thread-3, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 26 threads leaked from SUITE scope at org.apache.solr.cloud.BasicZkTest:
1) Thread[id=13392, name=searcherExecutor-4646-thread-1, state=WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2) Thread[id=13393, name=coreZkRegister-4638-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
3) Thread[id=13396, name=zkCallback-2326-thread-4, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
4) Thread[id=13400, name=zkCallback-2326-thread-8, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
5) Thread[id=13385, name=OverseerStateUpdate-97592888458149891-192.168.57.18:8983_-n_0000000000, state=TIMED_WAITING, group=Overseer state updater.]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:164)
at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:138)
at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:181)
at java.lang.Thread.run(Thread.java:745)
6) Thread[id=13401, name=zkCallback-2326-thread-9, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
7) Thread[id=13402, name=Thread-3355, state=WAITING, group=TGRP-BasicZkTest]
at java.lang.Object.wait(Native Method)
at java.lang.Thread.join(Thread.java:1249)
at java.lang.Thread.join(Thread.java:1323)
at org.apache.zookeeper.server.NIOServerCnxnFactory.join(NIOServerCnxnFactory.java:302)
at org.apache.solr.cloud.ZkTestServer$ZKServerMain.runFromConfig(ZkTestServer.java:309)
at org.apache.solr.cloud.ZkTestServer$2.run(ZkTestServer.java:490)
8) Thread[id=13404, name=SessionTracker, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at java.lang.Object.wait(Native Method)
at org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:146)
9) Thread[id=13387, name=OverseerHdfsCoreFailoverThread-97592888458149891-192.168.57.18:8983_-n_0000000000, state=TIMED_WAITING, group=Overseer Hdfs SolrCore Failover Thread.]
at java.lang.Thread.sleep(Native Method)
at org.apache.solr.cloud.OverseerAutoReplicaFailoverThread.run(OverseerAutoReplicaFailoverThread.java:139)
at java.lang.Thread.run(Thread.java:745)
10) Thread[id=13394, name=zkCallback-2326-thread-2, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
11) Thread[id=13407, name=zkCallback-2326-thread-10, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
12) Thread[id=13377, name=Connection evictor, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at java.lang.Thread.sleep(Native Method)
at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66)
at java.lang.Thread.run(Thread.java:745)
13) Thread[id=13382, name=SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker-SendThread(127.0.0.1:58634), state=RUNNABLE, group=TGRP-BasicZkTest]
at sun.nio.ch.DevPollArrayWrapper.poll0(Native Method)
at sun.nio.ch.DevPollArrayWrapper.poll(DevPollArrayWrapper.java:223)
at sun.nio.ch.DevPollSelectorImpl.doSelect(DevPollSelectorImpl.java:98)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:349)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
14) Thread[id=13386, name=OverseerCollectionConfigSetProcessor-97592888458149891-192.168.57.18:8983_-n_0000000000, state=TIMED_WAITING, group=Overseer collection creation process.]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
at org.apache.solr.cloud.DistributedQueue.peekElements(DistributedQueue.java:343)
at org.apache.solr.cloud.OverseerTaskQueue.peekTopN(OverseerTaskQueue.java:235)
at org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:227)
at java.lang.Thread.run(Thread.java:745)
15) Thread[id=13406, name=ProcessThread(sid:0 cport:-1):, state=WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.zookeeper.server.PrepRequestProcessor.run(PrepRequestProcessor.java:120)
16) Thread[id=13408, name=zkCallback-2326-thread-11, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
17) Thread[id=13397, name=zkCallback-2326-thread-5, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
18) Thread[id=13384, name=zkCallback-2326-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
19) Thread[id=13399, name=zkCallback-2326-thread-7, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
20) Thread[id=13378, name=Connection evictor, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at java.lang.Thread.sleep(Native Method)
at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66)
at java.lang.Thread.run(Thread.java:745)
21) Thread[id=13398, name=zkCallback-2326-thread-6, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
22) Thread[id=13389, name=Thread-3354, state=WAITING, group=TGRP-BasicZkTest]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at org.apache.solr.core.CloserThread.run(CoreContainer.java:1488)
23) Thread[id=13390, name=watches-2327-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
24) Thread[id=13403, name=NIOServerCxn.Factory:0.0.0.0/0.0.0.0:58634, state=RUNNABLE, group=TGRP-BasicZkTest]
at sun.nio.ch.DevPollArrayWrapper.poll0(Native Method)
at sun.nio.ch.DevPollArrayWrapper.poll(DevPollArrayWrapper.java:223)
at sun.nio.ch.DevPollSelectorImpl.doSelect(DevPollSelectorImpl.java:98)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:178)
at java.lang.Thread.run(Thread.java:745)
25) Thread[id=13383, name=SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker-EventThread, state=WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)
26) Thread[id=13395, name=zkCallback-2326-thread-3, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([83BEEA3C9BC5EFBB]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicZkTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=13408, name=zkCallback-2326-thread-11, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 2) Thread[id=13397, name=zkCallback-2326-thread-5, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 3) Thread[id=13384, name=zkCallback-2326-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 4) Thread[id=13392, name=searcherExecutor-4646-thread-1, state=WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 5) Thread[id=13399, name=zkCallback-2326-thread-7, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 6) Thread[id=13393, name=coreZkRegister-4638-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 7) Thread[id=13396, name=zkCallback-2326-thread-4, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 8) Thread[id=13400, name=zkCallback-2326-thread-8, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 9) Thread[id=13398, name=zkCallback-2326-thread-6, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 10) Thread[id=13389, name=Thread-3354, state=WAITING, group=TGRP-BasicZkTest] at java.lang.Object.wait(Native Method) at java.lang.Object.wait(Object.java:502) at org.apache.solr.core.CloserThread.run(CoreContainer.java:1488) 11) Thread[id=13401, name=zkCallback-2326-thread-9, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 12) Thread[id=13390, name=watches-2327-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 13) Thread[id=13394, name=zkCallback-2326-thread-2, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 14) Thread[id=13407, name=zkCallback-2326-thread-10, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) 15) Thread[id=13382, name=SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker-SendThread(127.0.0.1:58634), state=TIMED_WAITING, group=TGRP-BasicZkTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101) at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003) 16) Thread[id=13395, name=zkCallback-2326-thread-3, state=TIMED_WAITING, group=TGRP-BasicZkTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=13408, name=zkCallback-2326-thread-11, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2) Thread[id=13397, name=zkCallback-2326-thread-5, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
3) Thread[id=13384, name=zkCallback-2326-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
4) Thread[id=13392, name=searcherExecutor-4646-thread-1, state=WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
5) Thread[id=13399, name=zkCallback-2326-thread-7, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
6) Thread[id=13393, name=coreZkRegister-4638-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
7) Thread[id=13396, name=zkCallback-2326-thread-4, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
8) Thread[id=13400, name=zkCallback-2326-thread-8, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
9) Thread[id=13398, name=zkCallback-2326-thread-6, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
10) Thread[id=13389, name=Thread-3354, state=WAITING, group=TGRP-BasicZkTest]
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:502)
at org.apache.solr.core.CloserThread.run(CoreContainer.java:1488)
11) Thread[id=13401, name=zkCallback-2326-thread-9, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
12) Thread[id=13390, name=watches-2327-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
13) Thread[id=13394, name=zkCallback-2326-thread-2, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
14) Thread[id=13407, name=zkCallback-2326-thread-10, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
15) Thread[id=13382, name=SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker-SendThread(127.0.0.1:58634), state=TIMED_WAITING, group=TGRP-BasicZkTest]
at java.lang.Thread.sleep(Native Method)
at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
16) Thread[id=13395, name=zkCallback-2326-thread-3, state=TIMED_WAITING, group=TGRP-BasicZkTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([83BEEA3C9BC5EFBB]:0)
Build Log:
[...truncated 11600 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicZkTest
[junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.BasicZkTest_83BEEA3C9BC5EFBB-001/init-core-data-001
[junit4] 2> 913008 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 913010 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 913010 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 913011 INFO (Thread-3353) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 913011 INFO (Thread-3353) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 913111 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:58634
[junit4] 2> 913131 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 913133 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 913135 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 913137 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 913139 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 913140 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 913142 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 913144 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 913146 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 913148 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 913150 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.AbstractZkTestCase put /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 913153 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 913154 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/lib, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 913193 WARN (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 913196 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 913222 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 913331 WARN (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.s.IndexSchema [null] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 913336 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 913343 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:58634/solr
[junit4] 2> 913391 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 913392 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 192.168.57.18:8983_
[junit4] 2> 913395 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.c.Overseer Overseer (id=97592888458149891-192.168.57.18:8983_-n_0000000000) starting
[junit4] 2> 913406 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/192.168.57.18:8983_
[junit4] 2> 913410 INFO (OverseerStateUpdate-97592888458149891-192.168.57.18:8983_-n_0000000000) [n:192.168.57.18:8983_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 913555 WARN (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.m.r.SolrJmxReporter No serviceUrl or agentId was configured, using first MBeanServer.
[junit4] 2> 913559 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e5e645c
[junit4] 2> 913559 WARN (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.m.r.SolrJmxReporter No serviceUrl or agentId was configured, using first MBeanServer.
[junit4] 2> 913562 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e5e645c
[junit4] 2> 913562 WARN (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.m.r.SolrJmxReporter No serviceUrl or agentId was configured, using first MBeanServer.
[junit4] 2> 913562 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e5e645c
[junit4] 2> 914574 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/lib, /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1/lib/classes]
[junit4] 2> 914607 WARN (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 914609 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
[junit4] 2> 914646 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 914824 WARN (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.s.IndexSchema [collection1] default search field in schema is text. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 914826 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 914843 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 914843 WARN (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.m.r.SolrJmxReporter No serviceUrl or agentId was configured, using first MBeanServer.
[junit4] 2> 914843 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e5e645c
[junit4] 2> 914843 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/core/src/test-files/solr/collection1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.BasicZkTest_83BEEA3C9BC5EFBB-001/init-core-data-001/]
[junit4] 2> 914844 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e5e645c
[junit4] 2> 914844 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.48437671599484833]
[junit4] 2> 914952 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 914952 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 914953 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 914953 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 914955 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=430756747, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 914956 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@426c4b77[collection1] main]
[junit4] 2> 914958 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 914961 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 914976 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 914977 INFO (coreLoadExecutor-4645-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1561486217391898624
[junit4] 2> 914980 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 914989 INFO (SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker) [n:192.168.57.18:8983_ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 914987 INFO (coreZkRegister-4638-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 r:192.168.57.18:8983__collection1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 914990 INFO (coreZkRegister-4638-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 r:192.168.57.18:8983__collection1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 914990 INFO (coreZkRegister-4638-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 r:192.168.57.18:8983__collection1 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 915004 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 915005 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 915005 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 915006 INFO (coreZkRegister-4638-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 r:192.168.57.18:8983__collection1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://192.168.57.18:8983/collection1/ shard1
[junit4] 2> 915007 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 915009 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 915009 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 915010 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 915010 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 915011 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_ x:collection1 s:shard1 c:collection1) [n:192.168.57.18:8983_ c:collection1 s:shard1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@426c4b77[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 915017 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.SolrTestCaseJ4 ###Starting testBasic
[junit4] 2> 915118 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=qlkciyopsbgzyvkylsjhchghjrdf&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 915123 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[42 (-1561486217543942144)]} 0 0
[junit4] 2> 915124 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[42 (1561486217546039296)]} 0 0
[junit4] 2> 915124 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 915124 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@716662dd
[junit4] 2> 915127 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6ee01000[collection1] main]
[junit4] 2> 915127 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 915129 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6ee01000[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1)))}
[junit4] 2> 915129 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 4
[junit4] 2> 915130 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:42+AND+val_s:aa\;bb&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 915130 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:42+AND+val_s:"aa;bb"&qt=standard&start=0&rows=20&version=2.2} hits=1 status=0 QTime=0
[junit4] 2> 915131 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:42+AND+val_s:aa&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 915132 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[42 (-1561486217553379328)]} 0 0
[junit4] 2> 915132 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 915132 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@716662dd
[junit4] 2> 915132 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@736cc76e[collection1] main]
[junit4] 2> 915134 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 915135 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@736cc76e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 915135 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 3
[junit4] 2> 915136 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.c.S.Request [collection1] webapp=null path=null params={q=id:42&qt=standard&start=0&rows=20&version=2.2} hits=0 status=0 QTime=0
[junit4] 2> 915137 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[42 (1561486217558622208)]} 0 1
[junit4] 2> 915138 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[42 (1561486217559670784)]} 0 0
[junit4] 2> 915160 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 915160 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@716662dd
[junit4] 2> 915163 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@68b47204[collection1] main]
[junit4] 2> 915163 INFO (TEST-BasicZkTest.testBasic-seed#[83BEEA3C9BC5EFBB]) [n:192.168.57.18:8983_ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 915165 INFO (searcherExecutor-4646-thread-1-processing-n:192.168.57.18:8983_) [n:192.168.57.18:8983_ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@68b47204[collection1] main{ExitableDirectoryRead
[...truncated too long message...]
ad-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 7) Thread[id=13396, name=zkCallback-2326-thread-4, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 8) Thread[id=13400, name=zkCallback-2326-thread-8, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 9) Thread[id=13398, name=zkCallback-2326-thread-6, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 10) Thread[id=13389, name=Thread-3354, state=WAITING, group=TGRP-BasicZkTest]
[junit4] > at java.lang.Object.wait(Native Method)
[junit4] > at java.lang.Object.wait(Object.java:502)
[junit4] > at org.apache.solr.core.CloserThread.run(CoreContainer.java:1488)
[junit4] > 11) Thread[id=13401, name=zkCallback-2326-thread-9, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 12) Thread[id=13390, name=watches-2327-thread-1, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 13) Thread[id=13394, name=zkCallback-2326-thread-2, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 14) Thread[id=13407, name=zkCallback-2326-thread-10, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > 15) Thread[id=13382, name=SUITE-BasicZkTest-seed#[83BEEA3C9BC5EFBB]-worker-SendThread(127.0.0.1:58634), state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at java.lang.Thread.sleep(Native Method)
[junit4] > at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
[junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
[junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
[junit4] > 16) Thread[id=13395, name=zkCallback-2326-thread-3, state=TIMED_WAITING, group=TGRP-BasicZkTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
[junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
[junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > at __randomizedtesting.SeedInfo.seed([83BEEA3C9BC5EFBB]:0)
[junit4] Completed [249/695 (1!)] on J1 in 28.04s, 1 test, 4 errors <<< FAILURES!
[...truncated 64074 lines...]