Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 19392200BC5 for ; Tue, 22 Nov 2016 23:13:12 +0100 (CET) Received: by cust-asf.ponee.io (Postfix) id 17B6E160B0C; Tue, 22 Nov 2016 22:13:12 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 68135160AF1 for ; Tue, 22 Nov 2016 23:13:09 +0100 (CET) Received: (qmail 14755 invoked by uid 500); 22 Nov 2016 22:13:08 -0000 Mailing-List: contact dev-help@lucene.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@lucene.apache.org Delivered-To: mailing list dev@lucene.apache.org Received: (qmail 14745 invoked by uid 99); 22 Nov 2016 22:13:08 -0000 Received: from crius.apache.org (HELO crius.apache.org) (140.211.11.14) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 22 Nov 2016 22:13:08 +0000 Received: from crius.apache.org (localhost [127.0.0.1]) by crius.apache.org (ASF Mail Server at crius.apache.org) with ESMTP id 7E99E9C00A1 for ; Tue, 22 Nov 2016 22:13:04 +0000 (UTC) Date: Tue, 22 Nov 2016 22:08:27 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <2002246397.1878.1479852784519.JavaMail.jenkins@crius> In-Reply-To: <2029948231.1510.1479755038819.JavaMail.jenkins@crius> References: <2029948231.1510.1479755038819.JavaMail.jenkins@crius> Subject: [JENKINS] Lucene-Solr-NightlyTests-6.x - Build # 207 - Still Unstable MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_1877_591871967.1479852784227" X-Jenkins-Job: Lucene-Solr-NightlyTests-6.x X-Jenkins-Result: UNSTABLE archived-at: Tue, 22 Nov 2016 22:13:12 -0000 ------=_Part_1877_591871967.1479852784227 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-6.x/207/ 4 tests failed. FAILED: org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.te= stRestartWithAllInLIR Error Message: There are still nodes recoverying - waited for 330 seconds Stack Trace: java.lang.AssertionError: There are still nodes recoverying - waited for 33= 0 seconds =09at __randomizedtesting.SeedInfo.seed([85E88260B81B20E2:5B62EC1D83B94211]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:184) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:141) =09at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFi= nish(AbstractDistribZkTestBase.java:136) =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveries= ToFinish(AbstractFullDistribZkTestBase.java:856) =09at org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest.testR= estartWithAllInLIR(LeaderInitiatedRecoveryOnShardRestartTest.java:158) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:498) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1713) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:907) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:957) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= FixedStatement.callStatement(BaseDistributedSearchTestCase.java:992) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= Statement.evaluate(BaseDistributedSearchTestCase.java:967) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:49) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:811) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:462) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:916) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:802) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:852) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:863) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:41) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:53) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:54) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at java.lang.Thread.run(Thread.java:745) FAILED: org.apache.solr.store.blockcache.BlockDirectoryTest.testRandomAcce= ssWritesLargeCache Error Message: Direct buffer memory Stack Trace: java.lang.OutOfMemoryError: Direct buffer memory =09at java.nio.Bits.reserveMemory(Bits.java:693) =09at java.nio.DirectByteBuffer.(DirectByteBuffer.java:123) =09at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:311) =09at org.apache.solr.store.blockcache.BlockCache.(BlockCache.java:68= ) =09at org.apache.solr.store.blockcache.BlockDirectoryTest.setUp(BlockDirect= oryTest.java:119) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:498) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1713) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:941) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:957) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:49) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:811) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:462) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:916) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:802) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:852) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:863) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:41) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:53) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:54) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at java.lang.Thread.run(Thread.java:745) FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.tes= tCollectionsAPI Error Message: Expected to see collection awhollynewcollection_0 null Last available state= : DocCollection(awhollynewcollection_0//collections/awhollynewcollection_0/= state.json/9)=3D{ "replicationFactor":"4", "shards":{ "shard1":{ = "range":"80000000-d554ffff", "state":"active", "replicas":{= }}, "shard2":{ "range":"d5550000-2aa9ffff", "state":"active= ", "replicas":{}}, "shard3":{ "range":"2aaa0000-7fffffff", = "state":"active", "replicas":{}}}, "router":{"name":"composit= eId"}, "maxShardsPerNode":"4", "autoAddReplicas":"false"} Stack Trace: java.lang.AssertionError: Expected to see collection awhollynewcollection_0 null Last available state: DocCollection(awhollynewcollection_0//collections/awh= ollynewcollection_0/state.json/9)=3D{ "replicationFactor":"4", "shards":{ "shard1":{ "range":"80000000-d554ffff", "state":"active", "replicas":{}}, "shard2":{ "range":"d5550000-2aa9ffff", "state":"active", "replicas":{}}, "shard3":{ "range":"2aaa0000-7fffffff", "state":"active", "replicas":{}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"4", "autoAddReplicas":"false"} =09at __randomizedtesting.SeedInfo.seed([85E88260B81B20E2:CD9DF6D4BE280F77]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCas= e.java:236) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollections= API(CollectionsAPIDistributedZkTest.java:496) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:498) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1713) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:907) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:957) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:49) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:811) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:462) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:916) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:802) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:852) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:863) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:41) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:53) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:54) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at java.lang.Thread.run(Thread.java:745) FAILED: org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.tes= tSpecificConfigsets Error Message: KeeperErrorCode =3D NoNode for /collections/withconfigset2 Stack Trace: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode =3D N= oNode for /collections/withconfigset2 =09at __randomizedtesting.SeedInfo.seed([85E88260B81B20E2:A896CD3A4F3F9AEE]= :0) =09at org.apache.zookeeper.KeeperException.create(KeeperException.java:111) =09at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) =09at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) =09at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java= :356) =09at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java= :353) =09at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecut= or.java:60) =09at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:3= 53) =09at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSpecificCon= figsets(CollectionsAPIDistributedZkTest.java:425) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:498) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1713) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:907) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:957) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:49) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:811) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:462) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:916) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:802) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:852) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:863) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:41) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:53) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:54) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:367) =09at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 11284 lines...] [junit4] Suite: org.apache.solr.store.blockcache.BlockDirectoryTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Luce= ne-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.st= ore.blockcache.BlockDirectoryTest_85E88260B81B20E2-001/init-core-data-001 [junit4] 2> 487679 INFO (SUITE-BlockDirectoryTest-seed#[85E88260B81B2= 0E2]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientA= uth (true) via: @org.apache.solr.util.RandomizeSSL(reason=3D, ssl=3DNaN, va= lue=3DNaN, clientAuth=3DNaN) [junit4] 2> 487687 INFO (TEST-BlockDirectoryTest.testRandomAccessWrit= esLargeCache-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Starti= ng testRandomAccessWritesLargeCache [junit4] 2> 489311 INFO (TEST-BlockDirectoryTest.testRandomAccessWrit= esLargeCache-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Ending= testRandomAccessWritesLargeCache [junit4] 2> NOTE: download the large Jenkins line-docs file by running= 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DBlockDirector= yTest -Dtests.method=3DtestRandomAccessWritesLargeCache -Dtests.seed=3D85E8= 8260B81B20E2 -Dtests.multiplier=3D2 -Dtests.nightly=3Dtrue -Dtests.slow=3Dt= rue -Dtests.linedocsfile=3D/home/jenkins/jenkins-slave/workspace/Lucene-Sol= r-NightlyTests-6.x/test-data/enwiki.random.lines.txt -Dtests.locale=3Did-ID= -Dtests.timezone=3DAfrica/Libreville -Dtests.asserts=3Dtrue -Dtests.file.e= ncoding=3DUS-ASCII [junit4] ERROR 1.64s J1 | BlockDirectoryTest.testRandomAccessWritesLar= geCache <<< [junit4] > Throwable #1: java.lang.OutOfMemoryError: Direct buffer me= mory [junit4] > =09at java.nio.Bits.reserveMemory(Bits.java:693) [junit4] > =09at java.nio.DirectByteBuffer.(DirectByteBuffer.ja= va:123) [junit4] > =09at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:3= 11) [junit4] > =09at org.apache.solr.store.blockcache.BlockCache.(B= lockCache.java:68) [junit4] > =09at org.apache.solr.store.blockcache.BlockDirectoryTest.= setUp(BlockDirectoryTest.java:119) [junit4] > =09at java.lang.Thread.run(Thread.java:745)Throwable #2: j= ava.lang.NullPointerException [junit4] > =09at org.apache.solr.store.blockcache.BlockDirectoryTest.= tearDown(BlockDirectoryTest.java:131) [junit4] > =09at java.lang.Thread.run(Thread.java:745) [junit4] 2> 489319 INFO (TEST-BlockDirectoryTest.ensureCacheConfigura= ble-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Starting ensure= CacheConfigurable [junit4] 2> 489579 INFO (TEST-BlockDirectoryTest.ensureCacheConfigura= ble-seed#[85E88260B81B20E2]) [ ] o.a.s.s.b.BlockDirectory Block cache on= write is disabled [junit4] 2> 489579 INFO (TEST-BlockDirectoryTest.ensureCacheConfigura= ble-seed#[85E88260B81B20E2]) [ ] o.a.s.s.b.BlockDirectory Block cache on= write is disabled [junit4] 2> 489579 INFO (TEST-BlockDirectoryTest.ensureCacheConfigura= ble-seed#[85E88260B81B20E2]) [ ] o.a.s.s.b.BlockDirectory Block cache on= read is disabled [junit4] 2> 489579 INFO (TEST-BlockDirectoryTest.ensureCacheConfigura= ble-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Ending ensureCa= cheConfigurable [junit4] 2> 489583 INFO (TEST-BlockDirectoryTest.testRandomAccessWrit= es-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRan= domAccessWrites [junit4] 1> Total time is 3168ms [junit4] 2> 492754 INFO (TEST-BlockDirectoryTest.testRandomAccessWrit= es-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testRando= mAccessWrites [junit4] 2> 492757 INFO (TEST-BlockDirectoryTest.testEOF-seed#[85E882= 60B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEOF [junit4] 2> 492818 INFO (TEST-BlockDirectoryTest.testEOF-seed#[85E882= 60B81B20E2]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEOF [junit4] 2> 492819 INFO (SUITE-BlockDirectoryTest-seed#[85E88260B81B2= 0E2]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenk= ins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-c= ore/test/J1/temp/solr.store.blockcache.BlockDirectoryTest_85E88260B81B20E2-= 001 [junit4] 2> NOTE: test params are: codec=3DAsserting(Lucene62): {}, do= cValues:{}, maxPointsInLeafNode=3D1406, maxMBSortInHeap=3D7.589330986925872= , sim=3DRandomSimilarity(queryNorm=3Dfalse,coord=3Dyes): {}, locale=3Did-ID= , timezone=3DAfrica/Libreville [junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8= .0_102 (64-bit)/cpus=3D4,threads=3D1,free=3D317294960,total=3D496500736 [junit4] 2> NOTE: All tests run in this JVM: [WordBreakSolrSpellChecke= rTest, DocumentBuilderTest, TestHashQParserPlugin, TestDynamicFieldResource= , DateMathParserTest, CollectionsAPIDistributedZkTest, HdfsRecoveryZkTest, = TestDocBasedVersionConstraints, TestCloudManagedSchema, SpellCheckCollatorT= est, HdfsBasicDistributedZkTest, TestLuceneMatchVersion, SpatialFilterTest,= CustomCollectionTest, TestUseDocValuesAsStored2, TestCharFilters, BlockDir= ectoryTest] [junit4] Completed [49/655 (1!)] on J1 in 5.17s, 4 tests, 1 error <<< FA= ILURES! [...truncated 232 lines...] [junit4] Suite: org.apache.solr.cloud.LeaderInitiatedRecoveryOnShardRest= artTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Luce= ne-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cl= oud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/init-cor= e-data-001 [junit4] 2> 642935 INFO (SUITE-LeaderInitiatedRecoveryOnShardRestartT= est-seed#[85E88260B81B20E2]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized = ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$Sup= pressSSL(bugUrl=3Dhttps://issues.apache.org/jira/browse/SOLR-5776) [junit4] 2> 642935 INFO (SUITE-LeaderInitiatedRecoveryOnShardRestartT= est-seed#[85E88260B81B20E2]-worker) [ ] o.a.s.BaseDistributedSearchTestC= ase Setting hostContext system property: /v/ml [junit4] 2> 642941 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.ZkTestSe= rver STARTING ZK TEST SERVER [junit4] 2> 642947 INFO (Thread-37340) [ ] o.a.s.c.ZkTestServer cl= ient port:0.0.0.0/0.0.0.0:0 [junit4] 2> 642947 INFO (Thread-37340) [ ] o.a.s.c.ZkTestServer St= arting server [junit4] 2> 643042 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.ZkTestSe= rver start zk server on port:45774 [junit4] 2> 643066 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlo= g.xml to /configs/conf1/solrconfig.xml [junit4] 2> 643073 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/schema.xml to = /configs/conf1/schema.xml [junit4] 2> 643075 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/solrconfig.sni= ppet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindex= config.xml [junit4] 2> 643076 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/stopwords.txt = to /configs/conf1/stopwords.txt [junit4] 2> 643077 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/protwords.txt = to /configs/conf1/protwords.txt [junit4] 2> 643079 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/currency.xml t= o /configs/conf1/currency.xml [junit4] 2> 643080 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xm= l to /configs/conf1/enumsConfig.xml [junit4] 2> 643083 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/open-exchange-= rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 643085 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLat= in1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 643086 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/old_synonyms.t= xt to /configs/conf1/old_synonyms.txt [junit4] 2> 643087 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= ZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests= -6.x/checkout/solr/core/src/test-files/solr/collection1/conf/synonyms.txt t= o /configs/conf1/synonyms.txt [junit4] 2> 643212 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCa= seJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lu= cene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.= cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/contro= l-001/cores/collection1 [junit4] 2> 643213 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.Server j= etty-9.3.8.v20160314 [junit4] 2> 643215 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.h.Contex= tHandler Started o.e.j.s.ServletContextHandler@65651551{/v/ml,null,AVAILABL= E} [junit4] 2> 643223 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.ServerCo= nnector Started ServerConnector@311bf46e{HTTP/1.1,[http/1.1]}{127.0.0.1:506= 33} [junit4] 2> 643224 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.Server S= tarted @647481ms [junit4] 2> 643224 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.s.e.Jett= ySolrRunner Jetty properties: {solr.data.dir=3D/x1/jenkins/jenkins-slave/wo= rkspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/= temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-= 001/tempDir-001/control/data, hostContext=3D/v/ml, hostPort=3D50633, coreRo= otDirectory=3D/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-= 6.x/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../= x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/so= lr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRe= startTest_85E88260B81B20E2-001/control-001/cores} [junit4] 2> 643224 ERROR (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.StartupL= oggingUtils Missing Java Option solr.log.dir. Logging may be missing or inc= omplete. [junit4] 2> 643230 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter ___ _ Welcome to Apache Solr? version 6.4.0 [junit4] 2> 643230 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 643230 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 643231 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter |___/\___/_|_| Start time: 2016-11-22T20:28:13.079Z [junit4] 2> 643271 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 643271 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.SolrXmlC= onfig Loading container configuration from /x1/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp= /solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/= control-001/solr.xml [junit4] 2> 643278 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.u.UpdateSh= ardHandler Creating UpdateShardHandler HTTP client with params: socketTimeo= ut=3D340000&connTimeout=3D45000&retry=3Dtrue [junit4] 2> 643279 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.ZkContai= ner Zookeeper client=3D127.0.0.1:45774/solr [junit4] 2> 643300 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:50633_v%2F= ml ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0= .1:50633_v%2Fml [junit4] 2> 643301 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:50633_v%2F= ml ] o.a.s.c.Overseer Overseer (id=3D96983219752402948-127.0.0.1:50633_v= %2Fml-n_0000000000) starting [junit4] 2> 643309 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:50633_v%2F= ml ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes= /127.0.0.1:50633_v%2Fml [junit4] 2> 643311 INFO (zkCallback-676-thread-1-processing-n:127.0.0= .1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.c.ZkStateReader Upd= ated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 643436 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:50633_v%2F= ml ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /= x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/so= lr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenk= ins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-c= ore/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88= 260B81B20E2-001/control-001/cores [junit4] 2> 643436 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:50633_v%2F= ml ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 643440 INFO (OverseerStateUpdate-96983219752402948-127.0.= 0.1:50633_v%2Fml-n_0000000000) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.o.Rep= licaMutator Assigning new node to shard shard=3Dshard1 [junit4] 2> 643459 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection x:= collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 643473 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection x:= collection1] o.a.s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 643573 WARN (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection x:= collection1] o.a.s.s.IndexSchema [collection1] default search field in sche= ma is text. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 643575 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection x:= collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field= id [junit4] 2> 643589 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection x:= collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using co= nfiguration from collection control_collection [junit4] 2> 643595 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening = new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTes= ts-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiate= dRecoveryOnShardRestartTest_85E88260B81B20E2-001/control-001/cores/collecti= on1], dataDir=3D[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTes= ts-6.x/checkout/solr/build/solr-core/test/J1/../../../../../../../../../../= ../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout= /solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShar= dRestartTest_85E88260B81B20E2-001/control-001/cores/collection1/data/] [junit4] 2> 643595 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is = enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBean= Server@2ad946c0 [junit4] 2> 643597 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolic= y wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePol= icy: maxMergeAtOnce=3D16, maxMergeAtOnceExplicit=3D43, maxMergedSegmentMB= =3D5.7138671875, floorSegmentMB=3D0.2158203125, forceMergeDeletesPctAllowed= =3D22.681022262712812, segmentsPerTier=3D27.0, maxCFSSegmentSizeMB=3D8.7960= 93022207999E12, noCFSRatio=3D0.8516399023712865 [junit4] 2> 643606 WARN (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a= in requestHandler {type =3D requestHandler,name =3D /dump,class =3D DumpRe= questHandler,args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 643614 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog impl= ementation: org.apache.solr.update.UpdateLog [junit4] 2> 643614 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: = dataDir=3D defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep= =3D10 numVersionBuckets=3D65536 [junit4] 2> 643615 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: dis= abled [junit4] 2> 643615 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: dis= abled [junit4] 2> 643615 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolic= y wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMe= rgePolicy: minMergeSize=3D0, mergeFactor=3D10, maxMergeSize=3D391712009, ma= xMergeSizeForForcedMerge=3D9223372036854775807, calibrateSizeByDeletes=3Dtr= ue, maxMergeDocs=3D2147483647, maxCFSSegmentSizeMB=3D8.796093022207999E12, = noCFSRatio=3D0.1] [junit4] 2> 643616 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searche= r@2c8a218[collection1] main] [junit4] 2> 643617 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured = ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 643617 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null= at path _rest_managed.json using ZooKeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 643618 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be= reserved for 10000 [junit4] 2> 643618 INFO (searcherExecutor-2232-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_n= ode1) [n:127.0.0.1:50633_v%2Fml c:control_collection s:shard1 r:core_node1 = x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searc= her@2c8a218[collection1] main{ExitableDirectoryReader(UninvertingDirectoryR= eader())} [junit4] 2> 643618 INFO (coreLoadExecutor-2231-thread-1-processing-n:= 127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml c:control_collection s:sh= ard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max versi= on in index or recent updates, using new clock 1551731516733652992 [junit4] 2> 643629 INFO (coreZkRegister-2224-thread-1-processing-n:12= 7.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_nod= e1) [n:127.0.0.1:50633_v%2Fml c:control_collection s:shard1 r:core_node1 x:= collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to co= ntinue. [junit4] 2> 643629 INFO (coreZkRegister-2224-thread-1-processing-n:12= 7.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_nod= e1) [n:127.0.0.1:50633_v%2Fml c:control_collection s:shard1 r:core_node1 x:= collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - t= ry and sync [junit4] 2> 643629 INFO (coreZkRegister-2224-thread-1-processing-n:12= 7.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_nod= e1) [n:127.0.0.1:50633_v%2Fml c:control_collection s:shard1 r:core_node1 x:= collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:50633/v= /ml/collection1/ [junit4] 2> 643629 INFO (coreZkRegister-2224-thread-1-processing-n:12= 7.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_nod= e1) [n:127.0.0.1:50633_v%2Fml c:control_collection s:shard1 r:core_node1 x:= collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 643629 INFO (coreZkRegister-2224-thread-1-processing-n:12= 7.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_nod= e1) [n:127.0.0.1:50633_v%2Fml c:control_collection s:shard1 r:core_node1 x:= collection1] o.a.s.c.SyncStrategy http://127.0.0.1:50633/v/ml/collection1/ = has no replicas [junit4] 2> 643634 INFO (coreZkRegister-2224-thread-1-processing-n:12= 7.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_nod= e1) [n:127.0.0.1:50633_v%2Fml 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:50633/v/ml/collection1/ shard1 [junit4] 2> 643786 INFO (coreZkRegister-2224-thread-1-processing-n:12= 7.0.0.1:50633_v%2Fml x:collection1 s:shard1 c:control_collection r:core_nod= e1) [n:127.0.0.1:50633_v%2Fml c:control_collection s:shard1 r:core_node1 x:= collection1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 643942 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.c.ZkStat= eReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 643943 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.ChaosMon= key monkey: init - expire sessions:false cause connection loss:false [junit4] 2> 644054 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCa= seJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lu= cene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.= cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/shard-= 1-001/cores/collection1 [junit4] 2> 644054 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= FullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave= /workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/= J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20= E2-001/shard-1-001 [junit4] 2> 644055 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.Server j= etty-9.3.8.v20160314 [junit4] 2> 644057 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.h.Contex= tHandler Started o.e.j.s.ServletContextHandler@51c8c35c{/v/ml,null,AVAILABL= E} [junit4] 2> 644058 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.ServerCo= nnector Started ServerConnector@5941a73e{HTTP/1.1,[http/1.1]}{127.0.0.1:338= 27} [junit4] 2> 644058 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.Server S= tarted @648315ms [junit4] 2> 644058 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.s.e.Jett= ySolrRunner Jetty properties: {solr.data.dir=3D/x1/jenkins/jenkins-slave/wo= rkspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/= temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-= 001/tempDir-001/jetty1, solrconfig=3Dsolrconfig.xml, hostContext=3D/v/ml, h= ostPort=3D33827, coreRootDirectory=3D/x1/jenkins/jenkins-slave/workspace/Lu= cene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.= cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/shard-= 1-001/cores} [junit4] 2> 644058 ERROR (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.StartupL= oggingUtils Missing Java Option solr.log.dir. Logging may be missing or inc= omplete. [junit4] 2> 644066 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter ___ _ Welcome to Apache Solr? version 6.4.0 [junit4] 2> 644066 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 644066 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 644066 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter |___/\___/_|_| Start time: 2016-11-22T20:28:13.915Z [junit4] 2> 644078 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 644078 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.SolrXmlC= onfig Loading container configuration from /x1/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp= /solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/= shard-1-001/solr.xml [junit4] 2> 644086 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.u.UpdateSh= ardHandler Creating UpdateShardHandler HTTP client with params: socketTimeo= ut=3D340000&connTimeout=3D45000&retry=3Dtrue [junit4] 2> 644087 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.ZkContai= ner Zookeeper client=3D127.0.0.1:45774/solr [junit4] 2> 644112 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:33827_v%2F= ml ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) ->= (1) [junit4] 2> 644117 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:33827_v%2F= ml ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes= /127.0.0.1:33827_v%2Fml [junit4] 2> 644119 INFO (zkCallback-676-thread-1-processing-n:127.0.0= .1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.c.ZkStateReader Upd= ated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 644121 INFO (zkCallback-680-thread-1) [ ] o.a.s.c.c.Zk= StateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 644128 INFO (zkCallback-685-thread-1-processing-n:127.0.0= .1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml ] o.a.s.c.c.ZkStateReader Upd= ated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 644173 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:33827_v%2F= ml ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /= x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/so= lr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRe= startTest_85E88260B81B20E2-001/shard-1-001/cores [junit4] 2> 644173 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:33827_v%2F= ml ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 644177 INFO (OverseerStateUpdate-96983219752402948-127.0.= 0.1:50633_v%2Fml-n_0000000000) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.o.Rep= licaMutator Assigning new node to shard shard=3Dshard1 [junit4] 2> 645205 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 x:collect= ion1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 645219 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 x:collect= ion1] o.a.s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 645316 WARN (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 x:collect= ion1] o.a.s.s.IndexSchema [collection1] default search field in schema is t= ext. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 645318 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 x:collect= ion1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 645331 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 x:collect= ion1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configura= tion from collection collection1 [junit4] 2> 645331 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new Sol= rCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/= checkout/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecove= ryOnShardRestartTest_85E88260B81B20E2-001/shard-1-001/cores/collection1], d= ataDir=3D[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/= checkout/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecove= ryOnShardRestartTest_85E88260B81B20E2-001/shard-1-001/cores/collection1/dat= a/] [junit4] 2> 645331 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 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@= 2ad946c0 [junit4] 2> 645334 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapp= ing class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: ma= xMergeAtOnce=3D16, maxMergeAtOnceExplicit=3D43, maxMergedSegmentMB=3D5.7138= 671875, floorSegmentMB=3D0.2158203125, forceMergeDeletesPctAllowed=3D22.681= 022262712812, segmentsPerTier=3D27.0, maxCFSSegmentSizeMB=3D8.7960930222079= 99E12, noCFSRatio=3D0.8516399023712865 [junit4] 2> 645344 WARN (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in req= uestHandler {type =3D requestHandler,name =3D /dump,class =3D DumpRequestHa= ndler,args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 645355 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementat= ion: org.apache.solr.update.UpdateLog [junit4] 2> 645355 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= =3D defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 n= umVersionBuckets=3D65536 [junit4] 2> 645356 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 645356 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 645363 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapp= ing class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePoli= cy: minMergeSize=3D0, mergeFactor=3D10, maxMergeSize=3D391712009, maxMergeS= izeForForcedMerge=3D9223372036854775807, calibrateSizeByDeletes=3Dtrue, max= MergeDocs=3D2147483647, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRa= tio=3D0.1] [junit4] 2> 645363 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@43964= 173[collection1] main] [junit4] 2> 645364 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeep= erStorageIO with znodeBase: /configs/conf1 [junit4] 2> 645365 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at pat= h _rest_managed.json using ZooKeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 645365 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserv= ed for 10000 [junit4] 2> 645365 INFO (coreLoadExecutor-2242-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:= core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max version in i= ndex or recent updates, using new clock 1551731518565515264 [junit4] 2> 645373 INFO (searcherExecutor-2243-thread-1-processing-n:= 127.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [= n:127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1]= o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@43964173[c= ollection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 645379 INFO (coreZkRegister-2237-thread-1-processing-n:12= 7.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [n:= 127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1] o= .a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 645379 INFO (coreZkRegister-2237-thread-1-processing-n:12= 7.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [n:= 127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1] o= .a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 645379 INFO (coreZkRegister-2237-thread-1-processing-n:12= 7.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [n:= 127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1] o= .a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:33827/v/ml/collection= 1/ [junit4] 2> 645379 INFO (coreZkRegister-2237-thread-1-processing-n:12= 7.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [n:= 127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1] o= .a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 645379 INFO (coreZkRegister-2237-thread-1-processing-n:12= 7.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [n:= 127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1] o= .a.s.c.SyncStrategy http://127.0.0.1:33827/v/ml/collection1/ has no replica= s [junit4] 2> 645384 INFO (coreZkRegister-2237-thread-1-processing-n:12= 7.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [n:= 127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1] o= .a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:338= 27/v/ml/collection1/ shard1 [junit4] 2> 645540 INFO (coreZkRegister-2237-thread-1-processing-n:12= 7.0.0.1:33827_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node1) [n:= 127.0.0.1:33827_v%2Fml c:collection1 s:shard1 r:core_node1 x:collection1] o= .a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 645798 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCa= seJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lu= cene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.= cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/shard-= 2-001/cores/collection1 [junit4] 2> 645799 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= FullDistribZkTestBase create jetty 2 in directory /x1/jenkins/jenkins-slave= /workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/= J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20= E2-001/shard-2-001 [junit4] 2> 645799 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.Server j= etty-9.3.8.v20160314 [junit4] 2> 645802 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.h.Contex= tHandler Started o.e.j.s.ServletContextHandler@737ae4d1{/v/ml,null,AVAILABL= E} [junit4] 2> 645803 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.ServerCo= nnector Started ServerConnector@4d84347e{HTTP/1.1,[http/1.1]}{127.0.0.1:514= 80} [junit4] 2> 645804 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.e.j.s.Server S= tarted @650062ms [junit4] 2> 645804 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.s.e.Jett= ySolrRunner Jetty properties: {solr.data.dir=3D/x1/jenkins/jenkins-slave/wo= rkspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/= temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-= 001/tempDir-001/jetty2, solrconfig=3Dsolrconfig.xml, hostContext=3D/v/ml, h= ostPort=3D51480, coreRootDirectory=3D/x1/jenkins/jenkins-slave/workspace/Lu= cene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/../../../.= ./../../../../../../../x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Night= lyTests-6.x/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderIni= tiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/shard-2-001/cores} [junit4] 2> 645804 ERROR (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.StartupL= oggingUtils Missing Java Option solr.log.dir. Logging may be missing or inc= omplete. [junit4] 2> 645809 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter ___ _ Welcome to Apache Solr? version 6.4.0 [junit4] 2> 645809 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 645809 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 645809 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter |___/\___/_|_| Start time: 2016-11-22T20:28:15.658Z [junit4] 2> 645813 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.s.SolrDisp= atchFilter Loading solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 645813 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.SolrXmlC= onfig Loading container configuration from /x1/jenkins/jenkins-slave/worksp= ace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-core/test/J1/temp= /solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88260B81B20E2-001/= shard-2-001/solr.xml [junit4] 2> 645824 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.u.UpdateSh= ardHandler Creating UpdateShardHandler HTTP client with params: socketTimeo= ut=3D340000&connTimeout=3D45000&retry=3Dtrue [junit4] 2> 645828 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.ZkContai= ner Zookeeper client=3D127.0.0.1:45774/solr [junit4] 2> 645848 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) ->= (2) [junit4] 2> 645855 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes= /127.0.0.1:51480_v%2Fml [junit4] 2> 645856 INFO (zkCallback-685-thread-1-processing-n:127.0.0= .1:33827_v%2Fml) [n:127.0.0.1:33827_v%2Fml ] o.a.s.c.c.ZkStateReader Upd= ated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 645857 INFO (zkCallback-680-thread-1) [ ] o.a.s.c.c.Zk= StateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 645857 INFO (zkCallback-676-thread-1-processing-n:127.0.0= .1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.c.ZkStateReader Upd= ated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 645860 INFO (zkCallback-691-thread-1-processing-n:127.0.0= .1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml ] o.a.s.c.c.ZkStateReader Upd= ated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 645939 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /= x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/so= lr/build/solr-core/test/J1/../../../../../../../../../../../x1/jenkins/jenk= ins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-c= ore/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestartTest_85E88= 260B81B20E2-001/shard-2-001/cores [junit4] 2> 645939 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 645944 INFO (OverseerStateUpdate-96983219752402948-127.0.= 0.1:50633_v%2Fml-n_0000000000) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.o.Rep= licaMutator Assigning new node to shard shard=3Dshard1 [junit4] 2> 646958 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 x:collect= ion1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.4.0 [junit4] 2> 646975 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 x:collect= ion1] o.a.s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 647103 WARN (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 x:collect= ion1] o.a.s.s.IndexSchema [collection1] default search field in schema is t= ext. WARNING: Deprecated, please use 'df' on request instead. [junit4] 2> 647105 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 x:collect= ion1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 647122 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 x:collect= ion1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configura= tion from collection collection1 [junit4] 2> 647122 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new Sol= rCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/= checkout/solr/build/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecove= ryOnShardRestartTest_85E88260B81B20E2-001/shard-2-001/cores/collection1], d= ataDir=3D[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/= checkout/solr/build/solr-core/test/J1/../../../../../../../../../../../x1/j= enkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/b= uild/solr-core/test/J1/temp/solr.cloud.LeaderInitiatedRecoveryOnShardRestar= tTest_85E88260B81B20E2-001/shard-2-001/cores/collection1/data/] [junit4] 2> 647122 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled= . Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@= 2ad946c0 [junit4] 2> 647124 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapp= ing class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: ma= xMergeAtOnce=3D16, maxMergeAtOnceExplicit=3D43, maxMergedSegmentMB=3D5.7138= 671875, floorSegmentMB=3D0.2158203125, forceMergeDeletesPctAllowed=3D22.681= 022262712812, segmentsPerTier=3D27.0, maxCFSSegmentSizeMB=3D8.7960930222079= 99E12, noCFSRatio=3D0.8516399023712865 [junit4] 2> 647134 WARN (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.c.RequestHandlers INVALID paramSet a in req= uestHandler {type =3D requestHandler,name =3D /dump,class =3D DumpRequestHa= ndler,args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 647146 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementat= ion: org.apache.solr.update.UpdateLog [junit4] 2> 647146 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= =3D defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 n= umVersionBuckets=3D65536 [junit4] 2> 647147 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 647147 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 647148 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapp= ing class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePoli= cy: minMergeSize=3D0, mergeFactor=3D10, maxMergeSize=3D391712009, maxMergeS= izeForForcedMerge=3D9223372036854775807, calibrateSizeByDeletes=3Dtrue, max= MergeDocs=3D2147483647, maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRa= tio=3D0.1] [junit4] 2> 647150 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4857a= 514[collection1] main] [junit4] 2> 647152 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeep= erStorageIO with znodeBase: /configs/conf1 [junit4] 2> 647153 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null at pat= h _rest_managed.json using ZooKeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 647153 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserv= ed for 10000 [junit4] 2> 647154 INFO (searcherExecutor-2254-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [= n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1]= o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4857a514[c= ollection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 647154 INFO (coreLoadExecutor-2253-thread-1-processing-n:= 127.0.0.1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:= core_node2 x:collection1] o.a.s.u.UpdateLog Could not find max version in i= ndex or recent updates, using new clock 1551731520441417728 [junit4] 2> 647160 INFO (coreZkRegister-2248-thread-1-processing-n:12= 7.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n:= 127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] o= .a.s.c.ZkController Core needs to recover:collection1 [junit4] 2> 647160 INFO (updateExecutor-688-thread-1-processing-n:127= .0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n:1= 27.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] o.= a.s.u.DefaultSolrCoreState Running recovery [junit4] 2> 647160 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup= =3Dtrue [junit4] 2> 647160 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy ###### startupVersions=3D[[]] [junit4] 2> 647160 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy Begin buffering updates. core=3D[collection1] [junit4] 2> 647161 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=3DACTIVE, t= log=3Dnull} [junit4] 2> 647161 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recoveri= ng, leader is [http://127.0.0.1:33827/v/ml/collection1/] and I am [http://1= 27.0.0.1:51480/v/ml/collection1/] [junit4] 2> 647166 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1= :33827/v/ml]; [WaitForState: action=3DPREPRECOVERY&core=3Dcollection1&nodeN= ame=3D127.0.0.1:51480_v%252Fml&coreNodeName=3Dcore_node2&state=3Drecovering= &checkLive=3Dtrue&onlyIfLeader=3Dtrue&onlyIfLeaderActive=3Dtrue] [junit4] 2> 647176 INFO (qtp230087103-40620) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node2,= state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive= : true [junit4] 2> 647177 INFO (qtp230087103-40620) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see colle= ction1 (shard1 of collection1) have state: recovering [junit4] 2> 647177 INFO (qtp230087103-40620) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=3Dc= ollection1, shard=3Dshard1, thisCore=3Dcollection1, leaderDoesNotNeedRecove= ry=3Dfalse, isLeader? true, live=3Dtrue, checkLive=3Dtrue, currentState=3Dd= own, localState=3Dactive, nodeName=3D127.0.0.1:51480_v%2Fml, coreNodeName= =3Dcore_node2, onlyIfActiveCheckResult=3Dfalse, nodeProps: core_node2:{"cor= e":"collection1","base_url":"http://127.0.0.1:51480/v/ml","node_name":"127.= 0.0.1:51480_v%2Fml","state":"down"} [junit4] 2> 647445 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.SolrTestCa= seJ4 ###Starting testRestartWithAllInLIR [junit4] 2> 647445 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= DistribZkTestBase Wait for recoveries to finish - collection: collection1 f= ailOnTimeout:true timeout (sec):330 [junit4] 2> 648177 INFO (qtp230087103-40620) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=3Dc= ollection1, shard=3Dshard1, thisCore=3Dcollection1, leaderDoesNotNeedRecove= ry=3Dfalse, isLeader? true, live=3Dtrue, checkLive=3Dtrue, currentState=3Dr= ecovering, localState=3Dactive, nodeName=3D127.0.0.1:51480_v%2Fml, coreNode= Name=3Dcore_node2, onlyIfActiveCheckResult=3Dfalse, nodeProps: core_node2:{= "core":"collection1","base_url":"http://127.0.0.1:51480/v/ml","node_name":"= 127.0.0.1:51480_v%2Fml","state":"recovering"} [junit4] 2> 648177 INFO (qtp230087103-40620) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node2, state: rec= overing, checkLive: true, onlyIfLeader: true for: 1 seconds. [junit4] 2> 648177 INFO (qtp230087103-40620) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores param= s=3D{nodeName=3D127.0.0.1:51480_v%252Fml&onlyIfLeaderActive=3Dtrue&core=3Dc= ollection1&coreNodeName=3Dcore_node2&action=3DPREPRECOVERY&checkLive=3Dtrue= &state=3Drecovering&onlyIfLeader=3Dtrue&wt=3Djavabin&version=3D2} status=3D= 0 QTime=3D1001 [junit4] 2> 655178 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:3382= 7/v/ml/collection1/] - recoveringAfterStartup=3D[true] [junit4] 2> 655178 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.u.PeerSync PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:51480/= v/ml START replicas=3D[http://127.0.0.1:33827/v/ml/collection1/] nUpdates= =3D100 [junit4] 2> 655182 INFO (qtp230087103-40617) [n:127.0.0.1:33827_v%2Fm= l c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.u.IndexFingerpri= nt IndexFingerprint millis:0.0 result:{maxVersionSpecified=3D92233720368547= 75807, maxVersionEncountered=3D0, maxInHash=3D0, versionsHash=3D0, numVersi= ons=3D0, numDocs=3D0, maxDoc=3D0} [junit4] 2> 655182 INFO (qtp230087103-40617) [n:127.0.0.1:33827_v%2Fm= l c:collection1 s:shard1 r:core_node1 x:collection1] o.a.s.c.S.Request [col= lection1] webapp=3D/v/ml path=3D/get params=3D{distrib=3Dfalse&qt=3D/get&g= etFingerprint=3D9223372036854775807&wt=3Djavabin&version=3D2} status=3D0 QT= ime=3D0 [junit4] 2> 655184 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpec= ified=3D9223372036854775807, maxVersionEncountered=3D0, maxInHash=3D0, vers= ionsHash=3D0, numVersions=3D0, numDocs=3D0, maxDoc=3D0} [junit4] 2> 655184 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync=20 [junit4] 2> 655184 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.u.DirectUpdateHandler2 start commit{,optimize=3Dfalse,openSearcher=3D= true,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareC= ommit=3Dfalse} [junit4] 2> 655184 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 655185 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 655185 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful. [junit4] 2> 655185 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync. [junit4] 2> 655185 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy No replay needed. [junit4] 2> 655185 INFO (recoveryExecutor-689-thread-1-processing-n:1= 27.0.0.1:51480_v%2Fml x:collection1 s:shard1 c:collection1 r:core_node2) [n= :127.0.0.1:51480_v%2Fml c:collection1 s:shard1 r:core_node2 x:collection1] = o.a.s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 655446 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= DistribZkTestBase Recoveries finished - collection: collection1 [junit4] 2> 655448 INFO (qtp230087103-40621) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with = params name=3Dcollection1&action=3DDELETE&wt=3Djavabin&version=3D2 and send= ToOCPQueue=3Dtrue [junit4] 2> 655460 INFO (OverseerThreadFactory-2229-thread-1-processi= ng-n:127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.Oversee= rCollectionMessageHandler Executing Collection Cmd : action=3DUNLOAD&delete= InstanceDir=3Dtrue&deleteDataDir=3Dtrue [junit4] 2> 655475 INFO (qtp230087103-40624) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.cor= e.SolrCore@55276a1c [junit4] 2> 655477 INFO (qtp2024111253-40648) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.co= re.SolrCore@54efbc1c [junit4] 2> 655502 WARN (zkCallback-691-thread-1-processing-n:127.0.0= .1:51480_v%2Fml) [n:127.0.0.1:51480_v%2Fml ] o.a.s.c.LeaderElector=20 [junit4] 2> org.apache.solr.common.SolrException: SolrCore not found:c= ollection1 in [] [junit4] 2> =09at org.apache.solr.cloud.ShardLeaderElectionContext.run= LeaderProcess(ElectionContext.java:296) [junit4] 2> =09at org.apache.solr.cloud.LeaderElector.runIamLeaderProc= ess(LeaderElector.java:170) [junit4] 2> =09at org.apache.solr.cloud.LeaderElector.checkIfIamLeader= (LeaderElector.java:135) [junit4] 2> =09at org.apache.solr.cloud.LeaderElector.access$200(Leade= rElector.java:56) [junit4] 2> =09at org.apache.solr.cloud.LeaderElector$ElectionWatcher.= process(LeaderElector.java:348) [junit4] 2> =09at org.apache.solr.common.cloud.SolrZkClient$3.lambda$p= rocess$0(SolrZkClient.java:268) [junit4] 2> =09at java.util.concurrent.Executors$RunnableAdapter.call(= Executors.java:511) [junit4] 2> =09at java.util.concurrent.FutureTask.run(FutureTask.java:= 266) [junit4] 2> =09at org.apache.solr.common.util.ExecutorUtil$MDCAwareThr= eadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) [junit4] 2> =09at java.util.concurrent.ThreadPoolExecutor.runWorker(Th= readPoolExecutor.java:1142) [junit4] 2> =09at java.util.concurrent.ThreadPoolExecutor$Worker.run(T= hreadPoolExecutor.java:617) [junit4] 2> =09at java.lang.Thread.run(Thread.java:745) [junit4] 2> 655506 INFO (qtp230087103-40624) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores param= s=3D{deleteInstanceDir=3Dtrue&core=3Dcollection1&qt=3D/admin/cores&deleteDa= taDir=3Dtrue&action=3DUNLOAD&wt=3Djavabin&version=3D2} status=3D0 QTime=3D3= 4 [junit4] 2> 655518 INFO (qtp2024111253-40648) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemer= al leader parent node, won't remove previous leader registration. [junit4] 2> 655521 INFO (qtp2024111253-40648) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores para= ms=3D{deleteInstanceDir=3Dtrue&core=3Dcollection1&qt=3D/admin/cores&deleteD= ataDir=3Dtrue&action=3DUNLOAD&wt=3Djavabin&version=3D2} status=3D0 QTime=3D= 44 [junit4] 2> 656227 INFO (qtp230087103-40621) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections= params=3D{name=3Dcollection1&action=3DDELETE&wt=3Djavabin&version=3D2} sta= tus=3D0 QTime=3D778 [junit4] 2> 656228 INFO (TEST-LeaderInitiatedRecoveryOnShardRestartTe= st.testRestartWithAllInLIR-seed#[85E88260B81B20E2]) [ ] o.a.s.c.Abstract= FullDistribZkTestBase Creating collection with stateFormat=3D1: all_in_lir [junit4] 2> 656231 INFO (qtp2024111253-40645) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with= params replicationFactor=3D3&maxShardsPerNode=3D1&name=3Dall_in_lir&action= =3DCREATE&numShards=3D1&stateFormat=3D1&wt=3Djavabin&version=3D2 and sendTo= OCPQueue=3Dtrue [junit4] 2> 656234 INFO (OverseerThreadFactory-2229-thread-2-processi= ng-n:127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.CreateC= ollectionCmd Create collection all_in_lir [junit4] 2> 656234 INFO (OverseerCollectionConfigSetProcessor-9698321= 9752402948-127.0.0.1:50633_v%2Fml-n_0000000000) [n:127.0.0.1:50633_v%2Fml = ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-= work/qnr-0000000000 doesn't exist. Requestor may have disconnected from Zo= oKeeper [junit4] 2> 656235 INFO (OverseerThreadFactory-2229-thread-2-processi= ng-n:127.0.0.1:50633_v%2Fml) [n:127.0.0.1:50633_v%2Fml ] o.a.s.c.CreateC= ollectionCmd Only one config set found in zk - using it:conf1 [junit4] 2> 656456 INFO (qtp230087103-40618) [n:127.0.0.1:33827_v%2Fm= l ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&c= ollection.configName=3Dconf1&newCollection=3Dtrue&name=3Dall_in_lir_shard1_= replica3&action=3DCREATE&numShards=3D1&collection=3Dall_in_lir&shard=3Dshar= d1&wt=3Djavabin&version=3D2 [junit4] 2> 656456 INFO (qtp2024111253-40649) [n:127.0.0.1:51480_v%2F= ml ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&= collection.configName=3Dconf1&newCollection=3Dtrue&name=3Dall_in_lir_shard1= _replica2&action=3DCREATE&numShards=3D1&collection=3Dall_in_lir&shard=3Dsha= rd1&wt=3Djavabin&version=3D2 [junit4] 2> 656458 INFO (qtp698715723-40583) [n:127.0.0.1:50633_v%2Fm= l ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&c= ollection.configName=3Dconf1&newCollection=3Dtrue&name=3Dall_in_lir_shard1_= replica1&action=3DCREATE&numShards=3D1&collection=3Dall_in_lir&shard=3Dshar= d1&wt=3Djavabin&version=3D2 [junit4] 2> 657506 INFO (qtp698715723-40583) [n:127.0.0.1:50633_v%2Fm= l c:all_in_lir s:shard1 x:all_in_lir_shard1_replica1] o.a.s.c.SolrConfig U= sing Lucene MatchVersion: 6.4.0 [junit4] 2> 657506 INFO (qtp230087103-40618) [n:127.0.0.1:33827_v%2Fm= l c:all_in_lir s:shard1 x:all_in_lir_shard1_replica3] o.a.s.c.SolrConfig U= sing Lucene MatchVersion: 6.4.0 [junit4] 2> 657516 INFO (qtp2024111253-40649) [n:127.0.0.1:51480_v%2F= ml c:all_in_lir s:shard1 x:all_in_lir_shard1_replica2] o.a.s.c.SolrConfig = Using Lucene MatchVersion: 6.4.0 [junit4] 2> 657520 INFO (qtp230087103-40618) [n:127.0.0.1:33827_v%2Fm= l c:all_in_lir s:shard1 x:all_in_lir_shard1_replica3] o.a.s.s.IndexSchema = [all_in_lir_shard1_replica3] Schema name=3Dtest [junit4] 2> 657536 INFO (qtp698715723-40583) [n:127.0.0.1:50633_v%2Fm= l c:all_in_lir s:shard1 x:all_in_lir_shard1_replica1] o.a.s.s.IndexSchema = [all_in_lir_shard1_replica1] Schema name=3Dtest [junit4] 2> 657540 INFO (qtp2024111253-40649) [n:127.0.0.1:51480_v%2F= ml c:all_in_lir s:shard1 x:all_in_lir_shard1_replica2] o.a.s.s.IndexSchema= [all_in_lir_shard1_replica2] Schema name=3Dtest [junit4] 2> 657672 WARN (qtp230087103-40618) [n:127.0.0.1:33827_v%2Fm= l c:all_in_lir s:shard1 x:all_in_lir_shard1_replica3] o.a.s.s.IndexSchema = [all_in_lir_shard1_replica3] default search field in schema is text. WARNIN= G: Deprecated, please use 'df' on request instead. [junit4] 2> 657674 INFO (qtp230087103-40618) [n:127.0.0.1:33827_v%2Fm= l c:all_in_lir s:shard1 x:all_in_lir_shard1_replica3] o.a.s.s.IndexSchema = Loaded schema test/1.0 with uniqueid field id [junit4] 2> 657704 WARN (qtp2024111253-40649) [n:127.0.0.1:51480_v%2F= ml c:all_in_lir s:shard1 x:all_in_lir_shard1_replica2] o.a.s.s.IndexSchema= [all_in_lir_shard1_replica2] default search field in schema is text. WARNI= NG: Deprecated, please use 'df' on request instead. [junit4] 2> 657706 INFO (qtp230087103-40618) [n:127.0.0.1:33827_v%2Fm= l c:all_in_lir s:shard1 x:all_in_lir_shard1_replica3] o.a.s.c.CoreContaine= r Creating SolrCore 'all_in_lir_shard1_replica3' using configuration from c= ollection all_in_lir [junit4] 2> 657708 INFO (qtp230087103-40618) [n: [...truncated too long message...] lder$1.getMetrics(MetricsSourceBuilder.java:79) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter= .getMetrics(MetricsSourceAdapter.java:194) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter= .updateJmxCache(MetricsSourceAdapter.java:172) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter= .getMBeanInfo(MetricsSourceAdapter.java:151) [junit4] 2> =09at com.sun.jmx.interceptor.DefaultMBeanServerIntercepto= r.getClassName(DefaultMBeanServerInterceptor.java:1804) [junit4] 2> =09at com.sun.jmx.interceptor.DefaultMBeanServerIntercepto= r.safeGetClassName(DefaultMBeanServerInterceptor.java:1595) [junit4] 2> =09at com.sun.jmx.interceptor.DefaultMBeanServerIntercepto= r.checkMBeanPermission(DefaultMBeanServerInterceptor.java:1813) [junit4] 2> =09at com.sun.jmx.interceptor.DefaultMBeanServerIntercepto= r.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:430) [junit4] 2> =09at com.sun.jmx.interceptor.DefaultMBeanServerIntercepto= r.unregisterMBean(DefaultMBeanServerInterceptor.java:415) [junit4] 2> =09at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBe= an(JmxMBeanServer.java:546) [junit4] 2> =09at org.apache.hadoop.metrics2.util.MBeans.unregister(MB= eans.java:81) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter= .stopMBeans(MetricsSourceAdapter.java:226) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSourceAdapter= .stop(MetricsSourceAdapter.java:211) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.st= opSources(MetricsSystemImpl.java:463) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.st= op(MetricsSystemImpl.java:213) [junit4] 2> =09at org.apache.hadoop.metrics2.impl.MetricsSystemImpl.sh= utdown(MetricsSystemImpl.java:594) [junit4] 2> =09at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.= shutdownInstance(DefaultMetricsSystem.java:72) [junit4] 2> =09at org.apache.hadoop.metrics2.lib.DefaultMetricsSystem.= shutdown(DefaultMetricsSystem.java:68) [junit4] 2> =09at org.apache.hadoop.hdfs.server.namenode.metrics.NameN= odeMetrics.shutdown(NameNodeMetrics.java:171) [junit4] 2> =09at org.apache.hadoop.hdfs.server.namenode.NameNode.stop= (NameNode.java:872) [junit4] 2> =09at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniD= FSCluster.java:1726) [junit4] 2> =09at org.apache.hadoop.hdfs.MiniDFSCluster.shutdown(MiniD= FSCluster.java:1705) [junit4] 2> =09at org.apache.solr.cloud.hdfs.HdfsTestUtil.teardownClas= s(HdfsTestUtil.java:198) [junit4] 2> =09at org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistrib= utedZkTest.teardownClass(HdfsCollectionsAPIDistributedZkTest.java:52) [junit4] 2> =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native = Method) [junit4] 2> =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMe= thodAccessorImpl.java:62) [junit4] 2> =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(Dele= gatingMethodAccessorImpl.java:43) [junit4] 2> =09at java.lang.reflect.Method.invoke(Method.java:498) [junit4] 2> =09at com.carrotsearch.randomizedtesting.RandomizedRunner.= invoke(RandomizedRunner.java:1713) [junit4] 2> =09at com.carrotsearch.randomizedtesting.RandomizedRunner$= 7.evaluate(RandomizedRunner.java:870) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.StatementAd= apter.evaluate(StatementAdapter.java:36) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.SystemPrope= rtiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) [junit4] 2> =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.eva= luate(AbstractBeforeAfterRule.java:45) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.StatementAd= apter.evaluate(StatementAdapter.java:36) [junit4] 2> =09at org.apache.lucene.util.TestRuleStoreClassName$1.eval= uate(TestRuleStoreClassName.java:41) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.NoShadowing= OrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.jav= a:40) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.NoShadowing= OrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.jav= a:40) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.StatementAd= apter.evaluate(StatementAdapter.java:36) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.StatementAd= apter.evaluate(StatementAdapter.java:36) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.StatementAd= apter.evaluate(StatementAdapter.java:36) [junit4] 2> =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.= evaluate(TestRuleAssertionsRequired.java:53) [junit4] 2> =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluat= e(TestRuleMarkFailure.java:47) [junit4] 2> =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailure= s$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) [junit4] 2> =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.ev= aluate(TestRuleIgnoreTestSuites.java:54) [junit4] 2> =09at com.carrotsearch.randomizedtesting.rules.StatementAd= apter.evaluate(StatementAdapter.java:36) [junit4] 2> =09at com.carrotsearch.randomizedtesting.ThreadLeakControl= $StatementRunner.run(ThreadLeakControl.java:367) [junit4] 2> =09at java.lang.Thread.run(Thread.java:745) [junit4] 2> Caused by: java.lang.NullPointerException [junit4] 2> =09at org.apache.hadoop.hdfs.server.blockmanagement.Blocks= Map.size(BlocksMap.java:203) [junit4] 2> =09at org.apache.hadoop.hdfs.server.blockmanagement.BlockM= anager.getTotalBlocks(BlockManager.java:3370) [junit4] 2> =09at org.apache.hadoop.hdfs.server.namenode.FSNamesystem.= getBlocksTotal(FSNamesystem.java:5729) [junit4] 2> =09... 54 more [junit4] 2> 4361307 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-s= eed#[85E88260B81B20E2]-worker) [ ] o.a.s.c.ZkTestServer connecting to 12= 7.0.0.1:60489 60489 [junit4] 2> 4361307 INFO (SUITE-HdfsCollectionsAPIDistributedZkTest-s= eed#[85E88260B81B20E2]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenk= ins-slave/workspace/Lucene-Solr-NightlyTests-6.x/checkout/solr/build/solr-c= ore/test/J2/temp/solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest_85E882= 60B81B20E2-001 [junit4] 2> Nov 22, 2016 9:30:11 PM com.carrotsearch.randomizedtesting= .ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 35 leaked thr= ead(s). [junit4] 2> NOTE: test params are: codec=3DAsserting(Lucene62): {}, do= cValues:{}, maxPointsInLeafNode=3D85, maxMBSortInHeap=3D6.727346258230085, = sim=3DRandomSimilarity(queryNorm=3Dtrue,coord=3Dno): {}, locale=3Dsl, timez= one=3DAsia/Nicosia [junit4] 2> NOTE: Linux 3.13.0-85-generic amd64/Oracle Corporation 1.8= .0_102 (64-bit)/cpus=3D4,threads=3D2,free=3D100838248,total=3D520093696 [junit4] 2> NOTE: All tests run in this JVM: [RollingRestartTest, Coll= ectionStateFormat2Test, QueryParsingTest, TestSlowCompositeReaderWrapper, R= esponseLogComponentTest, TestMergePolicyConfig, InfoHandlerTest, CircularLi= stTest, TestReload, TestStressReorder, PKIAuthenticationIntegrationTest, Hd= fsNNFailoverTest, CollectionsAPISolrJTest, HdfsChaosMonkeyNothingIsSafeTest= , ExitableDirectoryReaderTest, TestSolrDynamicMBean, TestPhraseSuggestions,= TestIntervalFaceting, BadComponentTest, TestOrdValues, BooleanFieldTest, O= verseerRolesTest, TestSubQueryTransformer, HLLUtilTest, TestReloadAndDelete= Docs, CurrencyFieldXmlFileTest, HdfsTlogReplayBufferedWhileIndexingTest, Te= stLeaderElectionWithEmptyReplica, TestDFRSimilarityFactory, DeleteInactiveR= eplicaTest, DataDrivenBlockJoinTest, TestDistributedMissingSort, ShardSplit= Test, OverriddenZkACLAndCredentialsProvidersTest, AutoCommitTest, Analytics= MergeStrategyTest, TestSolrCoreSnapshots, TestRandomCollapseQParserPlugin, = TestJsonRequest, TestInfoStreamLogging, TestDocTermOrds, OverseerTest, Test= BackupRepositoryFactory, BufferStoreTest, ZkStateWriterTest, StressHdfsTest= , TestSolrCloudWithDelegationTokens, ExplicitHLLTest, ReplaceNodeTest, Resp= onseHeaderTest, TestNoOpRegenerator, TestExactStatsCache, TestRecovery, DOM= UtilTest, TestLMJelinekMercerSimilarityFactory, CdcrBootstrapTest, TestSolr= FieldCacheMBean, TestSchemaManager, StatsComponentTest, SolrTestCaseJ4Test,= DistributedQueueTest, TestDefaultSearchFieldResource, TestWriterPerf, Test= SSLRandomization, TestInitQParser, TestManagedSchema, TestAddFieldRealTimeG= et, FieldMutatingUpdateProcessorTest, TestPerFieldSimilarityClassic, TestEx= tendedDismaxParser, TestIndexSearcher, TestCloudInspectUtil, SpatialHeatmap= FacetsTest, RulesTest, VMParamsZkACLAndCredentialsProvidersTest, NoCacheHea= derTest, TestUtils, UpdateParamsTest, MinimalSchemaTest, SimpleCollectionCr= eateDeleteTest, CleanupOldIndexTest, LeaderFailureAfterFreshStartTest, Test= BlendedInfixSuggestions, DirectUpdateHandlerTest, TestTrieFacet, TestRecove= ryHdfs, TestSolrCLIRunExample, TestRandomFlRTGCloud, GraphQueryTest, TestJs= onFacetRefinement, ParsingFieldUpdateProcessorsTest, DistribCursorPagingTes= t, TestDefaultStatsCache, SuggesterTSTTest, TestDownShardTolerantSearch, Cl= oneFieldUpdateProcessorFactoryTest, TestClassicSimilarityFactory, TestGroup= ingSearch, ConnectionManagerTest, PrimUtilsTest, TestBinaryField, TestManag= edStopFilterFactory, TestCryptoKeys, PingRequestHandlerTest, TestConfigSets= API, TermVectorComponentDistributedTest, CdcrVersionReplicationTest, Delete= LastCustomShardedReplicaTest, DeleteNodeTest, DeleteReplicaTest, ForceLeade= rTest, LeaderInitiatedRecoveryOnCommitTest, MigrateRouteKeyTest, RecoveryAf= terSoftCommitTest, RestartWhileUpdatingTest, TestClusterProperties, TestCon= figSetsAPIExclusivity, TestConfigSetsAPIZkFailure, TestExclusionRuleCollect= ionAccess, TestLeaderInitiatedRecoveryThread, TestMiniSolrCloudCluster, Tes= tReplicaProperties, TestSolrCloudWithKerberosAlt, TestStressCloudBlindAtomi= cUpdates, HdfsBasicDistributedZk2Test, HdfsCollectionsAPIDistributedZkTest] [junit4] Completed [516/655 (3!)] on J2 in 171.06s, 20 tests, 1 failure,= 1 error <<< FAILURES! [...truncated 61157 lines...] ------=_Part_1877_591871967.1479852784227 Content-Type: text/plain; charset=us-ascii --------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org For additional commands, e-mail: dev-help@lucene.apache.org ------=_Part_1877_591871967.1479852784227--