You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2015/08/21 01:08:30 UTC
[JENKINS] Lucene-Solr-NightlyTests-5.3 - Build # 11 - Still Failing
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.3/11/
4 tests failed.
REGRESSION: org.apache.solr.cloud.hdfs.HdfsBasicDistributedZk2Test.test
Error Message:
Server refused connection at: http://127.0.0.1:42930/collection1
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:42930/collection1
at __randomizedtesting.SeedInfo.seed([D18E239D34220062:59DA1C479ADE6D9A]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:567)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943)
at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958)
at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:365)
at org.apache.solr.cloud.BasicDistributedZk2Test.test(BasicDistributedZk2Test.java:98)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:963)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:938)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
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:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
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:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.ConnectException: Connection refused
at java.net.PlainSocketImpl.socketConnect(Native Method)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:579)
at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:117)
at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:177)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:304)
at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:611)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:446)
at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:882)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:107)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:465)
... 48 more
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1440111752853,generation=2,filelist=[_785.fdt, _785.fdx, _785.fnm, _785.nvd, _785.nvm, _785.si, _785_Memory_0.ram, _ec5.cfe, _ec5.cfs, _ec5.si, _g2j.cfe, _g2j.cfs, _g2j.si, _g2k.cfe, _g2k.cfs, _g2k.si, _g2l.cfe, _g2l.cfs, _g2l.si, _g2m.cfe, _g2m.cfs, _g2m.si, _g2n.cfe, _g2n.cfs, _g2n.si, segments_2]}]> but was:<[{indexVersion=1440111752853,generation=2,filelist=[_785.fdt, _785.fdx, _785.fnm, _785.nvd, _785.nvm, _785.si, _785_Memory_0.ram, _ec5.cfe, _ec5.cfs, _ec5.si, _g2j.cfe, _g2j.cfs, _g2j.si, _g2k.cfe, _g2k.cfs, _g2k.si, _g2l.cfe, _g2l.cfs, _g2l.si, _g2m.cfe, _g2m.cfs, _g2m.si, _g2n.cfe, _g2n.cfs, _g2n.si, segments_2]}, {indexVersion=1440111752853,generation=3,filelist=[_785.fdt, _785.fdx, _785.fnm, _785.nvd, _785.nvm, _785.si, _785_Memory_0.ram, _ec5.cfe, _ec5.cfs, _ec5.si, _g2o.cfe, _g2o.cfs, _g2o.si, segments_3]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1440111752853,generation=2,filelist=[_785.fdt, _785.fdx, _785.fnm, _785.nvd, _785.nvm, _785.si, _785_Memory_0.ram, _ec5.cfe, _ec5.cfs, _ec5.si, _g2j.cfe, _g2j.cfs, _g2j.si, _g2k.cfe, _g2k.cfs, _g2k.si, _g2l.cfe, _g2l.cfs, _g2l.si, _g2m.cfe, _g2m.cfs, _g2m.si, _g2n.cfe, _g2n.cfs, _g2n.si, segments_2]}]> but was:<[{indexVersion=1440111752853,generation=2,filelist=[_785.fdt, _785.fdx, _785.fnm, _785.nvd, _785.nvm, _785.si, _785_Memory_0.ram, _ec5.cfe, _ec5.cfs, _ec5.si, _g2j.cfe, _g2j.cfs, _g2j.si, _g2k.cfe, _g2k.cfs, _g2k.si, _g2l.cfe, _g2l.cfs, _g2l.si, _g2m.cfe, _g2m.cfs, _g2m.si, _g2n.cfe, _g2n.cfs, _g2n.si, segments_2]}, {indexVersion=1440111752853,generation=3,filelist=[_785.fdt, _785.fdx, _785.fnm, _785.nvd, _785.nvm, _785.si, _785_Memory_0.ram, _ec5.cfe, _ec5.cfs, _ec5.si, _g2o.cfe, _g2o.cfs, _g2o.si, segments_3]}]>
at __randomizedtesting.SeedInfo.seed([D18E239D34220062:F45938AD446A0E61]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1138)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
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:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
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:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=36400, name=collection3, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=36400, name=collection3, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:56591: Could not find collection : awholynewstresscollection_collection3_2
at __randomizedtesting.SeedInfo.seed([D18E239D34220062]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1085)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:894)
FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=45779, name=collection0, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=45779, name=collection0, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:45317/c_ctq: Could not find collection : awholynewstresscollection_collection0_5
at __randomizedtesting.SeedInfo.seed([D18E239D34220062]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1085)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:894)
Build Log:
[...truncated 10548 lines...]
[junit4] Suite: org.apache.solr.cloud.hdfs.HdfsBasicDistributedZk2Test
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/init-core-data-001
[junit4] 2> 322563 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 323185 WARN (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.a.h.u.NativeCodeLoader Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
[junit4] 1> Formatting using clusterid: testClusterID
[junit4] 2> 323891 WARN (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.a.h.m.i.MetricsConfig Cannot locate configuration: tried hadoop-metrics2-namenode.properties,hadoop-metrics2.properties
[junit4] 2> 324074 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
[junit4] 2> 324084 WARN (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 324169 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 324223 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/hdfs to ./temp/Jetty_localhost_50952_hdfs____.jo7zuj/webapp
[junit4] 2> 324423 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 325558 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:50952
[junit4] 2> 326381 WARN (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 326389 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 326402 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_46876_datanode____39jbng/webapp
[junit4] 2> 326555 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 327280 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:46876
[junit4] 2> 327381 WARN (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.a.h.h.HttpRequestLog Jetty request log can only be enabled using Log4j
[junit4] 2> 327384 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log jetty-6.1.26
[junit4] 2> 327398 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log Extract jar:file:/x1/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-2.6.0-tests.jar!/webapps/datanode to ./temp/Jetty_localhost_41083_datanode____.5pug7f/webapp
[junit4] 2> 327528 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log NO JSP Support for /, did not find org.apache.jasper.servlet.JspServlet
[junit4] 2> 328078 INFO (SUITE-HdfsBasicDistributedZk2Test-seed#[D18E239D34220062]-worker) [ ] o.m.log Started HttpServer2$SelectChannelConnectorWithSafeStartup@localhost:41083
[junit4] 2> 328174 INFO (IPC Server handler 4 on 36136) [ ] BlockStateChange BLOCK* processReport: from storage DS-f0872738-e0c0-4d01-9478-0c1dc3ebcb88 node DatanodeRegistration(127.0.0.1, datanodeUuid=9b9657b3-b7e6-4897-ad61-cc227bd20014, infoPort=46876, ipcPort=53362, storageInfo=lv=-56;cid=testClusterID;nsid=1153788544;c=0), blocks: 0, hasStaleStorages: true, processing time: 3 msecs
[junit4] 2> 328176 INFO (IPC Server handler 4 on 36136) [ ] BlockStateChange BLOCK* processReport: from storage DS-8cd73937-4371-4a6c-8d07-eef52425bcc2 node DatanodeRegistration(127.0.0.1, datanodeUuid=9b9657b3-b7e6-4897-ad61-cc227bd20014, infoPort=46876, ipcPort=53362, storageInfo=lv=-56;cid=testClusterID;nsid=1153788544;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
[junit4] 2> 328310 INFO (IPC Server handler 2 on 36136) [ ] BlockStateChange BLOCK* processReport: from storage DS-b8701070-79d4-49b0-aa1f-ba52104cf11b node DatanodeRegistration(127.0.0.1, datanodeUuid=5bd720f6-778f-4a21-b6ed-77c036cff068, infoPort=41083, ipcPort=58073, storageInfo=lv=-56;cid=testClusterID;nsid=1153788544;c=0), blocks: 0, hasStaleStorages: true, processing time: 1 msecs
[junit4] 2> 328311 INFO (IPC Server handler 2 on 36136) [ ] BlockStateChange BLOCK* processReport: from storage DS-9a879207-659e-4df8-adc8-73f601baedd9 node DatanodeRegistration(127.0.0.1, datanodeUuid=5bd720f6-778f-4a21-b6ed-77c036cff068, infoPort=41083, ipcPort=58073, storageInfo=lv=-56;cid=testClusterID;nsid=1153788544;c=0), blocks: 0, hasStaleStorages: false, processing time: 0 msecs
[junit4] 2> 329054 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 329054 INFO (Thread-4671) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 329055 INFO (Thread-4671) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 329155 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.ZkTestServer start zk server on port:47501
[junit4] 2> 329155 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 329156 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 329159 INFO (zkCallback-147-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3c26f59c name:ZooKeeperConnection Watcher:127.0.0.1:47501 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 329159 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 329160 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 329160 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 329163 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 329164 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 329166 INFO (zkCallback-148-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@11dbdc59 name:ZooKeeperConnection Watcher:127.0.0.1:47501/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 329166 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 329167 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 329167 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 329171 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 329172 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 329174 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 329176 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 329177 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 329179 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 329180 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 329182 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 329182 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 329184 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 329185 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 329189 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 329189 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 329192 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 329192 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 329195 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 329195 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 329197 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 329198 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 329203 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 329203 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 329205 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 329206 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 329208 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 329208 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 329513 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores/collection1
[junit4] 2> 329515 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 329517 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@65bb52be{/,null,AVAILABLE}
[junit4] 2> 329518 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.ServerConnector Started ServerConnector@4e4d9f3c{HTTP/1.1}{127.0.0.1:47540}
[junit4] 2> 329518 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.Server Started @332465ms
[junit4] 2> 329518 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostPort=47540, hostContext=/, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores, solr.data.dir=hdfs://localhost:36136/hdfs__localhost_36136__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-5.3_solr_build_solr-core_test_J2_temp_solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001_tempDir-002_control_data}
[junit4] 2> 329519 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@1fe91485
[junit4] 2> 329519 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/'
[junit4] 2> 329537 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 329537 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 329540 INFO (zkCallback-149-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2514cd52 name:ZooKeeperConnection Watcher:127.0.0.1:47501/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 329540 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 329541 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 329543 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 329544 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/solr.xml
[junit4] 2> 329561 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores
[junit4] 2> 329561 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoreContainer New CoreContainer 1877121038
[junit4] 2> 329562 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/]
[junit4] 2> 329562 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/lib
[junit4] 2> 329562 WARN (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/lib).
[junit4] 2> 329573 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 329574 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 329575 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 329575 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 329575 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47501/solr
[junit4] 2> 329576 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 329576 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 329576 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 329578 INFO (zkCallback-151-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6fabaf02 name:ZooKeeperConnection Watcher:127.0.0.1:47501 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 329579 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 329579 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 329581 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 329583 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@48aa33e6 name:ZooKeeperConnection Watcher:127.0.0.1:47501/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 329583 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 329584 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 329587 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 329589 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 329591 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 329594 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 329596 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 329598 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 329600 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 329601 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 329603 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47540_
[junit4] 2> 329603 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:47540_
[junit4] 2> 329605 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 329607 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 329608 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 329609 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94378782414798852-127.0.0.1:47540_-n_0000000000
[junit4] 2> 329610 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:47540_
[junit4] 2> 329610 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 329612 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.Overseer Overseer (id=94378782414798852-127.0.0.1:47540_-n_0000000000) starting
[junit4] 2> 329614 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 329621 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 329621 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 329621 INFO (OverseerCollectionProcessor-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.OverseerCollectionProcessor Process current queue of collection creations
[junit4] 2> 329622 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 329638 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 329638 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 329639 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores
[junit4] 2> 329640 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.SolrCore Created CoreDescriptor: {coreNodeName=, configSetProperties=configsetprops.json, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores/collection1, collection=control_collection, schema=schema.xml, dataDir=data/, transient=false, config=solrconfig.xml, loadOnStartup=true, name=collection1, shard=, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores/collection1/}
[junit4] 2> 329641 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores/collection1/
[junit4] 2> 329641 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.c.CoresLocator Found 1 core definitions
[junit4] 2> 329642 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 329642 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 329643 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 329643 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2
[junit4] 2> 329643 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 329645 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:47540",
[junit4] 2> "operation":"state",
[junit4] 2> "shard":null,
[junit4] 2> "node_name":"127.0.0.1:47540_",
[junit4] 2> "core":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection"} current state version: 0
[junit4] 2> 329646 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:47540",
[junit4] 2> "operation":"state",
[junit4] 2> "shard":null,
[junit4] 2> "node_name":"127.0.0.1:47540_",
[junit4] 2> "core":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection"}
[junit4] 2> 329646 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 329646 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 329648 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 329643 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [n:127.0.0.1:47540_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 329650 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 1
[junit4] 2> 330643 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 330643 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 330644 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 330644 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 330645 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 330645 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores/collection1/'
[junit4] 2> 330662 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 330671 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 330706 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.3.0
[junit4] 2> 330739 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
[junit4] 2> 330740 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 330762 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 331037 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 331047 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 331049 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 331063 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 331068 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 331072 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 331073 WARN (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 331073 WARN (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 331073 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 331074 WARN (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 331075 WARN (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 331076 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2
[junit4] 2> 331076 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 331076 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.HdfsDirectoryFactory
[junit4] 2> 331086 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory solr.hdfs.home=hdfs://localhost:36136/solr_hdfs_home
[junit4] 2> 331086 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory Solr Kerberos Authentication disabled
[junit4] 2> 331087 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/control-001/cores/collection1/], dataDir=[null]
[junit4] 2> 331087 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5e47f5ae
[junit4] 2> 331087 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data
[junit4] 2> 331154 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.h.HdfsLocalityReporter Registering direcotry hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data for locality metrics.
[junit4] 2> 331155 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data
[junit4] 2> 331160 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data/index/
[junit4] 2> 331197 WARN (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory 'hdfs:/localhost:36136/solr_hdfs_home/control_collection/core_node1/data/index' doesn't exist. Creating new index...
[junit4] 2> 331197 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory creating directory factory for path hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data/index
[junit4] 2> 331219 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory Number of slabs of block cache [1] with direct memory allocation set to [true]
[junit4] 2> 331219 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory Block cache target memory usage, slab size of [8388608] will allocate [1] slabs and use ~[8388608] bytes
[junit4] 2> 331219 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.HdfsDirectoryFactory Creating new single instance HDFS BlockCache
[junit4] 2> 331259 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.b.BlockDirectory Block cache on write is disabled
[junit4] 2> 331259 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.h.HdfsLocalityReporter Registering direcotry hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data/index for locality metrics.
[junit4] 2> 331259 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data/index
[junit4] 2> 331260 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=9, maxMergeAtOnceExplicit=7, maxMergedSegmentMB=45.9296875, floorSegmentMB=1.669921875, forceMergeDeletesPctAllowed=8.6685309695476, segmentsPerTier=14.0, maxCFSSegmentSizeMB=1.5888671875, noCFSRatio=0.4069667879198541
[junit4] 2> 331596 INFO (IPC Server handler 3 on 36136) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:41457 is added to blk_1073741825_1001{blockUCState=COMMITTED, primaryNodeIndex=-1, replicas=[ReplicaUnderConstruction[[DISK]DS-9a879207-659e-4df8-adc8-73f601baedd9:NORMAL:127.0.0.1:41457|RBW], ReplicaUnderConstruction[[DISK]DS-f0872738-e0c0-4d01-9478-0c1dc3ebcb88:NORMAL:127.0.0.1:40587|RBW]]} size 71
[junit4] 2> 331598 INFO (IPC Server handler 2 on 36136) [ ] BlockStateChange BLOCK* addStoredBlock: blockMap updated: 127.0.0.1:40587 is added to blk_1073741825_1001 size 71
[junit4] 2> 332005 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(BlockDirectory(HdfsDirectory@b65bf9fe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@de200ff); maxCacheMB=192.0 maxMergeSizeMB=16.0),segFN=segments_1,generation=1}
[junit4] 2> 332005 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 332009 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in hdfs://localhost:36136/solr_hdfs_home/control_collection/core_node1/data/
[junit4] 2> 332015 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 332016 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 332016 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 332016 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 332017 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 332017 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 332017 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 332018 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 332018 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 332021 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 332023 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 332024 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 332026 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 332033 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/plugins,/admin/mbeans,/admin/properties,/admin/luke,/admin/segments,/update/csv,/update,/admin/threads,/update/json/docs,/admin/file,/replication,/schema,/update/json,/admin/ping,/admin/system,/get,standard,/config,/admin/logging
[junit4] 2> 332036 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 332040 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.HdfsUpdateLog
[junit4] 2> 332040 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing HdfsUpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 tlogDfsReplication=2
[junit4] 2> 332060 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
[junit4] 2> 332060 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
[junit4] 2> 332064 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@64c5bd74
[junit4] 2> 332149 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=NRTCachingDirectory(BlockDirectory(HdfsDirectory@b65bf9fe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@de200ff); maxCacheMB=192.0 maxMergeSizeMB=16.0),segFN=segments_1,generation=1}
[junit4] 2> 332149 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 332150 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@71c59d1b[collection1] main
[junit4] 2> 332150 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 332151 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 332151 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 332151 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 332152 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 332152 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 332152 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 332153 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 332153 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 332153 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 332156 INFO (searcherExecutor-610-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@71c59d1b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 332162 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 332162 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 256 version buckets from index
[junit4] 2> 332163 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
[junit4] 2> 332163 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1510060521894707200
[junit4] 2> 332163 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 1 ms to seed version buckets with highest version 1510060521894707200
[junit4] 2> 332163 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 332164 INFO (coreLoadExecutor-609-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 332165 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController Register replica - core:collection1 address:http://127.0.0.1:47540 collection:control_collection shard:shard1
[junit4] 2> 332166 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 332170 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.LeaderElector Joined leadership election with path: /collections/control_collection/leader_elect/shard1/election/94378782414798852-core_node1-n_0000000000
[junit4] 2> 332172 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
[junit4] 2> 332174 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 332175 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 332175 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 332175 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:47540/collection1/
[junit4] 2> 332175 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection"} current state version: 1
[junit4] 2> 332175 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 332175 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:47540/collection1/ has no replicas
[junit4] 2> 332176 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:47540/collection1/ shard1
[junit4] 2> 332176 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 332177 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 332179 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 2
[junit4] 2> 332189 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "base_url":"http://127.0.0.1:47540",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 2
[junit4] 2> 332192 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 332193 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 332195 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
[junit4] 2> 332232 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:47540/collection1/ and leader is http://127.0.0.1:47540/collection1/
[junit4] 2> 332232 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47540
[junit4] 2> 332232 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 332232 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 332233 INFO (coreZkRegister-603-thread-1-processing-r:core_node1 n:127.0.0.1:47540_ x:collection1 s:shard1 c:control_collection) [n:127.0.0.1:47540_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 332234 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 332236 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:47540",
[junit4] 2> "operation":"state",
[junit4] 2> "shard":"shard1",
[junit4] 2> "node_name":"127.0.0.1:47540_",
[junit4] 2> "core":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection"} current state version: 3
[junit4] 2> 332236 INFO (OverseerStateUpdate-94378782414798852-127.0.0.1:47540_-n_0000000000) [n:127.0.0.1:47540_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:47540",
[junit4] 2> "operation":"state",
[junit4] 2> "shard":"shard1",
[junit4] 2> "node_name":"127.0.0.1:47540_",
[junit4] 2> "core":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection"}
[junit4] 2> 332348 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 332350 INFO (zkCallback-152-thread-1-processing-n:127.0.0.1:47540_) [n:127.0.0.1:47540_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
[junit4] 2> 332651 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 332652 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 332653 INFO (zkCallback-154-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@47f46dad name:ZooKeeperConnection Watcher:127.0.0.1:47501/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 332653 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 332654 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 332654 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 332658 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 332979 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/cores/collection1
[junit4] 2> 332980 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001
[junit4] 2> 332981 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 332984 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3380db19{/,null,AVAILABLE}
[junit4] 2> 332984 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.ServerConnector Started ServerConnector@6b9e3b11{HTTP/1.1}{127.0.0.1:34628}
[junit4] 2> 332985 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.e.j.s.Server Started @335932ms
[junit4] 2> 332985 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=hdfs://localhost:36136/hdfs__localhost_36136__x1_jenkins_jenkins-slave_workspace_Lucene-Solr-NightlyTests-5.3_solr_build_solr-core_test_J2_temp_solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001_tempDir-002_jetty1, solrconfig=solrconfig.xml, hostContext=/, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/cores, hostPort=34628}
[junit4] 2> 332985 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@1fe91485
[junit4] 2> 332985 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/'
[junit4] 2> 333003 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 333005 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 333006 INFO (zkCallback-155-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1e102798 name:ZooKeeperConnection Watcher:127.0.0.1:47501/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333006 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 333006 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 333008 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 333009 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/solr.xml
[junit4] 2> 333025 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/cores
[junit4] 2> 333025 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoreContainer New CoreContainer 1900809906
[junit4] 2> 333025 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/]
[junit4] 2> 333026 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/lib
[junit4] 2> 333026 WARN (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.cloud.hdfs.HdfsBasicDistributedZk2Test_D18E239D34220062-001/shard-1-001/lib).
[junit4] 2> 333036 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 333037 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 333038 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 333038 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 333038 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:47501/solr
[junit4] 2> 333038 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 333038 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 333039 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 333041 INFO (zkCallback-157-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7c2b750b name:ZooKeeperConnection Watcher:127.0.0.1:47501 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 333041 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 333042 INFO (TEST-HdfsBasicDistributedZk2Test.test-seed#[D18E239D34220062]) [ ] o.a.s.c.c.SolrZkClient Using default ZkAC
[...truncated too long message...]
(TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-027/./collection1/data/index [CachedDir<<refCount=0;path=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-027/./collection1/data/index;done=false>>]
[junit4] 2> 6447424 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-027/./collection1/data/index
[junit4] 2> 6447424 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@14210e86{/solr,null,UNAVAILABLE}
[junit4] 2> 6447426 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@7fa6dbaa{HTTP/1.1}{127.0.0.1:0}
[junit4] 2> 6447426 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1856313456
[junit4] 2> 6447426 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@12ed078b
[junit4] 2> 6447427 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.u.UpdateHandler closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 6447427 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.u.SolrCoreState Closing SolrCoreState
[junit4] 2> 6447427 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.u.DefaultSolrCoreState SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 6447427 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.u.DefaultSolrCoreState closing IndexWriter with IndexWriterCloser
[junit4] 2> 6447428 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
[junit4] 2> 6447428 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 6447428 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-028/./collection1/data [CachedDir<<refCount=0;path=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-028/./collection1/data;done=false>>]
[junit4] 2> 6447429 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-028/./collection1/data
[junit4] 2> 6447429 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-028/./collection1/data/index [CachedDir<<refCount=0;path=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-028/./collection1/data/index;done=false>>]
[junit4] 2> 6447429 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001/solr-instance-028/./collection1/data/index
[junit4] 2> 6447430 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigReplication-seed#[D18E239D34220062]) [ x:collection1] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5910c85d{/solr,null,UNAVAILABLE}
[junit4] 2> 6447431 INFO (SUITE-TestReplicationHandler-seed#[D18E239D34220062]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_D18E239D34220062-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene53): {newname=PostingsFormat(name=Memory doPackFST= false), name=PostingsFormat(name=Memory doPackFST= false), id=PostingsFormat(name=Memory doPackFST= false)}, docValues:{}, sim=DefaultSimilarity, locale=ar_OM, timezone=IST
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_72 (64-bit)/cpus=4,threads=1,free=57398664,total=531103744
[junit4] 2> NOTE: All tests run in this JVM: [TestXIncludeConfig, SimpleCollectionCreateDeleteTest, OverseerStatusTest, DataDrivenBlockJoinTest, TestReplicaProperties, TestConfigReload, BinaryUpdateRequestHandlerTest, TestJsonRequest, XsltUpdateRequestHandlerTest, TestComplexPhraseQParserPlugin, DistributedDebugComponentTest, DistribCursorPagingTest, SparseHLLTest, MergeStrategyTest, VersionInfoTest, TestFastOutputStream, SolrInfoMBeanTest, TestUtils, TestDocSet, TestDefaultSimilarityFactory, DistributedIntervalFacetingTest, HdfsBasicDistributedZk2Test, SortByFunctionTest, SpatialHeatmapFacetsTest, BadIndexSchemaTest, TestSolrCLIRunExample, DistributedFacetPivotLargeTest, HighlighterMaxOffsetTest, LeaderElectionTest, FileBasedSpellCheckerTest, TestCollationField, StatsComponentTest, SOLR749Test, TestSystemIdResolver, RulesTest, BlockCacheTest, TestBM25SimilarityFactory, TestSolrQueryParser, DocExpirationUpdateProcessorFactoryTest, LoggingHandlerTest, TestLeaderElectionZkExpiry, ExplicitHLLTest, SuggesterTest, MoreLikeThisHandlerTest, TestSurroundQueryParser, TestDistribDocBasedVersion, ResponseHeaderTest, QueryParsingTest, TestZkChroot, TestNoOpRegenerator, TestSort, TestConfigSets, OverseerTest, TestExactSharedStatsCache, SpellCheckCollatorTest, RecoveryZkTest, TermVectorComponentDistributedTest, TestMacros, TestReload, SharedFSAutoReplicaFailoverTest, DistributedQueryComponentCustomSortTest, TestLuceneMatchVersion, CachingDirectoryFactoryTest, DistributedExpandComponentTest, TestExpandComponent, TestExtendedDismaxParser, TestCSVResponseWriter, TestSimpleTrackingShardHandler, TestPartialUpdateDeduplication, XmlUpdateRequestHandlerTest, TestManagedStopFilterFactory, CoreAdminCreateDiscoverTest, SearchHandlerTest, TestCloudPivotFacet, TestFieldTypeCollectionResource, TestScoreJoinQPNoScore, TestStressReorder, TestRandomRequestDistribution, SolrCoreCheckLockOnStartupTest, DOMUtilTest, TestTrackingShardHandlerFactory, TestBinaryResponseWriter, TestSolrXml, TestGroupingSearch, TestInfoStreamLogging, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, LeaderElectionIntegrationTest, ShardRoutingTest, BasicZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler]
[junit4] Completed [531/531] on J2 in 4238.84s, 13 tests, 1 failure <<< FAILURES!
[...truncated 14 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/build.xml:733: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/build.xml:670: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build.xml:230: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/common-build.xml:524: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/lucene/common-build.xml:1449: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/lucene/common-build.xml:1003: There were test failures: 531 suites, 2104 tests, 3 errors, 1 failure, 27 ignored (15 assumptions)
Total time: 376 minutes 47 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-NightlyTests-5.3 - Build # 12 - Still Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-5.3/12/
3 tests failed.
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload
Error Message:
expected:<[{indexVersion=1440187414141,generation=2,filelist=[_6t.fdt, _6t.fdx, _6t.fnm, _6t.nvd, _6t.nvm, _6t.si, _6t_Memory_0.ram, _6z.cfe, _6z.cfs, _6z.si, _70.cfe, _70.cfs, _70.si, _71.cfe, _71.cfs, _71.si, _72.cfe, _72.cfs, _72.si, _73.cfe, _73.cfs, _73.si, segments_2]}]> but was:<[{indexVersion=1440187414141,generation=3,filelist=[_6t.fdt, _6t.fdx, _6t.fnm, _6t.nvd, _6t.nvm, _6t.si, _6t_Memory_0.ram, _74.cfe, _74.cfs, _74.si, segments_3]}, {indexVersion=1440187414141,generation=2,filelist=[_6t.fdt, _6t.fdx, _6t.fnm, _6t.nvd, _6t.nvm, _6t.si, _6t_Memory_0.ram, _6z.cfe, _6z.cfs, _6z.si, _70.cfe, _70.cfs, _70.si, _71.cfe, _71.cfs, _71.si, _72.cfe, _72.cfs, _72.si, _73.cfe, _73.cfs, _73.si, segments_2]}]>
Stack Trace:
java.lang.AssertionError: expected:<[{indexVersion=1440187414141,generation=2,filelist=[_6t.fdt, _6t.fdx, _6t.fnm, _6t.nvd, _6t.nvm, _6t.si, _6t_Memory_0.ram, _6z.cfe, _6z.cfs, _6z.si, _70.cfe, _70.cfs, _70.si, _71.cfe, _71.cfs, _71.si, _72.cfe, _72.cfs, _72.si, _73.cfe, _73.cfs, _73.si, segments_2]}]> but was:<[{indexVersion=1440187414141,generation=3,filelist=[_6t.fdt, _6t.fdx, _6t.fnm, _6t.nvd, _6t.nvm, _6t.si, _6t_Memory_0.ram, _74.cfe, _74.cfs, _74.si, segments_3]}, {indexVersion=1440187414141,generation=2,filelist=[_6t.fdt, _6t.fdx, _6t.fnm, _6t.nvd, _6t.nvm, _6t.si, _6t_Memory_0.ram, _6z.cfe, _6z.cfs, _6z.si, _70.cfe, _70.cfs, _70.si, _71.cfe, _71.cfs, _71.si, _72.cfe, _72.cfs, _72.si, _73.cfe, _73.cfs, _73.si, segments_2]}]>
at __randomizedtesting.SeedInfo.seed([ABBC68D25DC3779C:8E6B73E22D8B799F]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:147)
at org.apache.solr.handler.TestReplicationHandler.doTestReplicateAfterCoreReload(TestReplicationHandler.java:1138)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
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:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
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:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test
Error Message:
Error from server at http://127.0.0.1:51984: Error CREATEing SolrCore 'halfcollection_shard1_replica1': Unable to create core [halfcollection_shard1_replica1] Caused by: Could not get shard id for core: halfcollection_shard1_replica1
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:51984: Error CREATEing SolrCore 'halfcollection_shard1_replica1': Unable to create core [halfcollection_shard1_replica1] Caused by: Could not get shard id for core: halfcollection_shard1_replica1
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.makeRequest(CollectionsAPIDistributedZkTest.java:301)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testErrorHandling(CollectionsAPIDistributedZkTest.java:418)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test(CollectionsAPIDistributedZkTest.java:168)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:963)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:938)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
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:46)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
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:54)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test
Error Message:
Captured an uncaught exception in thread: Thread[id=22224, name=collection1, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=22224, name=collection1, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:55655: Could not find collection : awholynewstresscollection_collection1_0
at __randomizedtesting.SeedInfo.seed([ABBC68D25DC3779C]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1085)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:894)
Build Log:
[...truncated 10754 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/init-core-data-001
[junit4] 2> 725246 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[ABBC68D25DC3779C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
[junit4] 2> 725246 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[ABBC68D25DC3779C]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 725251 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 725253 INFO (Thread-1952) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 725254 INFO (Thread-1952) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 725353 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.ZkTestServer start zk server on port:33903
[junit4] 2> 725354 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 725354 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 725357 INFO (zkCallback-311-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@57b0ae60 name:ZooKeeperConnection Watcher:127.0.0.1:33903 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 725357 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 725357 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 725357 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 725360 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 725366 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 725366 INFO (zkCallback-312-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@38ca0ebc name:ZooKeeperConnection Watcher:127.0.0.1:33903/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 725366 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 725367 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 725367 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
[junit4] 2> 725368 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
[junit4] 2> 725370 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
[junit4] 2> 725371 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
[junit4] 2> 725373 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 725373 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 725375 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 725376 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
[junit4] 2> 725377 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 725378 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 725379 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 725379 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
[junit4] 2> 725381 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 725381 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
[junit4] 2> 725383 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 725383 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
[junit4] 2> 725384 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 725385 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 725386 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 725386 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 725388 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 725388 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 725390 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 725390 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 725392 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 725392 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
[junit4] 2> 725684 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1
[junit4] 2> 725686 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 725687 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7dc5e23d{/,null,AVAILABLE}
[junit4] 2> 725689 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@3c150a75{HTTP/1.1}{127.0.0.1:40503}
[junit4] 2> 725689 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.Server Started @728831ms
[junit4] 2> 725689 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores, solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/tempDir-001/control/data, hostPort=40503, hostContext=/}
[junit4] 2> 725689 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@6b482747
[junit4] 2> 725690 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/'
[junit4] 2> 725706 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 725707 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 725708 INFO (zkCallback-313-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@24fc02e0 name:ZooKeeperConnection Watcher:127.0.0.1:33903/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 725708 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 725709 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 725710 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 725710 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/solr.xml
[junit4] 2> 725725 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores
[junit4] 2> 725725 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoreContainer New CoreContainer 269437805
[junit4] 2> 725725 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/]
[junit4] 2> 725725 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/lib
[junit4] 2> 725725 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/lib).
[junit4] 2> 725734 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 725735 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 725735 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 725736 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 725736 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33903/solr
[junit4] 2> 725736 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 725736 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 725737 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 725738 INFO (zkCallback-315-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3804f0d3 name:ZooKeeperConnection Watcher:127.0.0.1:33903 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 725739 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 725739 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 725741 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 725742 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1554e733 name:ZooKeeperConnection Watcher:127.0.0.1:33903/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 725742 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 725743 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
[junit4] 2> 725745 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
[junit4] 2> 725747 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
[junit4] 2> 725750 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
[junit4] 2> 725752 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
[junit4] 2> 725755 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 725757 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 725758 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 725760 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 725766 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40503_
[junit4] 2> 725766 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:40503_
[junit4] 2> 725768 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
[junit4] 2> 725769 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
[junit4] 2> 725771 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 725771 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94384023632936964-127.0.0.1:40503_-n_0000000000
[junit4] 2> 725772 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40503_
[junit4] 2> 725772 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
[junit4] 2> 725774 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer Overseer (id=94384023632936964-127.0.0.1:40503_-n_0000000000) starting
[junit4] 2> 725775 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
[junit4] 2> 725782 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 725783 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 725786 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 725786 INFO (OverseerCollectionProcessor-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.OverseerCollectionProcessor Process current queue of collection creations
[junit4] 2> 725808 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 725808 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 725809 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores
[junit4] 2> 725810 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.SolrCore Created CoreDescriptor: {transient=false, collection=control_collection, coreNodeName=, shard=, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1, dataDir=data/, loadOnStartup=true, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/, name=collection1, configSetProperties=configsetprops.json, schema=schema.xml, config=solrconfig.xml}
[junit4] 2> 725810 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/
[junit4] 2> 725810 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.c.CoresLocator Found 1 core definitions
[junit4] 2> 725811 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 725811 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 725812 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1
[junit4] 2> 725812 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:40503_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 725812 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.ZkController look for our core node name
[junit4] 2> 725812 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 725813 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1:40503",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":"127.0.0.1:40503_",
[junit4] 2> "roles":null,
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection"} current state version: 0
[junit4] 2> 725814 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1:40503",
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":"127.0.0.1:40503_",
[junit4] 2> "roles":null,
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection"}
[junit4] 2> 725814 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
[junit4] 2> 725814 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 725815 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 725817 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 1
[junit4] 2> 726812 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
[junit4] 2> 726813 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
[junit4] 2> 726813 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.ZkController Collection zkNode exists
[junit4] 2> 726813 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 726814 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 726814 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/'
[junit4] 2> 726830 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0
[junit4] 2> 726839 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 726853 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.3.0
[junit4] 2> 726883 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
[junit4] 2> 726884 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
[junit4] 2> 726892 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 727154 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 727163 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 727165 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 727175 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 727179 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 727182 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 727182 WARN (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 727183 WARN (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 727183 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 727183 WARN (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
[junit4] 2> 727183 WARN (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
[junit4] 2> 727184 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/configs/conf1', cwd=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1
[junit4] 2> 727185 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 727185 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 727185 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/], dataDir=[null]
[junit4] 2> 727185 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ffe9354
[junit4] 2> 727186 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/data
[junit4] 2> 727186 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/data/index/
[junit4] 2> 727186 WARN (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 727186 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/data/index
[junit4] 2> 727187 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=24, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.19899943985760293]
[junit4] 2> 727187 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=RawDirectoryWrapper(RAMDirectory@6c363714 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5b5a398c),segFN=segments_1,generation=1}
[junit4] 2> 727187 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 727192 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 727192 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 727193 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 727193 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 727193 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 727193 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 727193 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 727194 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 727194 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 727197 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 727198 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/data/
[junit4] 2> 727198 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 727198 WARN (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
[junit4] 2> 727201 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 727202 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 727206 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: standard,/update,/admin/ping,/admin/plugins,/get,/admin/segments,/admin/file,/config,/admin/properties,/admin/luke,/update/csv,/admin/threads,/replication,/update/json/docs,/admin/logging,/admin/mbeans,/schema,/admin/system,/update/json
[junit4] 2> 727207 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 727208 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 727208 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 727209 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
[junit4] 2> 727209 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
[junit4] 2> 727209 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=13, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=88.6494140625, floorSegmentMB=1.1689453125, forceMergeDeletesPctAllowed=17.60987502812817, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 727210 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=RawDirectoryWrapper(RAMDirectory@6c363714 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5b5a398c),segFN=segments_1,generation=1}
[junit4] 2> 727210 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
[junit4] 2> 727210 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@2bd27424[collection1] main
[junit4] 2> 727210 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
[junit4] 2> 727212 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 727212 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 727212 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 727212 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
[junit4] 2> 727212 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 727213 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 727213 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 727213 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 727213 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 727214 INFO (searcherExecutor-1104-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2bd27424[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 727214 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 727214 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
[junit4] 2> 727215 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
[junit4] 2> 727215 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1510144380182200320
[junit4] 2> 727217 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 3 ms to seed version buckets with highest version 1510144380182200320
[junit4] 2> 727217 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
[junit4] 2> 727218 INFO (coreLoadExecutor-1103-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 727218 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController Register replica - core:collection1 address:http://127.0.0.1:40503 collection:control_collection shard:shard1
[junit4] 2> 727219 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 727223 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.LeaderElector Joined leadership election with path: /collections/control_collection/leader_elect/shard1/election/94384023632936964-core_node1-n_0000000000
[junit4] 2> 727224 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
[junit4] 2> 727225 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 727226 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 727226 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection"} current state version: 1
[junit4] 2> 727226 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 727227 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40503/collection1/
[junit4] 2> 727227 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 727227 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:40503/collection1/ has no replicas
[junit4] 2> 727227 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:40503/collection1/ shard1
[junit4] 2> 727228 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 727236 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "base_url":"http://127.0.0.1:40503",
[junit4] 2> "core":"collection1",
[junit4] 2> "state":"active"} current state version: 1
[junit4] 2> 727238 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 727239 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 727240 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 2
[junit4] 2> 727282 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:40503/collection1/ and leader is http://127.0.0.1:40503/collection1/
[junit4] 2> 727282 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40503
[junit4] 2> 727282 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 727282 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
[junit4] 2> 727282 INFO (coreZkRegister-1097-thread-1-processing-r:core_node1 n:127.0.0.1:40503_ s:shard1 x:collection1 c:control_collection) [n:127.0.0.1:40503_ c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 727284 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 727285 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1:40503",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1:40503_",
[junit4] 2> "roles":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection"} current state version: 2
[junit4] 2> 727286 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1:40503",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1:40503_",
[junit4] 2> "roles":null,
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection"}
[junit4] 2> 727314 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 727316 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 727317 INFO (zkCallback-318-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@13c6ea91 name:ZooKeeperConnection Watcher:127.0.0.1:33903/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 727317 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 727317 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 727318 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 727320 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 727321 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 727321 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 727322 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 727323 INFO (zkCallback-319-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@c27091d name:ZooKeeperConnection Watcher:127.0.0.1:33903/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 727323 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 727323 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 727325 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 727326 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"create",
[junit4] 2> "name":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "stateFormat":"2"} current state version: 2
[junit4] 2> 727326 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1
[junit4] 2> 727327 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 727327 INFO (zkCallback-318-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 727329 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
[junit4] 2> 727337 INFO (zkCallback-318-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 3
[junit4] 2> 727432 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/collection1/state.json
[junit4] 2> 727433 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 727433 INFO (zkCallback-318-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 727435 INFO (zkCallback-318-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
[junit4] 2> 727435 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.c.ZkStateReader Updated cluster state version to 4
[junit4] 2> 727789 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/cores/collection1
[junit4] 2> 727791 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001
[junit4] 2> 727800 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529
[junit4] 2> 727869 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7e21d032{/,null,AVAILABLE}
[junit4] 2> 727869 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.ServerConnector Started ServerConnector@2163a7b5{HTTP/1.1}{127.0.0.1:51984}
[junit4] 2> 727869 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.e.j.s.Server Started @731011ms
[junit4] 2> 727870 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, hostPort=51984, solrconfig=solrconfig.xml, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/cores, solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/tempDir-001/jetty1}
[junit4] 2> 727870 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@6b482747
[junit4] 2> 727870 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/'
[junit4] 2> 727902 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 727904 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 727905 INFO (zkCallback-320-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@601e62a9 name:ZooKeeperConnection Watcher:127.0.0.1:33903/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 727905 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 727905 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 727906 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 727906 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/solr.xml
[junit4] 2> 727921 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/cores
[junit4] 2> 727922 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoreContainer New CoreContainer 385831866
[junit4] 2> 727922 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/]
[junit4] 2> 727922 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/lib
[junit4] 2> 727922 WARN (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/lib).
[junit4] 2> 727931 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 727932 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 727932 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 727932 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 727933 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33903/solr
[junit4] 2> 727933 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.ZkController zkHost includes chroot
[junit4] 2> 727933 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 727943 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 727944 INFO (zkCallback-322-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2d5608cd name:ZooKeeperConnection Watcher:127.0.0.1:33903 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 727945 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 727946 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 727951 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 727954 INFO (zkCallback-323-thread-1-processing-n:127.0.0.1:51984_) [n:127.0.0.1:51984_ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@b8862b9 name:ZooKeeperConnection Watcher:127.0.0.1:33903/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 727954 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 727959 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 728966 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51984_
[junit4] 2> 728970 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:51984_
[junit4] 2> 728973 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 728974 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94384023632936969-127.0.0.1:51984_-n_0000000001
[junit4] 2> 728975 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/94384023632936964-127.0.0.1:40503_-n_0000000000 to know if I could be the leader
[junit4] 2> 728994 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 728995 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 728995 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/cores
[junit4] 2> 728996 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.SolrCore Created CoreDescriptor: {config=solrconfig.xml, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/cores/collection1/, collection=collection1, coreNodeName=, shard=, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/cores/collection1, transient=false, dataDir=data/, name=collection1, loadOnStartup=true, schema=schema.xml, configSetProperties=configsetprops.json}
[junit4] 2> 728997 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/../../../../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_ABBC68D25DC3779C-001/shard-1-001/cores/collection1/
[junit4] 2> 728997 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.c.CoresLocator Found 1 core definitions
[junit4] 2> 728998 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build/solr-core/test/J1
[junit4] 2> 728998 INFO (TEST-CollectionsAPIDistributedZkTest.test-seed#[ABBC68D25DC3779C]) [n:127.0.0.1:51984_ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 728999 INFO (coreLoadExecutor-1114-thread-1-processing-n:127.0.0.1:51984_) [n:127.0.0.1:51984_ c:collection1 x:collection1] o.a.s.c.ZkController publishing state=down
[junit4] 2> 728999 INFO (coreLoadExecutor-1114-thread-1-processing-n:127.0.0.1:51984_) [n:127.0.0.1:51984_ c:collection1 x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
[junit4] 2> 729000 INFO (zkCallback-316-thread-1-processing-n:127.0.0.1:40503_) [n:127.0.0.1:40503_ ] o.a.s.c.DistributedQueue NodeChildrenChanged fired on path /overseer/queue state SyncConnected
[junit4] 2> 729000 INFO (coreLoadExecutor-1114-thread-1-processing-n:127.0.0.1:51984_) [n:127.0.0.1:51984_ c:collection1 x:collection1] o.a.s.c.ZkController Registering watch for external collection collection1
[junit4] 2> 729000 INFO (coreLoadExecutor-1114-thread-1-processing-n:127.0.0.1:51984_) [n:127.0.0.1:51984_ c:collection1 x:collection1] o.a.s.c.c.ZkStateReader addZkWatch collection1
[junit4] 2> 729000 INFO (OverseerStateUpdate-94384023632936964-127.0.0.1:40503_-n_0000000000) [n:127.0.0.1:40503_ ] o.a.
[...truncated too long message...]
it4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:799)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: java.lang.NullPointerException
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlocksMap.size(BlocksMap.java:198)
[junit4] 2> at org.apache.hadoop.hdfs.server.blockmanagement.BlockManager.getTotalBlocks(BlockManager.java:3291)
[junit4] 2> at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.getBlocksTotal(FSNamesystem.java:6223)
[junit4] 2> ... 53 more
[junit4] 2> 3910993 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-seed#[ABBC68D25DC3779C]-worker) [n:127.0.0.1:58433_ c:addReplicaColl s:shard2 r:core_node1 x:addReplicaColl_shard2_replica2] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> Aug 21, 2015 4:31:33 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene53): {a_i1=PostingsFormat(name=MockRandom), _version_=PostingsFormat(name=MockRandom), text=PostingsFormat(name=Direct), range_facet_l_dv=BlockTreeOrds(blocksize=128), intDefault=PostingsFormat(name=MockRandom), id=BlockTreeOrds(blocksize=128), range_facet_l=PostingsFormat(name=MockRandom), other_tl1=PostingsFormat(name=MockRandom), timestamp=PostingsFormat(name=MockRandom), range_facet_i_dv=PostingsFormat(name=MockRandom), multiDefault=FSTOrd50, a_t=PostingsFormat(name=MockRandom)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Lucene50), timestamp=DocValuesFormat(name=Memory), range_facet_i_dv=DocValuesFormat(name=Memory)}, sim=DefaultSimilarity, locale=sv, timezone=GB
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_72 (64-bit)/cpus=4,threads=2,free=50065472,total=530579456
[junit4] 2> NOTE: All tests run in this JVM: [TestUtils, TestSchemaNameResource, TestStressRecovery, TestConfigReload, TestRequestStatusCollectionAPI, QueryParsingTest, OutputWriterTest, OpenExchangeRatesOrgProviderTest, BigEndianAscendingWordSerializerTest, DirectUpdateHandlerOptimizeTest, TestDefaultStatsCache, DistributedIntervalFacetingTest, TestDistribDocBasedVersion, LeaderElectionTest, TestScoreJoinQPScore, SampleTest, SolrCoreCheckLockOnStartupTest, TestXIncludeConfig, XmlUpdateRequestHandlerTest, DistributedQueryElevationComponentTest, HLLSerializationTest, TestFileDictionaryLookup, TestFieldTypeCollectionResource, CoreAdminCreateDiscoverTest, HttpPartitionTest, TestConfigSets, SpatialHeatmapFacetsTest, CollectionTooManyReplicasTest, TestMaxScoreQueryParser, HdfsBasicDistributedZk2Test, RemoteQueryErrorTest, SpellCheckCollatorTest, PathHierarchyTokenizerFactoryTest, TestSolrQueryParser, TestDefaultSimilarityFactory, TestPartialUpdateDeduplication, SimpleFacetsTest, TestCollationFieldDocValues, TestLeaderElectionZkExpiry, SortByFunctionTest, SparseHLLTest, TestZkChroot, TestFastOutputStream, SuggesterTest, TestBulkSchemaAPI, BlockDirectoryTest, SearchHandlerTest, CustomCollectionTest, DistributedFacetPivotLargeTest, TestNoOpRegenerator, TestClusterStateMutator, TestCSVResponseWriter, TestCloudPivotFacet, TestBinaryResponseWriter, TestSimpleTrackingShardHandler, SSLMigrationTest, TestSolrXml, RegexBoostProcessorTest, HighlighterMaxOffsetTest, DistributedDebugComponentTest, MoreLikeThisHandlerTest, TestScoreJoinQPNoScore, HardAutoCommitTest, FullSolrCloudDistribCmdsTest, SolrIndexSplitterTest, SolrInfoMBeanTest, BadIndexSchemaTest, TestExtendedDismaxParser, TestRemoveLastDynamicCopyField, MergeStrategyTest, TestInfoStreamLogging, TestRestoreCore, AutoCommitTest, TestSchemaVersionResource, DocExpirationUpdateProcessorFactoryTest, TestFreeTextSuggestions, TestTrackingShardHandlerFactory, VersionInfoTest, ChangedSchemaMergeTest, ExplicitHLLTest, TestSolrJ, TestMacros, TestLuceneMatchVersion, BasicDistributedZk2Test, UnloadDistributedZkTest, OpenCloseCoreStressTest, OverseerTest, ShardRoutingTest, BasicZkTest, RecoveryZkTest, TestRandomFaceting, ZkCLITest, ShardRoutingCustomTest, TestFaceting, TestRecovery, TestHashPartitioner, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, TestStressReorder, TestJoin, TestReload, SolrCoreTest, StatsComponentTest, TestGroupingSearch, PeerSyncTest, ConvertedLegacyTest, TestSort, TestFunctionQuery, BasicFunctionalityTest, TestLazyCores, DirectUpdateHandlerTest, TestBadConfig, OverseerCollectionProcessorTest, TestIndexSearcher, HighlighterTest, SoftAutoCommitTest, AnalysisAfterCoreReloadTest, CoreAdminHandlerTest, DocValuesTest, TestTrie, SpatialFilterTest, SuggesterWFSTTest, PolyFieldTest, NoCacheHeaderTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, QueryEqualityTest, TestRemoteStreaming, DocValuesMultiTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, DebugComponentTest, IndexBasedSpellCheckerTest, TestSurroundQueryParser, LukeRequestHandlerTest, TestQueryUtils, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, DocumentAnalysisRequestHandlerTest, TestQueryTypes, PrimitiveFieldTypeTest, FileBasedSpellCheckerTest, RequestHandlersTest, DocumentBuilderTest, TermVectorComponentTest, FastVectorHighlighterTest, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, SolrPluginUtilsTest, TestCollationField, MBeansHandlerTest, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestLFUCache, SOLR749Test, UpdateParamsTest, TestSolrIndexConfig, TestQuerySenderNoQuery, CopyFieldTest, ResponseLogComponentTest, SolrIndexConfigTest, TestSolrDeletionPolicy2, MultiTermTest, TestDocSet, NumericFieldsTest, MinimalSchemaTest, TestElisionMultitermQuery, TestConfig, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, NotRequiredUniqueKeyTest, SpellPossibilityIteratorTest, TestCodecSupport, SynonymTokenizerTest, TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestBM25SimilarityFactory, TestFastWriter, ResourceLoaderTest, ScriptEngineTest, URLClassifyProcessorTest, PluginInfoTest, ChaosMonkeyNothingIsSafeTest, AssignTest, AsyncCallRequestStatusResponseTest, CleanupOldIndexTest, CloudExitableDirectoryReaderTest, DeleteInactiveReplicaTest, DistribCursorPagingTest, LeaderInitiatedRecoveryOnCommitTest, MultiThreadedOCPTest, OverseerStatusTest, ReplicationFactorTest, SaslZkACLProviderTest, SharedFSAutoReplicaFailoverTest, HdfsCollectionsAPIDistributedZkTest]
[junit4] Completed [479/531] on J2 in 634.63s, 1 test, 1 error <<< FAILURES!
[...truncated 168 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/build.xml:733: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/build.xml:670: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/build.xml:230: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/solr/common-build.xml:524: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/lucene/common-build.xml:1449: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-5.3/lucene/common-build.xml:1003: There were test failures: 531 suites, 2104 tests, 2 errors, 1 failure, 27 ignored (15 assumptions)
Total time: 202 minutes 28 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure