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 9285F200D1F for ; Fri, 29 Sep 2017 03:49:33 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 86CD41609EC; Fri, 29 Sep 2017 01:49:33 +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 466021609CD for ; Fri, 29 Sep 2017 03:49:23 +0200 (CEST) Received: (qmail 85737 invoked by uid 500); 29 Sep 2017 01:49:22 -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 85722 invoked by uid 99); 29 Sep 2017 01:49:21 -0000 Received: from Unknown (HELO jenkins-master.apache.org) (62.210.60.235) by apache.org (qpsmtpd/0.29) with ESMTP; Fri, 29 Sep 2017 01:49:21 +0000 Received: from jenkins-master.apache.org (localhost [127.0.0.1]) by jenkins-master.apache.org (ASF Mail Server at jenkins-master.apache.org) with ESMTP id 38FDDA00BC for ; Fri, 29 Sep 2017 01:49:16 +0000 (UTC) Date: Fri, 29 Sep 2017 01:46:22 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <129172921.800.1506649757237.JavaMail.jenkins@jenkins-master.apache.org> In-Reply-To: <87759259.266.1506568252526.JavaMail.jenkins@jenkins-master.apache.org> References: <87759259.266.1506568252526.JavaMail.jenkins@jenkins-master.apache.org> Subject: [JENKINS] Lucene-Solr-Tests-7.x - Build # 170 - Still Unstable MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_799_114496361.1506649753773" X-Jenkins-Job: Lucene-Solr-Tests-7.x X-Jenkins-Result: UNSTABLE archived-at: Fri, 29 Sep 2017 01:49:33 -0000 ------=_Part_799_114496361.1506649753773 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/170/ 5 tests failed. FAILED: org.apache.solr.cloud.AssignBackwardCompatibilityTest.test Error Message: Could not load collection from ZK: collection1 Stack Trace: org.apache.solr.common.SolrException: Could not load collection from ZK: co= llection1 =09at __randomizedtesting.SeedInfo.seed([8EFA0E21BA50E84B:6AE31FB14AC85B3]:= 0) =09at org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateR= eader.java:1115) =09at org.apache.solr.common.cloud.ZkStateReader$LazyCollectionRef.get(ZkSt= ateReader.java:648) =09at org.apache.solr.common.cloud.ClusterState.getCollectionOrNull(Cluster= State.java:128) =09at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.= java:108) =09at org.apache.solr.cloud.SolrCloudTestCase.getCollectionState(SolrCloudT= estCase.java:247) =09at org.apache.solr.cloud.AssignBackwardCompatibilityTest.test(AssignBack= wardCompatibilityTest.java:90) =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:1737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:934) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:970) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:984) =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:368) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:817) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:468) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:829) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:879) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:890) =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:368) =09at java.lang.Thread.run(Thread.java:748) Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: Ke= eperErrorCode =3D Session expired for /collections/collection1/state.json =09at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) =09at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) =09at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1212) =09at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java= :357) =09at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java= :354) =09at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecut= or.java:60) =09at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:3= 54) =09at org.apache.solr.common.cloud.ZkStateReader.fetchCollectionState(ZkSta= teReader.java:1127) =09at org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateR= eader.java:1113) =09... 44 more FAILED: org.apache.solr.cloud.RecoveryZkTest.test Error Message: Stack Trace: java.util.concurrent.TimeoutException =09at __randomizedtesting.SeedInfo.seed([8EFA0E21BA50E84B:6AE31FB14AC85B3]:= 0) =09at org.apache.solr.common.cloud.ZkStateReader.waitForState(ZkStateReader= .java:1268) =09at org.apache.solr.client.solrj.impl.CloudSolrClient.waitForState(CloudS= olrClient.java:438) =09at org.apache.solr.cloud.RecoveryZkTest.test(RecoveryZkTest.java:122) =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:1737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:934) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:970) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:984) =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:368) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:817) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:468) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:829) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:879) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:890) =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:368) =09at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.ShardSplitTest.testSplitStaticIndexReplicati= on Error Message: Could not load collection from ZK: control_collection Stack Trace: org.apache.solr.common.SolrException: Could not load collection from ZK: co= ntrol_collection =09at __randomizedtesting.SeedInfo.seed([8EFA0E21BA50E84B:C4B09A212BF8C74E]= :0) =09at org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateR= eader.java:1115) =09at org.apache.solr.common.cloud.ZkStateReader$LazyCollectionRef.get(ZkSt= ateReader.java:648) =09at org.apache.solr.common.cloud.ClusterState.getCollectionOrNull(Cluster= State.java:128) =09at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.= java:108) =09at org.apache.solr.cloud.ShardSplitTest.testSplitStaticIndexReplication(= ShardSplitTest.java:189) =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:1737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:934) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:970) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:984) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= FixedStatement.callStatement(BaseDistributedSearchTestCase.java:993) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= Statement.evaluate(BaseDistributedSearchTestCase.java:968) =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:368) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:817) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:468) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:829) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:879) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:890) =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:368) =09at java.lang.Thread.run(Thread.java:748) Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: Ke= eperErrorCode =3D Session expired for /collections/control_collection/state= .json =09at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) =09at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) =09at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1212) =09at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java= :357) =09at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java= :354) =09at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecut= or.java:60) =09at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:3= 54) =09at org.apache.solr.common.cloud.ZkStateReader.fetchCollectionState(ZkSta= teReader.java:1127) =09at org.apache.solr.common.cloud.ZkStateReader.getCollectionLive(ZkStateR= eader.java:1113) =09... 45 more FAILED: org.apache.solr.cloud.TestTlogReplica.testOnlyLeaderIndexes Error Message: expected:<2> but was:<5> Stack Trace: java.lang.AssertionError: expected:<2> but was:<5> =09at __randomizedtesting.SeedInfo.seed([8EFA0E21BA50E84B:92FB73ACCFF596D8]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.junit.Assert.failNotEquals(Assert.java:647) =09at org.junit.Assert.assertEquals(Assert.java:128) =09at org.junit.Assert.assertEquals(Assert.java:472) =09at org.junit.Assert.assertEquals(Assert.java:456) =09at org.apache.solr.cloud.TestTlogReplica.assertCopyOverOldUpdates(TestTl= ogReplica.java:909) =09at org.apache.solr.cloud.TestTlogReplica.testOnlyLeaderIndexes(TestTlogR= eplica.java:501) =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:1737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:934) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:970) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:984) =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:368) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:817) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:468) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:829) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:879) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:890) =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:368) =09at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfi= gReplication Error Message: Index: 0, Size: 0 Stack Trace: java.lang.IndexOutOfBoundsException: Index: 0, Size: 0 =09at __randomizedtesting.SeedInfo.seed([8EFA0E21BA50E84B:9AB2557499575555]= :0) =09at java.util.ArrayList.rangeCheck(ArrayList.java:653) =09at java.util.ArrayList.get(ArrayList.java:429) =09at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigRe= plication(TestReplicationHandler.java:561) =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:1737) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:934) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:970) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:984) =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:368) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:817) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:468) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:829) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:879) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:890) =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:368) =09at java.lang.Thread.run(Thread.java:748) Build Log: [...truncated 11622 lines...] [junit4] Suite: org.apache.solr.cloud.TestTlogReplica [junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lu= cene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogRe= plica_8EFA0E21BA50E84B-001/init-core-data-001 [junit4] 2> 409488 WARN (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3D2 = numCloses=3D2 [junit4] 2> 409489 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSP= ROP=3Dfalse) w/NUMERIC_DOCVALUES_SYSPROP=3Dfalse [junit4] 2> 409504 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth= (false) via: @org.apache.solr.util.RandomizeSSL(reason=3D, ssl=3DNaN, valu= e=3DNaN, clientAuth=3DNaN) [junit4] 2> 409504 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr= .allowed.securerandom=3Dnull & java.security.egd=3Dfile:/dev/./urandom [junit4] 2> 409504 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers= in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/= solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8EFA0E21BA50E84B-001/temp= Dir-001 [junit4] 2> 409504 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 409520 INFO (Thread-231) [ ] o.a.s.c.ZkTestServer clie= nt port:0.0.0.0/0.0.0.0:0 [junit4] 2> 409520 INFO (Thread-231) [ ] o.a.s.c.ZkTestServer Star= ting server [junit4] 2> 409593 ERROR (Thread-231) [ ] o.a.z.s.ZooKeeperServer Z= KShutdownHandler is not registered, so ZooKeeper server won't take any acti= on on ERROR or SHUTDOWN server state changes [junit4] 2> 409650 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:41222 [junit4] 2> 409813 INFO (jetty-launcher-135-thread-1) [ ] o.e.j.s.= Server jetty-9.3.20.v20170531 [junit4] 2> 409819 INFO (jetty-launcher-135-thread-2) [ ] o.e.j.s.= Server jetty-9.3.20.v20170531 [junit4] 2> 409951 INFO (jetty-launcher-135-thread-1) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@1698f2a1{/solr,null,= AVAILABLE} [junit4] 2> 409964 INFO (jetty-launcher-135-thread-2) [ ] o.e.j.s.= h.ContextHandler Started o.e.j.s.ServletContextHandler@4f34249a{/solr,null,= AVAILABLE} [junit4] 2> 409965 INFO (jetty-launcher-135-thread-2) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@71d584d4{HTTP/1.1,[http/1.1]}{127= .0.0.1:44920} [junit4] 2> 409965 INFO (jetty-launcher-135-thread-2) [ ] o.e.j.s.= Server Started @426787ms [junit4] 2> 409965 INFO (jetty-launcher-135-thread-2) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D4492= 0} [junit4] 2> 409965 ERROR (jetty-launcher-135-thread-2) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 409965 INFO (jetty-launcher-135-thread-2) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.1.0 [junit4] 2> 409965 INFO (jetty-launcher-135-thread-2) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 409965 INFO (jetty-launcher-135-thread-2) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir:= null [junit4] 2> 409965 INFO (jetty-launcher-135-thread-2) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-28T22:36:26.142Z [junit4] 2> 410012 INFO (jetty-launcher-135-thread-1) [ ] o.e.j.s.= AbstractConnector Started ServerConnector@2c512d27{HTTP/1.1,[http/1.1]}{127= .0.0.1:38423} [junit4] 2> 410012 INFO (jetty-launcher-135-thread-1) [ ] o.e.j.s.= Server Started @426834ms [junit4] 2> 410012 INFO (jetty-launcher-135-thread-1) [ ] o.a.s.c.= s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D3842= 3} [junit4] 2> 410118 ERROR (jetty-launcher-135-thread-1) [ ] o.a.s.u.= StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missin= g or incomplete. [junit4] 2> 410118 INFO (jetty-launcher-135-thread-1) [ ] o.a.s.s.= SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.1.0 [junit4] 2> 410118 INFO (jetty-launcher-135-thread-1) [ ] o.a.s.s.= SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 410118 INFO (jetty-launcher-135-thread-1) [ ] o.a.s.s.= SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir:= null [junit4] 2> 410118 INFO (jetty-launcher-135-thread-1) [ ] o.a.s.s.= SolrDispatchFilter |___/\___/_|_| Start time: 2017-09-28T22:36:26.295Z [junit4] 2> 410220 INFO (jetty-launcher-135-thread-2) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 410272 INFO (jetty-launcher-135-thread-1) [ ] o.a.s.s.= SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 410362 INFO (jetty-launcher-135-thread-2) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:41222/solr [junit4] 2> 410402 INFO (jetty-launcher-135-thread-1) [ ] o.a.s.c.= ZkContainer Zookeeper client=3D127.0.0.1:41222/solr [junit4] 2> 410921 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 410921 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 1= 27.0.0.1:38423_solr [junit4] 2> 410934 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.c.Overseer Overseer (id=3D98739040137904134-127.0.0.1:3= 8423_solr-n_0000000000) starting [junit4] 2> 411052 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:38423_solr [junit4] 2> 411117 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 411951 INFO (jetty-launcher-135-thread-2) [n:127.0.0.1:44= 920_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... = (0) -> (1) [junit4] 2> 411952 INFO (jetty-launcher-135-thread-2) [n:127.0.0.1:44= 920_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 412003 INFO (jetty-launcher-135-thread-2) [n:127.0.0.1:44= 920_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live= _nodes/127.0.0.1:44920_solr [junit4] 2> 412040 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 412040 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader Updated= live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 412350 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38423.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@300dea7f [junit4] 2> 412367 INFO (jetty-launcher-135-thread-2) [n:127.0.0.1:44= 920_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44920.solr= .node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@300dea7f [junit4] 2> 412484 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38423.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@300dea7f [junit4] 2> 412484 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38423.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@300dea7f [junit4] 2> 412485 INFO (jetty-launcher-135-thread-1) [n:127.0.0.1:38= 423_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build= /solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8EFA0E21BA50E84B-001/tem= pDir-001/node1/. [junit4] 2> 412667 INFO (jetty-launcher-135-thread-2) [n:127.0.0.1:44= 920_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44920.solr= .jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxM= BeanServer@300dea7f [junit4] 2> 412667 INFO (jetty-launcher-135-thread-2) [n:127.0.0.1:44= 920_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44920.solr= .jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@300dea7f [junit4] 2> 412668 INFO (jetty-launcher-135-thread-2) [n:127.0.0.1:44= 920_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions undern= eath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build= /solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8EFA0E21BA50E84B-001/tem= pDir-001/node2/. [junit4] 2> 413378 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (2) [junit4] 2> 413450 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.= 0.1:41222/solr ready [junit4] 2> 413670 INFO (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker) [ ] o.a.s.c.TestTlogReplica Using legacyCloud?: false [junit4] 2> 413728 INFO (qtp1238270335-922) [n:127.0.0.1:38423_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterprop wit= h params val=3Dfalse&name=3DlegacyCloud&action=3DCLUSTERPROP&wt=3Djavabin&v= ersion=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 413763 INFO (qtp1238270335-922) [n:127.0.0.1:38423_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections pa= rams=3D{val=3Dfalse&name=3DlegacyCloud&action=3DCLUSTERPROP&wt=3Djavabin&ve= rsion=3D2} status=3D0 QTime=3D35 [junit4] 2> 413840 INFO (TEST-TestTlogReplica.testAddDocs-seed#[8EFA0= E21BA50E84B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testAddDocs [junit4] 2> 413854 INFO (qtp1238270335-923) [n:127.0.0.1:38423_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with par= ams pullReplicas=3D0&replicationFactor=3D0&collection.configName=3Dconf&max= ShardsPerNode=3D100&name=3Dtlog_replica_test_add_docs&nrtReplicas=3D0&actio= n=3DCREATE&numShards=3D1&tlogReplicas=3D2&wt=3Djavabin&version=3D2 and send= ToOCPQueue=3Dtrue [junit4] 2> 413982 INFO (OverseerThreadFactory-469-thread-1-processin= g-n:127.0.0.1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.CreateCollec= tionCmd Create collection tlog_replica_test_add_docs [junit4] 2> 414657 INFO (OverseerStateUpdate-98739040137904134-127.0.= 0.1:38423_solr-n_0000000000) [n:127.0.0.1:38423_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"tlog_replica_test_add_docs", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"tlog_replica_test_add_docs_shard1_replica_t1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:44920/solr", [junit4] 2> "type":"TLOG"}=20 [junit4] 2> 414790 INFO (OverseerStateUpdate-98739040137904134-127.0.= 0.1:38423_solr-n_0000000000) [n:127.0.0.1:38423_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"tlog_replica_test_add_docs", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"tlog_replica_test_add_docs_shard1_replica_t2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:38423/solr", [junit4] 2> "type":"TLOG"}=20 [junit4] 2> 415352 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&core= NodeName=3Dcore_node4&collection.configName=3Dconf&newCollection=3Dtrue&nam= e=3Dtlog_replica_test_add_docs_shard1_replica_t2&action=3DCREATE&numShards= =3D1&collection=3Dtlog_replica_test_add_docs&shard=3Dshard1&wt=3Djavabin&ve= rsion=3D2&replicaType=3DTLOG [junit4] 2> 415353 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 21= 47483647 transient cores [junit4] 2> 415389 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&core= NodeName=3Dcore_node3&collection.configName=3Dconf&newCollection=3Dtrue&nam= e=3Dtlog_replica_test_add_docs_shard1_replica_t1&action=3DCREATE&numShards= =3D1&collection=3Dtlog_replica_test_add_docs&shard=3Dshard1&wt=3Djavabin&ve= rsion=3D2&replicaType=3DTLOG [junit4] 2> 415390 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr = ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 21= 47483647 transient cores [junit4] 2> 415718 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 415726 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 415738 INFO (zkCallback-146-thread-2-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 415763 INFO (zkCallback-147-thread-2-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 421459 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0 [junit4] 2> 421480 WARN (SUITE-TestTlogReplica-seed#[8EFA0E21BA50E84B= ]-worker-SendThread(127.0.0.1:41222)) [ ] o.a.z.ClientCnxn Client sessio= n timed out, have not heard from server in 7352ms for sessionid 0x15ecaa244= e20008 [junit4] 2> 421529 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from = client sessionid 0x15ecaa244e20008, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.lang.Thread.run(Thread.java:748) [junit4] 2> 421619 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.s.IndexSchema [tlog_replica_test_add_docs_shar= d1_replica_t1] Schema name=3Dminimal [junit4] 2> 421622 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with u= niqueid field id [junit4] 2> 421622 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replic= a_test_add_docs_shard1_replica_t1' using configuration from collection tlog= _replica_test_add_docs, trusted=3Dtrue [junit4] 2> 421627 WARN (zkCallback-153-thread-1) [ ] o.a.s.c.c.Co= nnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5d1d= a282 name: ZooKeeperConnection Watcher:127.0.0.1:41222/solr got event Watch= edEvent state:Disconnected type:None path:null path: null type: None [junit4] 2> 421627 WARN (zkCallback-153-thread-1) [ ] o.a.s.c.c.Co= nnectionManager zkClient has disconnected [junit4] 2> 421656 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_4= 4920.solr.core.tlog_replica_test_add_docs.shard1.replica_t1' (registry 'sol= r.core.tlog_replica_test_add_docs.shard1.replica_t1') enabled at server: co= m.sun.jmx.mbeanserver.JmxMBeanServer@300dea7f [junit4] 2> 421656 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 421656 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.SolrCore [[tlog_replica_test_add_docs_shard1= _replica_t1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspa= ce/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestT= logReplica_8EFA0E21BA50E84B-001/tempDir-001/node2/tlog_replica_test_add_doc= s_shard1_replica_t1], dataDir=3D[/home/jenkins/jenkins-slave/workspace/Luce= ne-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogRepl= ica_8EFA0E21BA50E84B-001/tempDir-001/node2/./tlog_replica_test_add_docs_sha= rd1_replica_t1/data/] [junit4] 2> 421664 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0 [junit4] 2> 421703 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.s.IndexSchema [tlog_replica_test_add_docs_shar= d1_replica_t2] Schema name=3Dminimal [junit4] 2> 421718 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with u= niqueid field id [junit4] 2> 421718 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replic= a_test_add_docs_shard1_replica_t2' using configuration from collection tlog= _replica_test_add_docs, trusted=3Dtrue [junit4] 2> 421719 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_3= 8423.solr.core.tlog_replica_test_add_docs.shard1.replica_t2' (registry 'sol= r.core.tlog_replica_test_add_docs.shard1.replica_t2') enabled at server: co= m.sun.jmx.mbeanserver.JmxMBeanServer@300dea7f [junit4] 2> 421719 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 421719 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.SolrCore [[tlog_replica_test_add_docs_shard1= _replica_t2] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspa= ce/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestT= logReplica_8EFA0E21BA50E84B-001/tempDir-001/node1/tlog_replica_test_add_doc= s_shard1_replica_t2], dataDir=3D[/home/jenkins/jenkins-slave/workspace/Luce= ne-Solr-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogRepl= ica_8EFA0E21BA50E84B-001/tempDir-001/node1/./tlog_replica_test_add_docs_sha= rd1_replica_t2/data/] [junit4] 2> 422041 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.UpdateHandler Using UpdateLog implementation= : org.apache.solr.update.UpdateLog [junit4] 2> 422041 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3D= null defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 = numVersionBuckets=3D65536 [junit4] 2> 422095 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 422095 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 422096 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.s.SolrIndexSearcher Opening [Searcher@335e2bf3= [tlog_replica_test_add_docs_shard1_replica_t1] main] [junit4] 2> 422147 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperS= torageIO with znodeBase: /configs/conf [junit4] 2> 422155 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.r.ManagedResourceStorage Loaded null at path _= rest_managed.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 422156 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.h.ReplicationHandler Commits will be reserved = for 10000ms. [junit4] 2> 422156 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.UpdateLog Could not find max version in inde= x or recent updates, using new clock 1579824655455223808 [junit4] 2> 422294 INFO (searcherExecutor-474-thread-1-processing-n:1= 27.0.0.1:44920_solr x:tlog_replica_test_add_docs_shard1_replica_t1 s:shard1= c:tlog_replica_test_add_docs r:core_node3) [n:127.0.0.1:44920_solr c:tlog_= replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_sh= ard1_replica_t1] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replic= a_t1] Registered new searcher Searcher@335e2bf3[tlog_replica_test_add_docs_= shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader(= ))} [junit4] 2> 422304 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ShardLeaderElectionContext Waiting until we = see more replicas up for shard shard1: total=3D2 found=3D1 timeoutin=3D9999= ms [junit4] 2> 422305 INFO (zkCallback-147-thread-2-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 422305 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 422320 INFO (zkCallback-146-thread-2-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 422320 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 422424 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.u.UpdateHandler Using UpdateLog implementation= : org.apache.solr.update.UpdateLog [junit4] 2> 422424 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3D= null defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 = numVersionBuckets=3D65536 [junit4] 2> 422425 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 422425 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 422426 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.s.SolrIndexSearcher Opening [Searcher@3efcd8ba= [tlog_replica_test_add_docs_shard1_replica_t2] main] [junit4] 2> 422432 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperS= torageIO with znodeBase: /configs/conf [junit4] 2> 422432 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.r.ManagedResourceStorage Loaded null at path _= rest_managed.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 422433 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.h.ReplicationHandler Commits will be reserved = for 10000ms. [junit4] 2> 422433 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.u.UpdateLog Could not find max version in inde= x or recent updates, using new clock 1579824655745679360 [junit4] 2> 422477 INFO (searcherExecutor-475-thread-1-processing-n:1= 27.0.0.1:38423_solr x:tlog_replica_test_add_docs_shard1_replica_t2 s:shard1= c:tlog_replica_test_add_docs r:core_node4) [n:127.0.0.1:38423_solr c:tlog_= replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_docs_sh= ard1_replica_t2] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replic= a_t2] Registered new searcher Searcher@3efcd8ba[tlog_replica_test_add_docs_= shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader(= ))} [junit4] 2> 422814 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ShardLeaderElectionContext Enough replicas f= ound to continue. [junit4] 2> 422814 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ShardLeaderElectionContext I may be the new = leader - try and sync [junit4] 2> 422814 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0= .1:44920/solr/tlog_replica_test_add_docs_shard1_replica_t1/ [junit4] 2> 422815 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.PeerSync PeerSync: core=3Dtlog_replica_test_= add_docs_shard1_replica_t1 url=3Dhttp://127.0.0.1:44920/solr START replicas= =3D[http://127.0.0.1:38423/solr/tlog_replica_test_add_docs_shard1_replica_t= 2/] nUpdates=3D100 [junit4] 2> 422981 INFO (qtp1238270335-925) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t2] webapp=3D/solr path=3D/get params=3D{distrib=3Dfalse&qt=3D/ge= t&fingerprint=3Dfalse&getVersions=3D100&wt=3Djavabin&version=3D2} status=3D= 0 QTime=3D146 [junit4] 2> 423156 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.PeerSync PeerSync: core=3Dtlog_replica_test_= add_docs_shard1_replica_t1 url=3Dhttp://127.0.0.1:44920/solr DONE. We have= no versions. sync failed. [junit4] 2> 423156 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.SyncStrategy Leader's attempt to sync with s= hard failed, moving to the next candidate [junit4] 2> 423156 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ShardLeaderElectionContext We failed sync, b= ut we have no versions - we can't sync in that case - we were active before= , so become leader anyway [junit4] 2> 423156 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ShardLeaderElectionContext Found all replica= s participating in election, clear LIR [junit4] 2> 423193 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ZkController tlog_replica_test_add_docs_shar= d1_replica_t1 stopping background replication from leader [junit4] 2> 423255 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ShardLeaderElectionContext I am the new lead= er: http://127.0.0.1:44920/solr/tlog_replica_test_add_docs_shard1_replica_t= 1/ shard1 [junit4] 2> 423363 INFO (zkCallback-147-thread-2-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423363 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423383 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423391 INFO (zkCallback-146-thread-2-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423420 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.ZkController I am the leader, no recovery ne= cessary [junit4] 2> 423421 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/a= dmin/cores params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node3&collection= .configName=3Dconf&newCollection=3Dtrue&name=3Dtlog_replica_test_add_docs_s= hard1_replica_t1&action=3DCREATE&numShards=3D1&collection=3Dtlog_replica_te= st_add_docs&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DTLOG} sta= tus=3D0 QTime=3D8032 [junit4] 2> 423530 INFO (zkCallback-147-thread-2-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423530 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423546 INFO (zkCallback-146-thread-2-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423546 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423551 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.ZkController tlog_replica_test_add_docs_shar= d1_replica_t2 starting background replication from leader [junit4] 2> 423551 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.ReplicateFromLeader Will start replication f= rom leader with poll interval: 00:00:03 [junit4] 2> 423688 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.h.ReplicationHandler Poll scheduled at an inte= rval of 3000ms [junit4] 2> 423688 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.h.ReplicationHandler Commits will be reserved = for 10000ms. [junit4] 2> 423693 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/a= dmin/cores params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node4&collection= .configName=3Dconf&newCollection=3Dtrue&name=3Dtlog_replica_test_add_docs_s= hard1_replica_t2&action=3DCREATE&numShards=3D1&collection=3Dtlog_replica_te= st_add_docs&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DTLOG} sta= tus=3D0 QTime=3D8341 [junit4] 2> 423750 INFO (qtp1238270335-923) [n:127.0.0.1:38423_solr = ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for a= t most 30 seconds. Check all shard replicas [junit4] 2> 423751 INFO (OverseerCollectionConfigSetProcessor-9873904= 0137904134-127.0.0.1:38423_solr-n_0000000000) [n:127.0.0.1:38423_solr ] = o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work= /qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKee= per [junit4] 2> 423839 INFO (zkCallback-147-thread-2-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423839 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423855 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 423855 INFO (zkCallback-146-thread-2-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 424753 INFO (qtp1238270335-923) [n:127.0.0.1:38423_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections pa= rams=3D{pullReplicas=3D0&replicationFactor=3D0&collection.configName=3Dconf= &maxShardsPerNode=3D100&name=3Dtlog_replica_test_add_docs&nrtReplicas=3D0&a= ction=3DCREATE&numShards=3D1&tlogReplicas=3D2&wt=3Djavabin&version=3D2} sta= tus=3D0 QTime=3D10898 [junit4] 2> 425155 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_te= st_add_docs_shard1_replica_t2] webapp=3D/solr path=3D/update params=3D{upd= ate.distrib=3DFROMLEADER&distrib.from=3Dhttp://127.0.0.1:44920/solr/tlog_re= plica_test_add_docs_shard1_replica_t1/&wt=3Djavabin&version=3D2}{add=3D[1 (= 1579824658468831232)]} 0 18 [junit4] 2> 425156 INFO (qtp1924193907-928) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_te= st_add_docs_shard1_replica_t1] webapp=3D/solr path=3D/update params=3D{wt= =3Djavabin&version=3D2}{add=3D[1 (1579824658468831232)]} 0 217 [junit4] 2> 425193 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.DirectUpdateHandler2 start commit{_version_= =3D1579824658639749120,optimize=3Dfalse,openSearcher=3Dtrue,waitSearcher=3D= true,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 425193 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.SolrIndexWriter Calling setCommitData with I= W:org.apache.solr.update.SolrIndexWriter@4bc069f2 commitCommandVersion:1579= 824658639749120 [junit4] 2> 425461 INFO (qtp1238270335-918) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_te= st_add_docs_shard1_replica_t2] webapp=3D/solr path=3D/update params=3D{upd= ate.distrib=3DFROMLEADER&waitSearcher=3Dtrue&openSearcher=3Dtrue&commit=3Dt= rue&softCommit=3Dfalse&distrib.from=3Dhttp://127.0.0.1:44920/solr/tlog_repl= ica_test_add_docs_shard1_replica_t1/&commit_end_point=3Dtrue&wt=3Djavabin&v= ersion=3D2&expungeDeletes=3Dfalse}{commit=3D} 0 0 [junit4] 2> 425468 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Updated masterUrl to ht= tp://127.0.0.1:44920/solr/tlog_replica_test_add_docs_shard1_replica_t1/ [junit4] 2> 425471 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.s.SolrIndexSearcher Opening [Searcher@63b51368= [tlog_replica_test_add_docs_shard1_replica_t1] main] [junit4] 2> 425502 INFO (searcherExecutor-474-thread-1-processing-n:1= 27.0.0.1:44920_solr x:tlog_replica_test_add_docs_shard1_replica_t1 s:shard1= c:tlog_replica_test_add_docs r:core_node3) [n:127.0.0.1:44920_solr c:tlog_= replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_sh= ard1_replica_t1] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replic= a_t1] Registered new searcher Searcher@63b51368[tlog_replica_test_add_docs_= shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader(= Uninverting(_0(7.1.0):C1)))} [junit4] 2> 425503 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 425503 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_te= st_add_docs_shard1_replica_t1] webapp=3D/solr path=3D/update params=3D{upd= ate.distrib=3DFROMLEADER&waitSearcher=3Dtrue&openSearcher=3Dtrue&commit=3Dt= rue&softCommit=3Dfalse&distrib.from=3Dhttp://127.0.0.1:44920/solr/tlog_repl= ica_test_add_docs_shard1_replica_t1/&commit_end_point=3Dtrue&wt=3Djavabin&v= ersion=3D2&expungeDeletes=3Dfalse}{commit=3D} 0 310 [junit4] 2> 425503 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{qt=3D/replicatio= n&wt=3Djavabin&version=3D2&command=3Dindexversion} status=3D0 QTime=3D0 [junit4] 2> 425504 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 425504 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Master's version: 15066= 38201370 [junit4] 2> 425504 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 425504 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Slave's version: 0 [junit4] 2> 425504 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Starting replication pr= ocess [junit4] 2> 425551 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&wt=3Djavabin&version=3D2&command=3Dfilelist} status=3D0 QT= ime=3D46 [junit4] 2> 425552 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Number of files in late= st index in master: 13 [junit4] 2> 425570 INFO (qtp1924193907-929) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_te= st_add_docs_shard1_replica_t1] webapp=3D/solr path=3D/update params=3D{_st= ateVer_=3Dtlog_replica_test_add_docs:6&waitSearcher=3Dtrue&commit=3Dtrue&so= ftCommit=3Dfalse&wt=3Djavabin&version=3D2}{commit=3D} 0 411 [junit4] 2> 425571 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Starting download (full= Copy=3Dfalse) to MockDirectoryWrapper(RAMDirectory@6fea9e60 lockFactory=3Do= rg.apache.lucene.store.SingleInstanceLockFactory@128d6537) [junit4] 2> 425590 INFO (qtp1924193907-928) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0.si&checksum=3Dtrue&wt=3Dfilestream&command=3Dfil= econtent} status=3D0 QTime=3D2 [junit4] 2> 425596 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/select params=3D{q=3D*:*&wt=3Djavabin&= version=3D2} hits=3D1 status=3D0 QTime=3D0 [junit4] 2> 425670 INFO (qtp1924193907-914) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/select params=3D{q=3D*:*&wt=3Djavabin&= version=3D2} hits=3D1 status=3D0 QTime=3D0 [junit4] 2> 425722 INFO (qtp1924193907-929) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0_Lucene50_0.doc&checksum=3Dtrue&wt=3Dfilestream&c= ommand=3Dfilecontent} status=3D0 QTime=3D0 [junit4] 2> 425758 INFO (qtp1924193907-919) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0_Lucene50_0.tim&checksum=3Dtrue&wt=3Dfilestream&c= ommand=3Dfilecontent} status=3D0 QTime=3D0 [junit4] 2> 425759 INFO (qtp1924193907-928) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0_Lucene50_0.pos&checksum=3Dtrue&wt=3Dfilestream&c= ommand=3Dfilecontent} status=3D0 QTime=3D0 [junit4] 2> 425761 INFO (qtp1924193907-928) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0.nvd&checksum=3Dtrue&wt=3Dfilestream&command=3Dfi= lecontent} status=3D0 QTime=3D0 [junit4] 2> 425779 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0.fdx&checksum=3Dtrue&wt=3Dfilestream&command=3Dfi= lecontent} status=3D0 QTime=3D0 [junit4] 2> 425940 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/admin/plugins params=3D{qt=3D/admin/pl= ugins&stats=3Dtrue&wt=3Djavabin&version=3D2} status=3D0 QTime=3D178 [junit4] 2> 426020 INFO (qtp1924193907-914) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0_Lucene50_0.tip&checksum=3Dtrue&wt=3Dfilestream&c= ommand=3Dfilecontent} status=3D0 QTime=3D0 [junit4] 2> 426021 INFO (qtp1924193907-919) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0.fdt&checksum=3Dtrue&wt=3Dfilestream&command=3Dfi= lecontent} status=3D0 QTime=3D0 [junit4] 2> 426027 INFO (qtp1238270335-918) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t2] webapp=3D/solr path=3D/select params=3D{q=3D*:*&wt=3Djavabin&= version=3D2} hits=3D0 status=3D0 QTime=3D0 [junit4] 2> 426072 INFO (qtp1924193907-919) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0_Lucene70_0.dvm&checksum=3Dtrue&wt=3Dfilestream&c= ommand=3Dfilecontent} status=3D0 QTime=3D0 [junit4] 2> 426093 INFO (qtp1924193907-928) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0_Lucene70_0.dvd&checksum=3Dtrue&wt=3Dfilestream&c= ommand=3Dfilecontent} status=3D0 QTime=3D0 [junit4] 2> 426144 INFO (qtp1924193907-930) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0.nvm&checksum=3Dtrue&wt=3Dfilestream&command=3Dfi= lecontent} status=3D0 QTime=3D0 [junit4] 2> 426146 INFO (qtp1924193907-929) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3D_0.fnm&checksum=3Dtrue&wt=3Dfilestream&command=3Dfi= lecontent} status=3D0 QTime=3D0 [junit4] 2> 426156 INFO (qtp1238270335-918) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t2] webapp=3D/solr path=3D/select params=3D{q=3D*:*&wt=3Djavabin&= version=3D2} hits=3D0 status=3D0 QTime=3D0 [junit4] 2> 426181 INFO (qtp1924193907-917) [n:127.0.0.1:44920_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_d= ocs_shard1_replica_t1] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t1] webapp=3D/solr path=3D/replication params=3D{generation=3D2&q= t=3D/replication&file=3Dsegments_2&checksum=3Dtrue&wt=3Dfilestream&command= =3Dfilecontent} status=3D0 QTime=3D0 [junit4] 2> 426181 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.h.IndexFetcher Total time taken for do= wnload (fullCopy=3Dfalse,bytesDownloaded=3D2365) : 0 secs (null bytes/sec) = to MockDirectoryWrapper(RAMDirectory@6fea9e60 lockFactory=3Dorg.apache.luce= ne.store.SingleInstanceLockFactory@128d6537) [junit4] 2> 426184 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.u.DefaultSolrCoreState New IndexWriter= is ready to be used. [junit4] 2> 426197 INFO (indexFetcher-485-thread-1) [n:127.0.0.1:3842= 3_solr c:tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_te= st_add_docs_shard1_replica_t2] o.a.s.s.SolrIndexSearcher Opening [Searcher@= 65c6f2a9[tlog_replica_test_add_docs_shard1_replica_t2] main] [junit4] 2> 426198 INFO (searcherExecutor-475-thread-1-processing-n:1= 27.0.0.1:38423_solr x:tlog_replica_test_add_docs_shard1_replica_t2 s:shard1= c:tlog_replica_test_add_docs r:core_node4) [n:127.0.0.1:38423_solr c:tlog_= replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_docs_sh= ard1_replica_t2] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replic= a_t2] Registered new searcher Searcher@65c6f2a9[tlog_replica_test_add_docs_= shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader(= Uninverting(_0(7.1.0):C1)))} [junit4] 2> 426266 INFO (qtp1238270335-918) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t2] webapp=3D/solr path=3D/select params=3D{q=3D*:*&wt=3Djavabin&= version=3D2} hits=3D1 status=3D0 QTime=3D0 [junit4] 2> 426441 INFO (qtp1238270335-918) [n:127.0.0.1:38423_solr c= :tlog_replica_test_add_docs s:shard1 r:core_node4 x:tlog_replica_test_add_d= ocs_shard1_replica_t2] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1= _replica_t2] webapp=3D/solr path=3D/admin/plugins params=3D{qt=3D/admin/pl= ugins&stats=3Dtrue&wt=3Djavabin&version=3D2} status=3D0 QTime=3D173 [junit4] 2> 426443 INFO (TEST-TestTlogReplica.testAddDocs-seed#[8EFA0= E21BA50E84B]) [ ] o.a.s.c.TestTlogReplica tearDown deleting collection [junit4] 2> 426461 INFO (qtp1238270335-924) [n:127.0.0.1:38423_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with par= ams name=3Dtlog_replica_test_add_docs&action=3DDELETE&wt=3Djavabin&version= =3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 426546 INFO (OverseerThreadFactory-469-thread-2-processin= g-n:127.0.0.1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.OverseerColl= ectionMessageHandler Executing Collection Cmd : action=3DUNLOAD&deleteInsta= nceDir=3Dtrue&deleteDataDir=3Dtrue [junit4] 2> 426693 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsolr.= core.tlog_replica_test_add_docs.shard1.replica_t2, tag=3Dnull [junit4] 2> 426693 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.rep= orters.SolrJmxReporter@35bf0486: rootName =3D solr_38423, domain =3D solr.c= ore.tlog_replica_test_add_docs.shard1.replica_t2, service url =3D null, age= nt id =3D null] for registry solr.core.tlog_replica_test_add_docs.shard1.re= plica_t2 / com.codahale.metrics.MetricRegistry@2a48b950 [junit4] 2> 426730 INFO (qtp1924193907-915) [n:127.0.0.1:44920_solr = ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsolr.= core.tlog_replica_test_add_docs.shard1.replica_t1, tag=3Dnull [junit4] 2> 426730 INFO (qtp1924193907-915) [n:127.0.0.1:44920_solr = ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.rep= orters.SolrJmxReporter@6978d509: rootName =3D solr_44920, domain =3D solr.c= ore.tlog_replica_test_add_docs.shard1.replica_t1, service url =3D null, age= nt id =3D null] for registry solr.core.tlog_replica_test_add_docs.shard1.re= plica_t1 / com.codahale.metrics.MetricRegistry@114608d6 [junit4] 2> 426769 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.c.ZkController tlog_replica_test_add_docs_shard1_replica_t2 stopp= ing background replication from leader [junit4] 2> 426912 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t2] CLOSIN= G SolrCore org.apache.solr.core.SolrCore@1cef684c [junit4] 2> 426912 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsolr.= core.tlog_replica_test_add_docs.shard1.replica_t2, tag=3D485451852 [junit4] 2> 426913 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsolr.= collection.tlog_replica_test_add_docs.shard1.leader, tag=3D485451852 [junit4] 2> 427022 INFO (qtp1924193907-915) [n:127.0.0.1:44920_solr = ] o.a.s.c.ZkController tlog_replica_test_add_docs_shard1_replica_t1 stopp= ing background replication from leader [junit4] 2> 427023 INFO (qtp1924193907-915) [n:127.0.0.1:44920_solr = ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t1] CLOSIN= G SolrCore org.apache.solr.core.SolrCore@617b6700 [junit4] 2> 427023 INFO (qtp1924193907-915) [n:127.0.0.1:44920_solr = ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsolr.= core.tlog_replica_test_add_docs.shard1.replica_t1, tag=3D1635477248 [junit4] 2> 427023 INFO (qtp1924193907-915) [n:127.0.0.1:44920_solr = ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=3Dsolr.= collection.tlog_replica_test_add_docs.shard1.leader, tag=3D1635477248 [junit4] 2> 427061 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.c.ShardLeaderElectionContextBase No version found for ephemeral l= eader parent node, won't remove previous leader registration. [junit4] 2> 427075 INFO (qtp1238270335-926) [n:127.0.0.1:38423_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params= =3D{deleteInstanceDir=3Dtrue&core=3Dtlog_replica_test_add_docs_shard1_repli= ca_t2&qt=3D/admin/cores&deleteDataDir=3Dtrue&action=3DUNLOAD&wt=3Djavabin&v= ersion=3D2} status=3D0 QTime=3D381 [junit4] 2> 427128 INFO (zkCallback-153-thread-3) [ ] o.a.s.c.c.Zk= StateReader A cluster state change: [WatchedEvent state:SyncConnected type:= NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] fo= r collection [tlog_replica_test_add_docs] has occurred - updating... (live = nodes size: [2]) [junit4] 2> 427128 INFO (zkCallback-146-thread-2-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 427128 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_= replica_test_add_docs] has occurred - updating... (live nodes size: [2]) [junit4] 2> 427389 WARN (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.LeaderElector Our node = is no longer in line to be leader [junit4] 2> 427390 INFO (qtp1924193907-915) [n:127.0.0.1:44920_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores params= =3D{deleteInstanceDir=3Dtrue&core=3Dtlog_replica_test_add_docs_shard1_repli= ca_t1&qt=3D/admin/cores&deleteDataDir=3Dtrue&action=3DUNLOAD&wt=3Djavabin&v= ersion=3D2} status=3D0 QTime=3D680 [junit4] 2> 427590 INFO (zkCallback-153-thread-3) [ ] o.a.s.c.c.Zk= StateReader A cluster state change: [WatchedEvent state:SyncConnected type:= NodeDeleted path:/collections/tlog_replica_test_add_docs/state.json] for co= llection [tlog_replica_test_add_docs] has occurred - updating... (live node= s size: [2]) [junit4] 2> 428181 INFO (qtp1238270335-924) [n:127.0.0.1:38423_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections pa= rams=3D{name=3Dtlog_replica_test_add_docs&action=3DDELETE&wt=3Djavabin&vers= ion=3D2} status=3D0 QTime=3D1720 [junit4] 2> 428182 INFO (TEST-TestTlogReplica.testAddDocs-seed#[8EFA0= E21BA50E84B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testAddDocs [junit4] 2> 428560 INFO (OverseerCollectionConfigSetProcessor-9873904= 0137904134-127.0.0.1:38423_solr-n_0000000000) [n:127.0.0.1:38423_solr ] = o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work= /qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKee= per [junit4] 2> 428649 INFO (TEST-TestTlogReplica.testRealTimeGet-seed#[8= EFA0E21BA50E84B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testRealTimeGet [junit4] 2> 428650 INFO (qtp1238270335-922) [n:127.0.0.1:38423_solr = ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with par= ams pullReplicas=3D0&replicationFactor=3D0&collection.configName=3Dconf&max= ShardsPerNode=3D100&name=3Dtlog_replica_test_real_time_get&nrtReplicas=3D0&= action=3DCREATE&numShards=3D1&tlogReplicas=3D2&wt=3Djavabin&version=3D2 and= sendToOCPQueue=3Dtrue [junit4] 2> 428705 INFO (OverseerThreadFactory-469-thread-3-processin= g-n:127.0.0.1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.CreateCollec= tionCmd Create collection tlog_replica_test_real_time_get [junit4] 2> 429128 INFO (OverseerStateUpdate-98739040137904134-127.0.= 0.1:38423_solr-n_0000000000) [n:127.0.0.1:38423_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"tlog_replica_test_real_time_get", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"tlog_replica_test_real_time_get_shard1_replica_t= 1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:44920/solr", [junit4] 2> "type":"TLOG"}=20 [junit4] 2> 429143 INFO (OverseerStateUpdate-98739040137904134-127.0.= 0.1:38423_solr-n_0000000000) [n:127.0.0.1:38423_solr ] o.a.s.c.o.SliceMu= tator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"tlog_replica_test_real_time_get", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"tlog_replica_test_real_time_get_shard1_replica_t= 2", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:38423/solr", [junit4] 2> "type":"TLOG"}=20 [junit4] 2> 429362 INFO (qtp1924193907-919) [n:127.0.0.1:44920_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&core= NodeName=3Dcore_node3&collection.configName=3Dconf&newCollection=3Dtrue&nam= e=3Dtlog_replica_test_real_time_get_shard1_replica_t1&action=3DCREATE&numSh= ards=3D1&collection=3Dtlog_replica_test_real_time_get&shard=3Dshard1&wt=3Dj= avabin&version=3D2&replicaType=3DTLOG [junit4] 2> 429365 INFO (qtp1238270335-920) [n:127.0.0.1:38423_solr = ] o.a.s.h.a.CoreAdminOperation core create command qt=3D/admin/cores&core= NodeName=3Dcore_node4&collection.configName=3Dconf&newCollection=3Dtrue&nam= e=3Dtlog_replica_test_real_time_get_shard1_replica_t2&action=3DCREATE&numSh= ards=3D1&collection=3Dtlog_replica_test_real_time_get&shard=3Dshard1&wt=3Dj= avabin&version=3D2&replicaType=3DTLOG [junit4] 2> 429528 INFO (zkCallback-146-thread-2-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_real_time_get/state.json] for collection [= tlog_replica_test_real_time_get] has occurred - updating... (live nodes siz= e: [2]) [junit4] 2> 429528 INFO (zkCallback-146-thread-1-processing-n:127.0.0= .1:44920_solr) [n:127.0.0.1:44920_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_real_time_get/state.json] for collection [= tlog_replica_test_real_time_get] has occurred - updating... (live nodes siz= e: [2]) [junit4] 2> 429528 INFO (zkCallback-147-thread-1-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_real_time_get/state.json] for collection [= tlog_replica_test_real_time_get] has occurred - updating... (live nodes siz= e: [2]) [junit4] 2> 429528 INFO (zkCallback-147-thread-2-processing-n:127.0.0= .1:38423_solr) [n:127.0.0.1:38423_solr ] o.a.s.c.c.ZkStateReader A clust= er state change: [WatchedEvent state:SyncConnected type:NodeDataChanged pat= h:/collections/tlog_replica_test_real_time_get/state.json] for collection [= tlog_replica_test_real_time_get] has occurred - updating... (live nodes siz= e: [2]) [junit4] 2> 430457 INFO (qtp1924193907-919) [n:127.0.0.1:44920_solr c= :tlog_replica_test_real_time_get s:shard1 r:core_node3 x:tlog_replica_test_= real_time_get_shard1_replica_t1] o.a.s.c.SolrConfig Using Lucene MatchVersi= on: 7.1.0 [junit4] =20 [...truncated too long message...] olrJmxReporter@640ede36: rootName =3D solr_38968, domain =3D solr.core.coll= ection1.shard1.replica_n95, service url =3D null, agent id =3D null] for re= gistry solr.core.collection1.shard1.replica_n95 / com.codahale.metrics.Metr= icRegistry@37475af3 [junit4] 2> 4996435 INFO (coreCloseExecutor-6251-thread-3) [n:127.0.0= .1:38968_solr c:collection1 s:shard1 r:core_node96 x:collection1_shard1_rep= lica_n95] o.a.s.m.SolrMetricManager Closing metric reporters for registry= =3Dsolr.collection.collection1.shard1.leader, tag=3D2080430028 [junit4] 2> 4996507 INFO (jetty-closer-2448-thread-1) [ ] o.a.s.c.= Overseer Overseer (id=3D98739336491499529-127.0.0.1:33151_solr-n_0000000000= ) closing [junit4] 2> 4996508 INFO (OverseerStateUpdate-98739336491499529-127.0= .0.1:33151_solr-n_0000000000) [n:127.0.0.1:33151_solr ] o.a.s.c.Overseer= Overseer Loop exiting : 127.0.0.1:33151_solr [junit4] 2> 4996546 INFO (zkCallback-2462-thread-1-processing-n:127.0= .0.1:36425_solr) [n:127.0.0.1:36425_solr ] o.a.s.c.c.ZkStateReader Updat= ed live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 4996546 WARN (zkCallback-2469-thread-2-processing-n:127.0= .0.1:38968_solr) [n:127.0.0.1:38968_solr ] o.a.s.c.LeaderElector Our nod= e is no longer in line to be leader [junit4] 2> 4996546 INFO (zkCallback-2469-thread-1-processing-n:127.0= .0.1:38968_solr) [n:127.0.0.1:38968_solr ] o.a.s.c.c.ZkStateReader Updat= ed live nodes from ZooKeeper... (4) -> (3) [junit4] 2> 4996546 INFO (zkCallback-2469-thread-1-processing-n:127.0= .0.1:38968_solr) [n:127.0.0.1:38968_solr ] o.a.s.c.OverseerElectionConte= xt I am going to be the leader 127.0.0.1:38968_solr [junit4] 2> 4996566 INFO (zkCallback-2462-thread-3-processing-n:127.0= .0.1:36425_solr) [n:127.0.0.1:36425_solr ] o.a.s.c.OverseerElectionConte= xt I am going to be the leader 127.0.0.1:36425_solr [junit4] 2> 4996584 INFO (zkCallback-2462-thread-2-processing-n:127.0= .0.1:36425_solr) [n:127.0.0.1:36425_solr ] o.a.s.c.c.ZkStateReader Updat= ed live nodes from ZooKeeper... (3) -> (1) [junit4] 2> 4996600 INFO (jetty-closer-2448-thread-2) [ ] o.e.j.s.= h.ContextHandler Stopped o.e.j.s.ServletContextHandler@562db0da{/solr,null,= UNAVAILABLE} [junit4] 2> 4998048 WARN (zkCallback-2467-thread-3-processing-n:127.0= .0.1:33151_solr) [n:127.0.0.1:33151_solr ] o.a.s.c.c.ZkStateReader ZooKe= eper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode =3D Sess= ion expired for /live_nodes] [junit4] 2> 4998048 INFO (jetty-closer-2448-thread-1) [ ] o.e.j.s.= h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b603a19{/solr,null,= UNAVAILABLE} [junit4] 2> 4998068 WARN (zkCallback-2469-thread-1-processing-n:127.0= .0.1:38968_solr) [n:127.0.0.1:38968_solr ] o.a.s.c.c.ZkStateReader ZooKe= eper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode =3D Sess= ion expired for /live_nodes] [junit4] 2> 4998068 INFO (jetty-closer-2448-thread-3) [ ] o.e.j.s.= h.ContextHandler Stopped o.e.j.s.ServletContextHandler@e9d0027{/solr,null,U= NAVAILABLE} [junit4] 2> 4998125 WARN (zkCallback-2462-thread-1-processing-n:127.0= .0.1:36425_solr) [n:127.0.0.1:36425_solr ] o.a.s.c.c.ZkStateReader ZooKe= eper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode =3D Sess= ion expired for /live_nodes] [junit4] 2> 4998125 INFO (jetty-closer-2448-thread-4) [ ] o.e.j.s.= h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b2d0ea1{/solr,null,= UNAVAILABLE} [junit4] 2> 4998126 ERROR (SUITE-AssignBackwardCompatibilityTest-seed#= [8EFA0E21BA50E84B]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler= is not registered, so ZooKeeper server won't take any action on ERROR or S= HUTDOWN server state changes [junit4] 2> 4998142 INFO (SUITE-AssignBackwardCompatibilityTest-seed#= [8EFA0E21BA50E84B]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.= 0.1:38039 38039 [junit4] 2> 4998284 INFO (Thread-2951) [ ] o.a.s.c.ZkTestServer co= nnecting to 127.0.0.1:38039 38039 [junit4] 2> 4998284 WARN (Thread-2951) [ ] o.a.s.c.ZkTestServer Wa= tch limit violations:=20 [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2>=20 [junit4] 2> =0915=09/solr/configs/collection1/managed-schema [junit4] 2> =096=09/solr/aliases.json [junit4] 2> =094=09/solr/security.json [junit4] 2> =094=09/solr/configs/collection1 [junit4] 2>=20 [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2>=20 [junit4] 2> =09167=09/solr/collections/collection1/state.json [junit4] 2> =096=09/solr/clusterprops.json [junit4] 2> =096=09/solr/clusterstate.json [junit4] 2> =093=09/solr/collections/collection1/leader_elect/shard1/e= lection/98739336491499527-core_node82-n_0000000004 [junit4] 2> =093=09/solr/collections/collection1/leader_elect/shard1/e= lection/98739336491499529-core_node7-n_0000000001 [junit4] 2> =092=09/solr/collections/collection1/leader_elect/shard1/e= lection/98739336491499531-core_node96-n_0000000011 [junit4] 2> =092=09/solr/overseer_elect/election/98739336491499531-127= .0.0.1:38968_solr-n_0000000001 [junit4] 2> =092=09/solr/collections/collection1/leader_elect/shard1/e= lection/98739336491499527-core_node8-n_0000000000 [junit4] 2>=20 [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2>=20 [junit4] 2> =096=09/solr/live_nodes [junit4] 2> =096=09/solr/collections [junit4] 2>=20 [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/je= nkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J0/te= mp/solr.cloud.AssignBackwardCompatibilityTest_8EFA0E21BA50E84B-001 [junit4] 2> Sep 28, 2017 11:52:54 PM com.carrotsearch.randomizedtestin= g.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thre= ad(s). [junit4] 2> NOTE: test params are: codec=3DDummyCompressingStoredField= s(storedFieldsFormat=3DCompressingStoredFieldsFormat(compressionMode=3DDUMM= Y, chunkSize=3D30625, maxDocsPerChunk=3D5, blockSize=3D761), termVectorsFor= mat=3DCompressingTermVectorsFormat(compressionMode=3DDUMMY, chunkSize=3D306= 25, blockSize=3D761)), sim=3DRandomSimilarity(queryNorm=3Dfalse): {}, local= e=3Dja-JP, timezone=3DAsia/Rangoon [junit4] 2> NOTE: Linux 4.4.0-83-generic amd64/Oracle Corporation 1.8.= 0_144 (64-bit)/cpus=3D4,threads=3D1,free=3D268004160,total=3D526909440 [junit4] 2> NOTE: All tests run in this JVM: [TestRandomRequestDistrib= ution, TestBlobHandler, TestMultiValuedNumericRangeQuery, TestJettySolrRunn= er, StatsReloadRaceTest, DistributedSpellCheckComponentTest, AtomicUpdatePr= ocessorFactoryTest, PreAnalyzedUpdateProcessorTest, TestFieldCollectionReso= urce, TestGraphTermsQParserPlugin, SuggesterWFSTTest, TestSubQueryTransform= erCrossCore, TestCrossCoreJoin, PKIAuthenticationIntegrationTest, TestTlogR= eplica, TestBadConfig, TestSolrQueryResponse, TestGraphMLResponseWriter, Te= stPhraseSuggestions, TestCollationField, TestMergePolicyConfig, LeaderIniti= atedRecoveryOnCommitTest, SolrIndexMetricsTest, PropertiesRequestHandlerTes= t, SolrSlf4jReporterTest, MetricsConfigTest, SpellingQueryConverterTest, Te= stFunctionQuery, CdcrUpdateLogTest, HighlighterConfigTest, DebugComponentTe= st, TlogReplayBufferedWhileIndexingTest, MoveReplicaTest, TestSolr4Spatial,= TestWriterPerf, FullHLLTest, TestRemoteStreaming, HdfsBasicDistributedZk2T= est, SolrCloudExampleTest, TestSolrCoreParser, DefaultValueUpdateProcessorT= est, CdcrVersionReplicationTest, TestRangeQuery, TestReplicationHandlerBack= up, TestBackupRepositoryFactory, SynonymTokenizerTest, TestEmbeddedSolrServ= erAdminHandler, OpenExchangeRatesOrgProviderTest, BlockJoinFacetSimpleTest,= TestLegacyFieldReuse, TestBinaryField, CdcrReplicationDistributedZkTest, H= dfsChaosMonkeySafeLeaderTest, TestFaceting, TestNumericTokenStream, RemoteQ= ueryErrorTest, TestPerFieldSimilarityWithDefaultOverride, TestUseDocValuesA= sStored2, TestRandomCollapseQParserPlugin, CollectionReloadTest, CoreMergeI= ndexesAdminHandlerTest, OverseerTaskQueueTest, QueryElevationComponentTest,= TestMultiWordSynonyms, TestCopyFieldCollectionResource, TestUniqueKeyField= Resource, TestIndexingPerformance, SaslZkACLProviderTest, CursorMarkTest, T= estCSVLoader, TestFileDictionaryLookup, TestConfig, V2StandaloneTest, Distr= ibutedFacetPivotLongTailTest, TestHighlightDedupGrouping, TestCloudPivotFac= et, TestSchemaSimilarityResource, TestJoin, TestSolrConfigHandlerConcurrent= , TestExpandComponent, TestPHPSerializedResponseWriter, TestMiniSolrCloudCl= usterSSL, BasicZkTest, RestartWhileUpdatingTest, XmlUpdateRequestHandlerTes= t, RequestHandlersTest, ChangedSchemaMergeTest, TestRuleBasedAuthorizationP= lugin, TestRTimerTree, HdfsUnloadDistributedZkTest, TestSimpleQParserPlugin= , TestCollapseQParserPlugin, TestNamedUpdateProcessors, TestSolrCoreSnapsho= ts, CustomCollectionTest, MissingSegmentRecoveryTest, SpellCheckCollatorTes= t, TestSegmentSorting, TestConfigSetsAPIZkFailure, SubstringBytesRefFilterT= est, FieldAnalysisRequestHandlerTest, PeerSyncTest, TestDocumentBuilder, Te= stLuceneMatchVersion, TestFieldTypeResource, MBeansHandlerTest, FieldMutati= ngUpdateProcessorTest, TestCloudDeleteByQuery, SolrRequestParserTest, TestC= ollationFieldDocValues, TestRawResponseWriter, OutOfBoxZkACLAndCredentialsP= rovidersTest, UtilsToolTest, SolrCoreTest, AliasIntegrationTest, SolrGraphi= teReporterTest, TestCollectionsAPIViaSolrCloudCluster, TestStreamBody, Blob= RepositoryCloudTest, TestClusterStateMutator, BasicDistributedZkTest, Chaos= MonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, Col= lectionsAPIDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, Overs= eerTest, LeaderElectionIntegrationTest, TestReplicationHandler, TestDistrib= utedSearch, SolrCmdDistributorTest, TestIndexSearcher, HighlighterTest, Sof= tAutoCommitTest, DocValuesTest, TestLFUCache, TestRTGBase, CursorPagingTest= , TestCursorMarkWithoutUniqueKey, TestEmbeddedSolrServerSchemaAPI, Connecti= onReuseTest, AssignBackwardCompatibilityTest] [junit4] Completed [500/732 (5!)] on J0 in 67.62s, 1 test, 1 error <<< F= AILURES! [...truncated 47479 lines...] ------=_Part_799_114496361.1506649753773 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_799_114496361.1506649753773--