Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Solaris/882/ Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
2 tests failed. FAILED: org.apache.solr.cloud.CustomCollectionTest.test Error Message: Timeout occured while waiting response from server at: http://127.0.0.1:49028 Stack Trace: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:49028 at __randomizedtesting.SeedInfo.seed([49DF10E2016A995C:C18B2F38AF96F4A4]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:619) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:261) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:250) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:415) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:367) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1280) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:1050) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:992) at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1219) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1599) at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1553) at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:280) at org.apache.solr.cloud.CustomCollectionTest.test(CustomCollectionTest.java:97) 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:1764) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985) at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at java.lang.Thread.run(Thread.java:745) Caused by: java.net.SocketTimeoutException: Read timed out at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) at java.net.SocketInputStream.read(SocketInputStream.java:170) at java.net.SocketInputStream.read(SocketInputStream.java:141) at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139) at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155) at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165) at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:167) at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271) at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184) at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88) at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:513) ... 53 more FAILED: junit.framework.TestSuite.org.apache.solr.search.join.BlockJoinFacetDistribTest Error Message: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest: 1) Thread[id=24253, name=OverseerHdfsCoreFailoverThread-96694936878186512-127.0.0.1:60991_solr-n_0000000001, 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:137) at java.lang.Thread.run(Thread.java:745) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.search.join.BlockJoinFacetDistribTest: 1) Thread[id=24253, name=OverseerHdfsCoreFailoverThread-96694936878186512-127.0.0.1:60991_solr-n_0000000001, 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:137) at java.lang.Thread.run(Thread.java:745) at __randomizedtesting.SeedInfo.seed([49DF10E2016A995C]:0) Build Log: [...truncated 10562 lines...] [junit4] Suite: org.apache.solr.search.join.BlockJoinFacetDistribTest [junit4] 2> Creating dataDir: /export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/init-core-data-001 [junit4] 2> 195543 INFO (SUITE-BlockJoinFacetDistribTest-seed#[49DF10E2016A995C]-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> 195544 INFO (SUITE-BlockJoinFacetDistribTest-seed#[49DF10E2016A995C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 195544 INFO (Thread-289) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 195544 INFO (Thread-289) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 195644 INFO (SUITE-BlockJoinFacetDistribTest-seed#[49DF10E2016A995C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:37396 [junit4] 2> 195662 INFO (jetty-launcher-6487-thread-1) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 195663 INFO (jetty-launcher-6487-thread-2) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 195665 INFO (jetty-launcher-6487-thread-6) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 195665 INFO (jetty-launcher-6487-thread-3) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 195666 INFO (jetty-launcher-6487-thread-5) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 195667 INFO (jetty-launcher-6487-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4b465073{/solr,null,AVAILABLE} [junit4] 2> 195667 INFO (jetty-launcher-6487-thread-4) [ ] o.e.j.s.Server jetty-9.3.8.v20160314 [junit4] 2> 195670 INFO (jetty-launcher-6487-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4b29391f{/solr,null,AVAILABLE} [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-4) [ ] o.e.j.s.ServerConnector Started ServerConnector@7d3a7a56{HTTP/1.1,[http/1.1]}{127.0.0.1:52567} [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-1) [ ] o.e.j.s.ServerConnector Started ServerConnector@4da4fba4{HTTP/1.1,[http/1.1]}{127.0.0.1:54074} [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-4) [ ] o.e.j.s.Server Started @198337ms [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-1) [ ] o.e.j.s.Server Started @198337ms [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=52567} [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=54074} [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0 [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0 [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-02T22:34:05.362Z [junit4] 2> 195672 INFO (jetty-launcher-6487-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-02T22:34:05.362Z [junit4] 2> 195676 INFO (jetty-launcher-6487-thread-5) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5fa4bae0{/solr,null,AVAILABLE} [junit4] 2> 195676 INFO (jetty-launcher-6487-thread-5) [ ] o.e.j.s.ServerConnector Started ServerConnector@543379af{HTTP/1.1,[http/1.1]}{127.0.0.1:47135} [junit4] 2> 195676 INFO (jetty-launcher-6487-thread-5) [ ] o.e.j.s.Server Started @198342ms [junit4] 2> 195676 INFO (jetty-launcher-6487-thread-5) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=47135} [junit4] 2> 195676 INFO (jetty-launcher-6487-thread-5) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0 [junit4] 2> 195677 INFO (jetty-launcher-6487-thread-5) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 195677 INFO (jetty-launcher-6487-thread-5) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 195677 INFO (jetty-launcher-6487-thread-5) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-02T22:34:05.367Z [junit4] 2> 195684 INFO (jetty-launcher-6487-thread-6) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@349503cf{/solr,null,AVAILABLE} [junit4] 2> 195684 INFO (jetty-launcher-6487-thread-6) [ ] o.e.j.s.ServerConnector Started ServerConnector@13a3ddc{HTTP/1.1,[http/1.1]}{127.0.0.1:60991} [junit4] 2> 195684 INFO (jetty-launcher-6487-thread-6) [ ] o.e.j.s.Server Started @198350ms [junit4] 2> 195684 INFO (jetty-launcher-6487-thread-6) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=60991} [junit4] 2> 195684 INFO (jetty-launcher-6487-thread-6) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0 [junit4] 2> 195685 INFO (jetty-launcher-6487-thread-6) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 195685 INFO (jetty-launcher-6487-thread-6) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 195685 INFO (jetty-launcher-6487-thread-6) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-02T22:34:05.375Z [junit4] 2> 195692 INFO (jetty-launcher-6487-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@68b4de85{/solr,null,AVAILABLE} [junit4] 2> 195692 INFO (jetty-launcher-6487-thread-2) [ ] o.e.j.s.ServerConnector Started ServerConnector@5f4feae1{HTTP/1.1,[http/1.1]}{127.0.0.1:34721} [junit4] 2> 195693 INFO (jetty-launcher-6487-thread-2) [ ] o.e.j.s.Server Started @198358ms [junit4] 2> 195693 INFO (jetty-launcher-6487-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34721} [junit4] 2> 195693 INFO (jetty-launcher-6487-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0 [junit4] 2> 195693 INFO (jetty-launcher-6487-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 195693 INFO (jetty-launcher-6487-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 195693 INFO (jetty-launcher-6487-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-02T22:34:05.383Z [junit4] 2> 195700 INFO (jetty-launcher-6487-thread-6) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 195702 INFO (jetty-launcher-6487-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@22fe614b{/solr,null,AVAILABLE} [junit4] 2> 195702 INFO (jetty-launcher-6487-thread-3) [ ] o.e.j.s.ServerConnector Started ServerConnector@2e21fbbc{HTTP/1.1,[http/1.1]}{127.0.0.1:48690} [junit4] 2> 195703 INFO (jetty-launcher-6487-thread-3) [ ] o.e.j.s.Server Started @198368ms [junit4] 2> 195703 INFO (jetty-launcher-6487-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=48690} [junit4] 2> 195703 INFO (jetty-launcher-6487-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.0.0 [junit4] 2> 195703 INFO (jetty-launcher-6487-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 195703 INFO (jetty-launcher-6487-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 195703 INFO (jetty-launcher-6487-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-10-02T22:34:05.393Z [junit4] 2> 195707 INFO (jetty-launcher-6487-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 195707 INFO (jetty-launcher-6487-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 195708 INFO (jetty-launcher-6487-thread-5) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 195763 INFO (jetty-launcher-6487-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 195830 INFO (jetty-launcher-6487-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37396/solr [junit4] 2> 195832 INFO (jetty-launcher-6487-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37396/solr [junit4] 2> 195833 INFO (jetty-launcher-6487-thread-5) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37396/solr [junit4] 2> 195838 INFO (jetty-launcher-6487-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 195846 INFO (jetty-launcher-6487-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37396/solr [junit4] 2> 195847 INFO (jetty-launcher-6487-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37396/solr [junit4] 2> 195856 INFO (jetty-launcher-6487-thread-6) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37396/solr [junit4] 2> 195900 INFO (jetty-launcher-6487-thread-3) [n:127.0.0.1:48690_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:48690_solr [junit4] 2> 195903 INFO (jetty-launcher-6487-thread-6) [n:127.0.0.1:60991_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60991_solr [junit4] 2> 195903 INFO (jetty-launcher-6487-thread-5) [n:127.0.0.1:47135_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47135_solr [junit4] 2> 195904 INFO (jetty-launcher-6487-thread-3) [n:127.0.0.1:48690_solr ] o.a.s.c.Overseer Overseer (id=96694936878186511-127.0.0.1:48690_solr-n_0000000000) starting [junit4] 2> 195922 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 195936 INFO (jetty-launcher-6487-thread-2) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 195937 INFO (zkCallback-6515-thread-1-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 195937 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 195938 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 195948 INFO (jetty-launcher-6487-thread-3) [n:127.0.0.1:48690_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48690_solr [junit4] 2> 195949 INFO (jetty-launcher-6487-thread-2) [n:127.0.0.1:34721_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34721_solr [junit4] 2> 195950 INFO (jetty-launcher-6487-thread-1) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 195955 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 195956 INFO (zkCallback-6515-thread-1-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 195956 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 195960 INFO (zkCallback-6522-thread-1-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 195960 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 195962 INFO (jetty-launcher-6487-thread-4) [n:127.0.0.1:52567_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52567_solr [junit4] 2> 195973 INFO (zkCallback-6515-thread-1-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 195974 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 195978 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 195980 INFO (jetty-launcher-6487-thread-3) [n:127.0.0.1:48690_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.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node5/. [junit4] 2> 195982 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 196009 INFO (zkCallback-6517-thread-3-processing-n:127.0.0.1:54074_solr) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (5) [junit4] 2> 196014 INFO (jetty-launcher-6487-thread-1) [n:127.0.0.1:54074_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54074_solr [junit4] 2> 196043 INFO (jetty-launcher-6487-thread-2) [n:127.0.0.1:34721_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.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node2/. [junit4] 2> 196046 INFO (zkCallback-6515-thread-3-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6) [junit4] 2> 196048 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6) [junit4] 2> 196049 INFO (zkCallback-6517-thread-1-processing-n:127.0.0.1:54074_solr) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6) [junit4] 2> 196049 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6) [junit4] 2> 196061 INFO (zkCallback-6522-thread-1-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 196072 INFO (zkCallback-6522-thread-2-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6) [junit4] 2> 196075 INFO (jetty-launcher-6487-thread-5) [n:127.0.0.1:47135_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.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node3/. [junit4] 2> 196078 INFO (jetty-launcher-6487-thread-4) [n:127.0.0.1:52567_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.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node6/. [junit4] 2> 196095 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6) [junit4] 2> 196130 INFO (jetty-launcher-6487-thread-6) [n:127.0.0.1:60991_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.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node4/. [junit4] 2> 196139 INFO (jetty-launcher-6487-thread-1) [n:127.0.0.1:54074_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.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node1/. [junit4] 2> 196157 INFO (SUITE-BlockJoinFacetDistribTest-seed#[49DF10E2016A995C]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (6) [junit4] 2> 197140 INFO (qtp385450171-24044) [n:127.0.0.1:47135_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&collection.configName=solrCloudCollectionConfig&name=facetcollection&action=CREATE&numShards=3&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 197146 INFO (OverseerThreadFactory-2112-thread-1-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.CreateCollectionCmd Create collection facetcollection [junit4] 2> 197300 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard2_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2 [junit4] 2> 197302 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard1_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2 [junit4] 2> 197304 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard3_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2 [junit4] 2> 197305 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard1_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2 [junit4] 2> 197307 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard3_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2 [junit4] 2> 197317 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr ] o.a.s.h.a.CoreAdminOperation core create command property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard2_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2 [junit4] 2> 197465 INFO (zkCallback-6517-thread-1-processing-n:127.0.0.1:54074_solr) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 197465 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 197465 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 197466 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 197466 INFO (zkCallback-6515-thread-2-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 197466 INFO (zkCallback-6522-thread-2-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 198365 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 198366 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 198386 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 198407 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 198426 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 198426 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.s.IndexSchema [facetcollection_shard1_replica1] Schema name=test [junit4] 2> 198431 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 198489 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.s.IndexSchema [facetcollection_shard2_replica1] Schema name=test [junit4] 2> 198497 WARN (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.s.IndexSchema [facetcollection_shard1_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 198497 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 198498 WARN (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.s.IndexSchema [facetcollection_shard2_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 198498 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 198504 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica1' using configuration from collection facetcollection [junit4] 2> 198505 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.SolrCore [[facetcollection_shard1_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node2/facetcollection_shard1_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node2/./facetcollection_shard1_replica1/data/] [junit4] 2> 198512 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.s.IndexSchema [facetcollection_shard3_replica1] Schema name=test [junit4] 2> 198512 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica1' using configuration from collection facetcollection [junit4] 2> 198512 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.SolrCore [[facetcollection_shard2_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node1/facetcollection_shard2_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node1/./facetcollection_shard2_replica1/data/] [junit4] 2> 198521 WARN (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.s.IndexSchema [facetcollection_shard3_replica1] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 198521 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.s.IndexSchema [facetcollection_shard1_replica2] Schema name=test [junit4] 2> 198522 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 198524 WARN (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.s.IndexSchema [facetcollection_shard1_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 198524 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 198524 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.s.IndexSchema [facetcollection_shard3_replica2] Schema name=test [junit4] 2> 198531 WARN (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.s.IndexSchema [facetcollection_shard3_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 198532 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 198534 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 x:facetcollection_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard1_replica2' using configuration from collection facetcollection [junit4] 2> 198534 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.SolrCore [[facetcollection_shard1_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node6/facetcollection_shard1_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node6/./facetcollection_shard1_replica2/data/] [junit4] 2> 198540 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica2] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica2' using configuration from collection facetcollection [junit4] 2> 198540 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.SolrCore [[facetcollection_shard3_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node5/facetcollection_shard3_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node5/./facetcollection_shard3_replica2/data/] [junit4] 2> 198554 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 198554 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 198555 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 198555 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 198561 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.s.IndexSchema [facetcollection_shard2_replica2] Schema name=test [junit4] 2> 198562 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@34b6156b[facetcollection_shard1_replica1] main] [junit4] 2> 198564 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 198564 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 198565 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 x:facetcollection_shard3_replica1] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard3_replica1' using configuration from collection facetcollection [junit4] 2> 198575 WARN (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.s.IndexSchema [facetcollection_shard2_replica2] default search field in schema is name. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 198575 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 198576 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 198576 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 198577 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@212cbb84[facetcollection_shard1_replica2] main] [junit4] 2> 198577 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 198577 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 198579 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 198579 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 198579 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7cf64471[facetcollection_shard2_replica1] main] [junit4] 2> 198581 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 198582 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 198582 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1547118993234460672 [junit4] 2> 198582 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 198582 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 198583 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 198583 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 198584 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@4da712cd[facetcollection_shard3_replica2] main] [junit4] 2> 198585 INFO (searcherExecutor-2126-thread-1-processing-n:127.0.0.1:54074_solr x:facetcollection_shard2_replica1 s:shard2 c:facetcollection r:core_node1) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.SolrCore [facetcollection_shard2_replica1] Registered new searcher Searcher@7cf64471[facetcollection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 198586 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 198587 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 198594 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1547118993247043584 [junit4] 2> 198594 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms [junit4] 2> 198599 INFO (searcherExecutor-2128-thread-1-processing-n:127.0.0.1:48690_solr x:facetcollection_shard3_replica2 s:shard3 c:facetcollection r:core_node6) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.SolrCore [facetcollection_shard3_replica2] Registered new searcher Searcher@4da712cd[facetcollection_shard3_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 198600 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 198602 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 x:facetcollection_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'facetcollection_shard2_replica2' using configuration from collection facetcollection [junit4] 2> 198602 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 198604 INFO (searcherExecutor-2125-thread-1-processing-n:127.0.0.1:34721_solr x:facetcollection_shard1_replica1 s:shard1 c:facetcollection r:core_node5) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.SolrCore [facetcollection_shard1_replica1] Registered new searcher Searcher@34b6156b[facetcollection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 198605 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1547118993258577920 [junit4] 2> 198605 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 198607 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.SolrCore [[facetcollection_shard3_replica1] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node3/facetcollection_shard3_replica1], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node3/./facetcollection_shard3_replica1/data/] [junit4] 2> 198603 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.SolrCore [[facetcollection_shard2_replica2] ] Opening new SolrCore at [/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node4/facetcollection_shard2_replica2], dataDir=[/export/home/jenkins/workspace/Lucene-Solr-master-Solaris/solr/build/solr-core/test/J1/temp/solr.search.join.BlockJoinFacetDistribTest_49DF10E2016A995C-001/tempDir-001/node4/./facetcollection_shard2_replica2/data/] [junit4] 2> 198609 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard3: total=2 found=1 timeoutin=9999ms [junit4] 2> 198609 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 198610 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1547118993263820800 [junit4] 2> 198631 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 198631 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 198632 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 198632 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 198635 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@5b9f2fdb[facetcollection_shard2_replica2] main] [junit4] 2> 198637 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 198638 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 198638 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1547118993293180928 [junit4] 2> 198640 INFO (searcherExecutor-2142-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.SolrCore [facetcollection_shard2_replica2] Registered new searcher Searcher@5b9f2fdb[facetcollection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 198672 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9998ms [junit4] 2> 198685 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 198685 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 198690 INFO (searcherExecutor-2127-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.SolrCore [facetcollection_shard1_replica2] Registered new searcher Searcher@212cbb84[facetcollection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 198697 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 198697 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 198698 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4b420d4d[facetcollection_shard3_replica1] main] [junit4] 2> 198700 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/solrCloudCollectionConfig [junit4] 2> 198701 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/solrCloudCollectionConfig [junit4] 2> 198701 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1547118993359241216 [junit4] 2> 198703 INFO (searcherExecutor-2133-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.SolrCore [facetcollection_shard3_replica1] Registered new searcher Searcher@4b420d4d[facetcollection_shard3_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 198776 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 198776 INFO (zkCallback-6517-thread-1-processing-n:127.0.0.1:54074_solr) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 198777 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 198779 INFO (zkCallback-6522-thread-2-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 198780 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 198782 INFO (zkCallback-6515-thread-1-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199096 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 199096 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 199097 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:54074/solr/facetcollection_shard2_replica1/ [junit4] 2> 199097 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=http://127.0.0.1:54074/solr START replicas=[http://127.0.0.1:60991/solr/facetcollection_shard2_replica2/] nUpdates=100 [junit4] 2> 199097 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard2_replica1 url=http://127.0.0.1:54074/solr DONE. We have no versions. sync failed. [junit4] 2> 199100 INFO (qtp1261256479-24068) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.S.Request [facetcollection_shard2_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1 [junit4] 2> 199101 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 199101 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_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> 199109 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:54074/solr/facetcollection_shard2_replica1/ shard2 [junit4] 2> 199111 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 199111 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 199111 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:48690/solr/facetcollection_shard3_replica2/ [junit4] 2> 199111 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica2 url=http://127.0.0.1:48690/solr START replicas=[http://127.0.0.1:47135/solr/facetcollection_shard3_replica1/] nUpdates=100 [junit4] 2> 199111 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard3_replica2 url=http://127.0.0.1:48690/solr DONE. We have no versions. sync failed. [junit4] 2> 199118 INFO (qtp385450171-24049) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.S.Request [facetcollection_shard3_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 199119 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 199119 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] 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> 199133 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:48690/solr/facetcollection_shard3_replica2/ shard3 [junit4] 2> 199173 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 199173 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 199174 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:34721/solr/facetcollection_shard1_replica1/ [junit4] 2> 199174 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=http://127.0.0.1:34721/solr START replicas=[http://127.0.0.1:52567/solr/facetcollection_shard1_replica2/] nUpdates=100 [junit4] 2> 199174 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.u.PeerSync PeerSync: core=facetcollection_shard1_replica1 url=http://127.0.0.1:34721/solr DONE. We have no versions. sync failed. [junit4] 2> 199177 INFO (qtp875447826-24037) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.S.Request [facetcollection_shard1_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0 [junit4] 2> 199178 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate [junit4] 2> 199178 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_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> 199187 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:34721/solr/facetcollection_shard1_replica1/ shard1 [junit4] 2> 199299 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199299 INFO (zkCallback-6515-thread-3-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199299 INFO (zkCallback-6522-thread-2-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199301 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199301 INFO (zkCallback-6517-thread-1-processing-n:127.0.0.1:54074_solr) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199301 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199311 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 199314 INFO (qtp1624387439-24032) [n:127.0.0.1:54074_solr c:facetcollection s:shard2 r:core_node1 x:facetcollection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard2_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=2014 [junit4] 2> 199335 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 199338 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 199342 INFO (qtp631387922-24077) [n:127.0.0.1:34721_solr c:facetcollection s:shard1 r:core_node5 x:facetcollection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard1_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=2040 [junit4] 2> 199342 INFO (qtp1175296475-24056) [n:127.0.0.1:48690_solr c:facetcollection s:shard3 r:core_node6 x:facetcollection_shard3_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard3_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2} status=0 QTime=2036 [junit4] 2> 199452 INFO (zkCallback-6511-thread-1-processing-n:127.0.0.1:47135_solr) [n:127.0.0.1:47135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199453 INFO (zkCallback-6515-thread-3-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199454 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199454 INFO (zkCallback-6522-thread-2-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199458 INFO (zkCallback-6517-thread-1-processing-n:127.0.0.1:54074_solr) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199459 INFO (zkCallback-6516-thread-1-processing-n:127.0.0.1:60991_solr) [n:127.0.0.1:60991_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199679 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.ZkController Core needs to recover:facetcollection_shard2_replica2 [junit4] 2> 199680 INFO (updateExecutor-6512-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 199746 INFO (qtp1261256479-24065) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard2_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard2&wt=javabin&version=2} status=0 QTime=2432 [junit4] 2> 199746 INFO (recoveryExecutor-6513-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 199746 INFO (recoveryExecutor-6513-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]] [junit4] 2> 199747 INFO (recoveryExecutor-6513-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[facetcollection_shard2_replica2] [junit4] 2> 199747 INFO (recoveryExecutor-6513-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 199747 INFO (recoveryExecutor-6513-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.RecoveryStrategy Publishing state of core [facetcollection_shard2_replica2] as recovering, leader is [http://127.0.0.1:54074/solr/facetcollection_shard2_replica1/] and I am [http://127.0.0.1:60991/solr/facetcollection_shard2_replica2/] [junit4] 2> 199748 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.ZkController Core needs to recover:facetcollection_shard3_replica1 [junit4] 2> 199749 INFO (qtp385450171-24046) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard3_replica1&action=CREATE&numShards=3&collection=facetcollection&shard=shard3&wt=javabin&version=2} status=0 QTime=2445 [junit4] 2> 199751 INFO (updateExecutor-6500-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 199752 INFO (recoveryExecutor-6501-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 199753 INFO (recoveryExecutor-6501-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]] [junit4] 2> 199753 INFO (recoveryExecutor-6501-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[facetcollection_shard3_replica1] [junit4] 2> 199753 INFO (recoveryExecutor-6501-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 199753 INFO (recoveryExecutor-6501-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.RecoveryStrategy Publishing state of core [facetcollection_shard3_replica1] as recovering, leader is [http://127.0.0.1:48690/solr/facetcollection_shard3_replica2/] and I am [http://127.0.0.1:47135/solr/facetcollection_shard3_replica1/] [junit4] 2> 199754 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.ZkController Core needs to recover:facetcollection_shard1_replica2 [junit4] 2> 199754 INFO (recoveryExecutor-6513-thread-1-processing-n:127.0.0.1:60991_solr x:facetcollection_shard2_replica2 s:shard2 c:facetcollection r:core_node4) [n:127.0.0.1:60991_solr c:facetcollection s:shard2 r:core_node4 x:facetcollection_shard2_replica2] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:54074/solr]; [WaitForState: action=PREPRECOVERY&core=facetcollection_shard2_replica1&nodeName=127.0.0.1:60991_solr&coreNodeName=core_node4&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true] [junit4] 2> 199755 INFO (recoveryExecutor-6501-thread-1-processing-n:127.0.0.1:47135_solr x:facetcollection_shard3_replica1 s:shard3 c:facetcollection r:core_node2) [n:127.0.0.1:47135_solr c:facetcollection s:shard3 r:core_node2 x:facetcollection_shard3_replica1] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:48690/solr]; [WaitForState: action=PREPRECOVERY&core=facetcollection_shard3_replica2&nodeName=127.0.0.1:47135_solr&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true] [junit4] 2> 199758 INFO (updateExecutor-6495-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 199758 INFO (recoveryExecutor-6496-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true [junit4] 2> 199759 INFO (qtp1624387439-24031) [n:127.0.0.1:54074_solr ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 199760 INFO (recoveryExecutor-6496-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]] [junit4] 2> 199760 INFO (recoveryExecutor-6496-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[facetcollection_shard1_replica2] [junit4] 2> 199761 INFO (recoveryExecutor-6496-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null} [junit4] 2> 199761 INFO (recoveryExecutor-6496-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.RecoveryStrategy Publishing state of core [facetcollection_shard1_replica2] as recovering, leader is [http://127.0.0.1:34721/solr/facetcollection_shard1_replica1/] and I am [http://127.0.0.1:52567/solr/facetcollection_shard1_replica2/] [junit4] 2> 199761 INFO (qtp1175296475-24060) [n:127.0.0.1:48690_solr ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 199762 INFO (qtp1624387439-24031) [n:127.0.0.1:54074_solr ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see facetcollection_shard2_replica1 (shard2 of facetcollection) have state: recovering [junit4] 2> 199762 INFO (qtp1624387439-24031) [n:127.0.0.1:54074_solr ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=facetcollection, shard=shard2, thisCore=facetcollection_shard2_replica1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:60991_solr, coreNodeName=core_node4, onlyIfActiveCheckResult=false, nodeProps: core_node4:{"core":"facetcollection_shard2_replica2","base_url":"http://127.0.0.1:60991/solr","node_name":"127.0.0.1:60991_solr","state":"down"} [junit4] 2> 199763 INFO (qtp875447826-24038) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={property.schema=schema-blockjoinfacetcomponent.xml&property.config=solrconfig-blockjoinfacetcomponent.xml&qt=/admin/cores&collection.configName=solrCloudCollectionConfig&name=facetcollection_shard1_replica2&action=CREATE&numShards=3&collection=facetcollection&shard=shard1&wt=javabin&version=2} status=0 QTime=2459 [junit4] 2> 199763 INFO (qtp1175296475-24060) [n:127.0.0.1:48690_solr ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see facetcollection_shard3_replica2 (shard3 of facetcollection) have state: recovering [junit4] 2> 199763 INFO (qtp1175296475-24060) [n:127.0.0.1:48690_solr ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=facetcollection, shard=shard3, thisCore=facetcollection_shard3_replica2, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:47135_solr, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"core":"facetcollection_shard3_replica1","base_url":"http://127.0.0.1:47135/solr","node_name":"127.0.0.1:47135_solr","state":"down"} [junit4] 2> 199767 INFO (recoveryExecutor-6496-thread-1-processing-n:127.0.0.1:52567_solr x:facetcollection_shard1_replica2 s:shard1 c:facetcollection r:core_node3) [n:127.0.0.1:52567_solr c:facetcollection s:shard1 r:core_node3 x:facetcollection_shard1_replica2] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:34721/solr]; [WaitForState: action=PREPRECOVERY&core=facetcollection_shard1_replica1&nodeName=127.0.0.1:52567_solr&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true] [junit4] 2> 199769 INFO (qtp631387922-24081) [n:127.0.0.1:34721_solr ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 199776 INFO (qtp385450171-24044) [n:127.0.0.1:47135_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> 199777 INFO (qtp631387922-24081) [n:127.0.0.1:34721_solr ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see facetcollection_shard1_replica1 (shard1 of facetcollection) have state: recovering [junit4] 2> 199777 INFO (qtp631387922-24081) [n:127.0.0.1:34721_solr ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=facetcollection, shard=shard1, thisCore=facetcollection_shard1_replica1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:52567_solr, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"facetcollection_shard1_replica2","base_url":"http://127.0.0.1:52567/solr","node_name":"127.0.0.1:52567_solr","state":"down"} [junit4] 2> 199891 INFO (zkCallback-6515-thread-2-processing-n:127.0.0.1:48690_solr) [n:127.0.0.1:48690_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199891 INFO (zkCallback-6522-thread-2-processing-n:127.0.0.1:34721_solr) [n:127.0.0.1:34721_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199892 INFO (zkCallback-6517-thread-1-processing-n:127.0.0.1:54074_solr) [n:127.0.0.1:54074_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> 199892 INFO (zkCallback-6504-thread-1-processing-n:127.0.0.1:52567_solr) [n:127.0.0.1:52567_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/facetcollection/state.json] for collection [facetcollection] has occurred - updating... (live nodes size: [6]) [junit4] 2> [...truncated too long message...] lr.cloud.CustomCollectionTest.test(CustomCollectionTest.java:97) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:985) [junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] > Caused by: java.net.SocketTimeoutException: Read timed out [junit4] > at java.net.SocketInputStream.socketRead0(Native Method) [junit4] > at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) [junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:170) [junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:141) [junit4] > at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:139) [junit4] > at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:155) [junit4] > at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:284) [junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140) [junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57) [junit4] > at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:261) [junit4] > at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:165) [junit4] > at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:167) [junit4] > at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:272) [junit4] > at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:124) [junit4] > at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:271) [junit4] > at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184) [junit4] > at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:88) [junit4] > at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) [junit4] > at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184) [junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) [junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55) [junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:513) [junit4] > ... 53 more [junit4] 2> 2169114 INFO (SUITE-CustomCollectionTest-seed#[49DF10E2016A995C]-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/J0/temp/solr.cloud.CustomCollectionTest_49DF10E2016A995C-001 [junit4] 2> Oct 02, 2016 11:06:58 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s). [junit4] 2> NOTE: test params are: codec=Asserting(Lucene62): {other_tl1=FSTOrd50, range_facet_l_dv=FST50, multiDefault=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), intDefault=FSTOrd50, a_i1=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), range_facet_l=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), _version_=FSTOrd50, a_t=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), id=FST50, range_facet_i_dv=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128))), text=PostingsFormat(name=MockRandom), _route_=PostingsFormat(name=MockRandom), timestamp=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128)))}, docValues:{range_facet_l_dv=DocValuesFormat(name=Lucene54), range_facet_i_dv=DocValuesFormat(name=Direct), timestamp=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=331, maxMBSortInHeap=7.3710135456343, sim=RandomSimilarity(queryNorm=true): {}, locale=ar-KW, timezone=America/Blanc-Sablon [junit4] 2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=1,free=139459456,total=518979584 [junit4] 2> NOTE: All tests run in this JVM: [BlockDirectoryTest, TestInitQParser, TestCoreContainer, DirectoryFactoryTest, TestRTGBase, TestBinaryResponseWriter, CleanupOldIndexTest, AsyncMigrateRouteKeyTest, TestXmlQParser, TestCSVLoader, OverriddenZkACLAndCredentialsProvidersTest, DistribJoinFromCollectionTest, TestLeaderInitiatedRecoveryThread, TestGeoJSONResponseWriter, JSONWriterTest, TlogReplayBufferedWhileIndexingTest, TestSearcherReuse, PrimUtilsTest, TestFaceting, TestRecoveryHdfs, HardAutoCommitTest, SpatialFilterTest, CursorPagingTest, AnalysisAfterCoreReloadTest, CdcrReplicationHandlerTest, HdfsSyncSliceTest, DeleteShardTest, NumericFieldsTest, OverseerTest, StatelessScriptUpdateProcessorFactoryTest, DistributedFacetPivotLargeTest, TestOrdValues, PrimitiveFieldTypeTest, TestFunctionQuery, TestReplicationHandler, ZkControllerTest, SynonymTokenizerTest, TestConfigSetsAPI, SolrCloudExampleTest, TestXIncludeConfig, OpenExchangeRatesOrgProviderTest, TestSolrQueryParserDefaultOperatorResource, RuleEngineTest, TestDocTermOrds, HdfsDirectoryTest, DocumentAnalysisRequestHandlerTest, TestSolrQueryResponse, TestSolrXml, TestJmxIntegration, ZkCLITest, RequestLoggingTest, TestRebalanceLeaders, TestFieldCacheReopen, TestPerFieldSimilarity, OverseerModifyCollectionTest, MultiTermTest, TestStressLucene, FastVectorHighlighterTest, TestSolrFieldCacheMBean, TestRuleBasedAuthorizationPlugin, CollectionsAPISolrJTest, RemoteQueryErrorTest, EnumFieldTest, TestNamedUpdateProcessors, AnalyticsQueryTest, TestWordDelimiterFilterFactory, TestSolrConfigHandler, TestRemoteStreaming, BooleanFieldTest, TestDynamicFieldResource, ReplicationFactorTest, HdfsRecoveryZkTest, TestStressCloudBlindAtomicUpdates, TestMiniSolrCloudCluster, UniqFieldsUpdateProcessorFactoryTest, SolrCoreTest, BasicDistributedZkTest, SolrIndexConfigTest, SimpleFacetsTest, PingRequestHandlerTest, TestBM25SimilarityFactory, DisMaxRequestHandlerTest, DocumentBuilderTest, TestDistribDocBasedVersion, SimpleCollectionCreateDeleteTest, SimplePostToolTest, TestSurroundQueryParser, DocExpirationUpdateProcessorFactoryTest, DistributedSpellCheckComponentTest, TestHdfsUpdateLog, TestLRUCache, TestUseDocValuesAsStored2, TestSolrCloudWithKerberosAlt, GraphQueryTest, BlobRepositoryCloudTest, TestSolrJ, TestUpdate, JavabinLoaderTest, TestRandomFlRTGCloud, HighlighterTest, CreateCollectionCleanupTest, TestImplicitCoreProperties, TestSchemaVersionResource, BlockJoinFacetRandomTest, TestDocumentBuilder, DistributedMLTComponentTest, CdcrBootstrapTest, BasicAuthIntegrationTest, DOMUtilTest, ClassificationUpdateProcessorFactoryTest, TestFieldSortValues, TestGroupingSearch, MergeStrategyTest, TestExclusionRuleCollectionAccess, TestAuthorizationFramework, HdfsNNFailoverTest, FacetPivotSmallTest, CdcrVersionReplicationTest, TestPostingsSolrHighlighter, TestFieldTypeResource, DistributedFacetPivotSmallAdvancedTest, FileUtilsTest, SaslZkACLProviderTest, QueryEqualityTest, ShardRoutingTest, TestBinaryField, TestSolrConfigHandlerCloud, CoreAdminCreateDiscoverTest, SuggesterFSTTest, TestCollationFieldDocValues, TestRestManager, TestRandomDVFaceting, XmlUpdateRequestHandlerTest, DirectSolrConnectionTest, TestExactStatsCache, TestStressReorder, TestFastOutputStream, TestConfigReload, TimeZoneUtilsTest, CopyFieldTest, TestBackupRepositoryFactory, TestSolrCLIRunExample, PeerSyncReplicationTest, TestAnalyzeInfixSuggestions, TestRawResponseWriter, TestConfigSetsAPIZkFailure, AlternateDirectoryTest, TestSlowCompositeReaderWrapper, RollingRestartTest, ClusterStateUpdateTest, TestDefaultSearchFieldResource, TestClusterStateMutator, HdfsWriteToMultipleCollectionsTest, TestTolerantSearch, SyncSliceTest, ShardRoutingCustomTest, TestDistributedSearch, SpellCheckComponentTest, PeerSyncTest, TestSort, TestLazyCores, SoftAutoCommitTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, SolrRequestParserTest, SuggesterWFSTTest, PolyFieldTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, SolrCoreCheckLockOnStartupTest, TestPseudoReturnFields, TestAtomicUpdateErrorCases, SortByFunctionTest, DocValuesMultiTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, DebugComponentTest, CacheHeaderTest, IndexBasedSpellCheckerTest, TestQueryUtils, StandardRequestHandlerTest, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, FileBasedSpellCheckerTest, TermsComponentTest, RequestHandlersTest, TestValueSourceCache, PathHierarchyTokenizerFactoryTest, TestIndexingPerformance, MoreLikeThisHandlerTest, RequiredFieldsTest, TestSolrQueryParser, IndexSchemaRuntimeFieldTest, RegexBoostProcessorTest, SolrPluginUtilsTest, TestCSVResponseWriter, QueryParsingTest, TestPartialUpdateDeduplication, CSVRequestHandlerTest, SearchHandlerTest, SOLR749Test, TestQuerySenderNoQuery, TestStressRecovery, TestSystemIdResolver, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, ZkNodePropsTest, SystemInfoHandlerTest, DistributedIntervalFacetingTest, SolrTestCaseJ4Test, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestEmbeddedSolrServerConstructors, TestJettySolrRunner, ActionThrottleTest, CollectionReloadTest, CollectionsAPIAsyncDistributedZkTest, ConcurrentDeleteAndCreateCollectionTest, ConfigSetsAPITest, CustomCollectionTest] [junit4] Completed [458/636 (2!)] on J0 in 218.71s, 1 test, 1 error <<< FAILURES! [...truncated 60859 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
