From dev-return-322485-archive-asf-public=cust-asf.ponee.io@lucene.apache.org Thu May 17 03:20:28 2018 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx-eu-01.ponee.io (Postfix) with SMTP id BEBA7180669 for ; Thu, 17 May 2018 03:20:25 +0200 (CEST) Received: (qmail 18519 invoked by uid 500); 17 May 2018 01:20:24 -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 18505 invoked by uid 99); 17 May 2018 01:20:23 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd4-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 17 May 2018 01:20:23 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd4-us-west.apache.org (ASF Mail Server at spamd4-us-west.apache.org) with ESMTP id EFB1EC00CD for ; Thu, 17 May 2018 01:20:22 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd4-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 1.741 X-Spam-Level: * X-Spam-Status: No, score=1.741 tagged_above=-999 required=6.31 tests=[KAM_ASCII_DIVIDERS=0.8, KAM_BADIPHTTP=2, KAM_LAZY_DOMAIN_SECURITY=1, KAM_LOTSOFHASH=0.25, RCVD_IN_DNSWL_MED=-2.3, T_RP_MATCHES_RCVD=-0.01, WEIRD_PORT=0.001] autolearn=disabled Received: from mx1-lw-eu.apache.org ([10.40.0.8]) by localhost (spamd4-us-west.apache.org [10.40.0.11]) (amavisd-new, port 10024) with ESMTP id py3wE7LszM5j for ; Thu, 17 May 2018 01:20:04 +0000 (UTC) Received: from mailrelay1-us-west.apache.org (mailrelay1-us-west.apache.org [209.188.14.139]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTP id 622C45F295 for ; Thu, 17 May 2018 01:20:03 +0000 (UTC) Received: from jenkins-master.apache.org (unknown [62.210.60.235]) by mailrelay1-us-west.apache.org (ASF Mail Server at mailrelay1-us-west.apache.org) with ESMTP id 199F5E0110 for ; Thu, 17 May 2018 01:20:02 +0000 (UTC) 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 7427FA009F for ; Thu, 17 May 2018 01:19:59 +0000 (UTC) Date: Thu, 17 May 2018 01:11:53 +0000 (UTC) From: Apache Jenkins Server To: dev@lucene.apache.org Message-ID: <1464570810.293.1526519999479.JavaMail.jenkins@jenkins-master.apache.org> In-Reply-To: <526794661.147.1526482875973.JavaMail.jenkins@jenkins-master.apache.org> References: <526794661.147.1526482875973.JavaMail.jenkins@jenkins-master.apache.org> Subject: [JENKINS] Lucene-Solr-Tests-7.x - Build # 609 - Still Unstable MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_292_1442514761.1526519999191" X-Jenkins-Job: Lucene-Solr-Tests-7.x X-Jenkins-Result: UNSTABLE ------=_Part_292_1442514761.1526519999191 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/609/ 1 tests failed. FAILED: org.apache.solr.cloud.autoscaling.SearchRateTriggerIntegrationTest= .testDeleteNode Error Message: unexpected DELETENODE status: {responseHeader=3D{status=3D0,QTime=3D24},sta= tus=3D{state=3Dnotfound,msg=3DDid not find [search_rate_trigger3/5f19e806aa= 0369Td0hr7vyajrsah2inj9ppbqyry/0] in any tasks queue}} Stack Trace: java.lang.AssertionError: unexpected DELETENODE status: {responseHeader=3D{= status=3D0,QTime=3D24},status=3D{state=3Dnotfound,msg=3DDid not find [searc= h_rate_trigger3/5f19e806aa0369Td0hr7vyajrsah2inj9ppbqyry/0] in any tasks qu= eue}} =09at __randomizedtesting.SeedInfo.seed([3E05F21542EA0DDC:1C973C97752082A1]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.autoscaling.SearchRateTriggerIntegrationTest.la= mbda$testDeleteNode$6(SearchRateTriggerIntegrationTest.java:668) =09at java.util.ArrayList.forEach(ArrayList.java:1257) =09at org.apache.solr.cloud.autoscaling.SearchRateTriggerIntegrationTest.te= stDeleteNode(SearchRateTriggerIntegrationTest.java:660) =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 14607 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.SearchRateTriggerInteg= rationTest [junit4] 2> 2839752 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity= checks: test.solr.allowed.securerandom=3Dnull & java.security.egd=3Dfile:/= dev/./urandom [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Luce= ne-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.= SearchRateTriggerIntegrationTest_3E05F21542EA0DDC-001/init-core-data-001 [junit4] 2> 2839753 WARN (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearch= ers: numOpens=3D6 numCloses=3D6 [junit4] 2> 2839754 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (= NUMERIC_POINTS_SYSPROP=3Dtrue) w/NUMERIC_DOCVALUES_SYSPROP=3Dfalse [junit4] 2> 2839755 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (fal= se) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason= =3D, ssl=3DNaN, value=3DNaN, clientAuth=3DNaN) [junit4] 2> 2839756 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cl= uster of 5 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests= -7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateTri= ggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001 [junit4] 2> 2839756 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SE= RVER [junit4] 2> 2839756 INFO (Thread-6467) [ ] o.a.s.c.ZkTestServer cl= ient port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2839756 INFO (Thread-6467) [ ] o.a.s.c.ZkTestServer St= arting server [junit4] 2> 2839760 ERROR (Thread-6467) [ ] o.a.z.s.ZooKeeperServer= ZKShutdownHandler is not registered, so ZooKeeper server won't take any ac= tion on ERROR or SHUTDOWN server state changes [junit4] 2> 2839856 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.c.ZkTestServer start zk server on = port:51535 [junit4] 2> 2839858 INFO (zkConnectionManagerCallback-9137-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839862 INFO (jetty-launcher-9134-thread-1) [ ] o.e.j.= s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa5= 9876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11 [junit4] 2> 2839863 INFO (jetty-launcher-9134-thread-2) [ ] o.e.j.= s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa5= 9876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11 [junit4] 2> 2839863 INFO (jetty-launcher-9134-thread-3) [ ] o.e.j.= s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa5= 9876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11 [junit4] 2> 2839863 INFO (jetty-launcher-9134-thread-4) [ ] o.e.j.= s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa5= 9876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11 [junit4] 2> 2839864 INFO (jetty-launcher-9134-thread-5) [ ] o.e.j.= s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa5= 9876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11 [junit4] 2> 2839864 INFO (jetty-launcher-9134-thread-1) [ ] o.e.j.= s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2839864 INFO (jetty-launcher-9134-thread-1) [ ] o.e.j.= s.session No SessionScavenger set, using defaults [junit4] 2> 2839864 INFO (jetty-launcher-9134-thread-1) [ ] o.e.j.= s.session node0 Scavenging every 600000ms [junit4] 2> 2839865 INFO (jetty-launcher-9134-thread-1) [ ] o.e.j.= s.h.ContextHandler Started o.e.j.s.ServletContextHandler@50657dc0{/solr,nul= l,AVAILABLE} [junit4] 2> 2839865 INFO (jetty-launcher-9134-thread-1) [ ] o.e.j.= s.AbstractConnector Started ServerConnector@11ae22a8{HTTP/1.1,[http/1.1]}{1= 27.0.0.1:55479} [junit4] 2> 2839865 INFO (jetty-launcher-9134-thread-1) [ ] o.e.j.= s.Server Started @2840036ms [junit4] 2> 2839865 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D55= 479} [junit4] 2> 2839866 ERROR (jetty-launcher-9134-thread-1) [ ] o.a.s.= u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be miss= ing or incomplete. [junit4] 2> 2839866 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLog= gerFactory [junit4] 2> 2839866 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= s.SolrDispatchFilter ___ _ Welcome to Apache Solr=E2=84=A2 vers= ion 7.4.0 [junit4] 2> 2839866 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2839866 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2839866 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-17T00:23:38.729Z [junit4] 2> 2839868 INFO (jetty-launcher-9134-thread-2) [ ] o.e.j.= s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2839868 INFO (jetty-launcher-9134-thread-2) [ ] o.e.j.= s.session No SessionScavenger set, using defaults [junit4] 2> 2839868 INFO (jetty-launcher-9134-thread-2) [ ] o.e.j.= s.session node0 Scavenging every 600000ms [junit4] 2> 2839868 INFO (jetty-launcher-9134-thread-2) [ ] o.e.j.= s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7349e405{/solr,nul= l,AVAILABLE} [junit4] 2> 2839868 INFO (jetty-launcher-9134-thread-2) [ ] o.e.j.= s.AbstractConnector Started ServerConnector@4e02609{HTTP/1.1,[http/1.1]}{12= 7.0.0.1:45106} [junit4] 2> 2839868 INFO (jetty-launcher-9134-thread-2) [ ] o.e.j.= s.Server Started @2840039ms [junit4] 2> 2839868 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D45= 106} [junit4] 2> 2839869 ERROR (jetty-launcher-9134-thread-2) [ ] o.a.s.= u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be miss= ing or incomplete. [junit4] 2> 2839869 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLog= gerFactory [junit4] 2> 2839869 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= s.SolrDispatchFilter ___ _ Welcome to Apache Solr=E2=84=A2 vers= ion 7.4.0 [junit4] 2> 2839869 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2839869 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2839869 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-17T00:23:38.732Z [junit4] 2> 2839871 INFO (jetty-launcher-9134-thread-4) [ ] o.e.j.= s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2839871 INFO (jetty-launcher-9134-thread-4) [ ] o.e.j.= s.session No SessionScavenger set, using defaults [junit4] 2> 2839871 INFO (jetty-launcher-9134-thread-4) [ ] o.e.j.= s.session node0 Scavenging every 660000ms [junit4] 2> 2839871 INFO (jetty-launcher-9134-thread-4) [ ] o.e.j.= s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6aaa49c8{/solr,nul= l,AVAILABLE} [junit4] 2> 2839871 INFO (jetty-launcher-9134-thread-4) [ ] o.e.j.= s.AbstractConnector Started ServerConnector@68847ac1{HTTP/1.1,[http/1.1]}{1= 27.0.0.1:41962} [junit4] 2> 2839871 INFO (jetty-launcher-9134-thread-4) [ ] o.e.j.= s.Server Started @2840042ms [junit4] 2> 2839871 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D41= 962} [junit4] 2> 2839872 ERROR (jetty-launcher-9134-thread-4) [ ] o.a.s.= u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be miss= ing or incomplete. [junit4] 2> 2839872 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLog= gerFactory [junit4] 2> 2839872 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= s.SolrDispatchFilter ___ _ Welcome to Apache Solr=E2=84=A2 vers= ion 7.4.0 [junit4] 2> 2839872 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2839872 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2839872 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-17T00:23:38.735Z [junit4] 2> 2839873 INFO (zkConnectionManagerCallback-9139-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839874 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2839879 INFO (zkConnectionManagerCallback-9141-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839879 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2839883 INFO (jetty-launcher-9134-thread-5) [ ] o.e.j.= s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2839884 INFO (jetty-launcher-9134-thread-5) [ ] o.e.j.= s.session No SessionScavenger set, using defaults [junit4] 2> 2839884 INFO (jetty-launcher-9134-thread-5) [ ] o.e.j.= s.session node0 Scavenging every 600000ms [junit4] 2> 2839885 INFO (jetty-launcher-9134-thread-3) [ ] o.e.j.= s.session DefaultSessionIdManager workerName=3Dnode0 [junit4] 2> 2839885 INFO (jetty-launcher-9134-thread-3) [ ] o.e.j.= s.session No SessionScavenger set, using defaults [junit4] 2> 2839885 INFO (jetty-launcher-9134-thread-3) [ ] o.e.j.= s.session node0 Scavenging every 660000ms [junit4] 2> 2839885 INFO (jetty-launcher-9134-thread-3) [ ] o.e.j.= s.h.ContextHandler Started o.e.j.s.ServletContextHandler@385b1bb7{/solr,nul= l,AVAILABLE} [junit4] 2> 2839885 INFO (jetty-launcher-9134-thread-3) [ ] o.e.j.= s.AbstractConnector Started ServerConnector@788c5cb7{HTTP/1.1,[http/1.1]}{1= 27.0.0.1:56580} [junit4] 2> 2839885 INFO (jetty-launcher-9134-thread-3) [ ] o.e.j.= s.Server Started @2840056ms [junit4] 2> 2839885 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D56= 580} [junit4] 2> 2839886 ERROR (jetty-launcher-9134-thread-3) [ ] o.a.s.= u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be miss= ing or incomplete. [junit4] 2> 2839886 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLog= gerFactory [junit4] 2> 2839887 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= s.SolrDispatchFilter ___ _ Welcome to Apache Solr=E2=84=A2 vers= ion 7.4.0 [junit4] 2> 2839887 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2839887 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2839887 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-17T00:23:38.750Z [junit4] 2> 2839888 INFO (zkConnectionManagerCallback-9143-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839889 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2839895 INFO (jetty-launcher-9134-thread-1) [ ] o.a.s.= c.ZkContainer Zookeeper client=3D127.0.0.1:51535/solr [junit4] 2> 2839896 INFO (jetty-launcher-9134-thread-5) [ ] o.e.j.= s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5fe6036d{/solr,nul= l,AVAILABLE} [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.e.j.= s.AbstractConnector Started ServerConnector@5eaf8e9d{HTTP/1.1,[http/1.1]}{1= 27.0.0.1:47352} [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.e.j.= s.Server Started @2840068ms [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= c.s.e.JettySolrRunner Jetty properties: {hostContext=3D/solr, hostPort=3D47= 352} [junit4] 2> 2839897 ERROR (jetty-launcher-9134-thread-5) [ ] o.a.s.= u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be miss= ing or incomplete. [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLog= gerFactory [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= s.SolrDispatchFilter ___ _ Welcome to Apache Solr=E2=84=A2 vers= ion 7.4.0 [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2839897 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-05-17T00:23:38.760Z [junit4] 2> 2839899 INFO (zkConnectionManagerCallback-9149-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839905 INFO (jetty-launcher-9134-thread-4) [ ] o.a.s.= c.ZkContainer Zookeeper client=3D127.0.0.1:51535/solr [junit4] 2> 2839906 INFO (zkConnectionManagerCallback-9151-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839906 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2839912 INFO (zkConnectionManagerCallback-9146-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839912 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2839946 INFO (zkConnectionManagerCallback-9157-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839947 INFO (jetty-launcher-9134-thread-2) [ ] o.a.s.= c.ZkContainer Zookeeper client=3D127.0.0.1:51535/solr [junit4] 2> 2839951 INFO (jetty-launcher-9134-thread-5) [ ] o.a.s.= c.ZkContainer Zookeeper client=3D127.0.0.1:51535/solr [junit4] 2> 2839952 INFO (zkConnectionManagerCallback-9161-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2839955 INFO (zkConnectionManagerCallback-9153-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840004 INFO (jetty-launcher-9134-thread-3) [ ] o.a.s.= c.ZkContainer Zookeeper client=3D127.0.0.1:51535/solr [junit4] 2> 2840011 INFO (zkConnectionManagerCallback-9163-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840016 INFO (zkConnectionManagerCallback-9167-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840017 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessio= nid 0x1063b87224d000a, likely client has closed socket [junit4] 2> 2840022 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2840023 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader= 127.0.0.1:41962_solr [junit4] 2> 2840024 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.Overseer Overseer (id=3D73811895480287243-127.0.0.1= :41962_solr-n_0000000000) starting [junit4] 2> 2840056 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2840059 INFO (zkConnectionManagerCallback-9173-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840060 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/li= ve_nodes/127.0.0.1:55479_solr [junit4] 2> 2840062 INFO (zkConnectionManagerCallback-9182-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840063 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (1) [junit4] 2> 2840064 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0= .1:51535/solr ready [junit4] 2> 2840065 INFO (zkCallback-9152-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2840066 INFO (zkCallback-9162-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2840075 INFO (zkConnectionManagerCallback-9175-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840082 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (1) [junit4] 2> 2840084 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2840086 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient = cache for 2147483647 transient cores [junit4] 2> 2840086 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/li= ve_nodes/127.0.0.1:45106_solr [junit4] 2> 2840101 INFO (OverseerStateUpdate-73811895480287243-127.0= .0.1:41962_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updated live n= odes from ZooKeeper... (1) -> (2) [junit4] 2> 2840117 INFO (zkConnectionManagerCallback-9184-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840118 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient = cache for 2147483647 transient cores [junit4] 2> 2840118 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/li= ve_nodes/127.0.0.1:41962_solr [junit4] 2> 2840129 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (3) [junit4] 2> 2840131 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2840137 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient = cache for 2147483647 transient cores [junit4] 2> 2840137 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/li= ve_nodes/127.0.0.1:47352_solr [junit4] 2> 2840143 INFO (zkCallback-9152-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4) [junit4] 2> 2840143 INFO (zkCallback-9174-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4) [junit4] 2> 2840144 INFO (zkCallback-9162-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (4) [junit4] 2> 2840151 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 2840152 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 2840152 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 2840152 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Processed trigger updates upto znodeVersion 1 [junit4] 2> 2840174 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger= NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:55479_s= olr] [junit4] 2> 2840182 INFO (zkCallback-9181-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (4) [junit4] 2> 2840196 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2840204 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread -- clean old nodeAdded markers [junit4] 2> 2840204 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 2840212 INFO (zkConnectionManagerCallback-9186-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840212 DEBUG (ScheduledTrigger-8654-thread-2) [ ] o.a.= s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with curr= ently live nodes: 4 [junit4] 2> 2840219 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (4) [junit4] 2> 2840221 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 2840223 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient = cache for 2147483647 transient cores [junit4] 2> 2840223 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/li= ve_nodes/127.0.0.1:56580_solr [junit4] 2> 2840224 INFO (zkCallback-9152-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2840232 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2840232 INFO (zkCallback-9174-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2840232 INFO (zkCallback-9181-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2840257 INFO (zkCallback-9162-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2840258 INFO (zkCallback-9185-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2840367 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41962.so= lr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@70b84e7f [junit4] 2> 2840396 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41962.so= lr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@70b84e7f [junit4] 2> 2840396 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41962.so= lr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserve= r.JmxMBeanServer@70b84e7f [junit4] 2> 2840398 INFO (jetty-launcher-9134-thread-4) [n:127.0.0.1:= 41962_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions unde= rneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build= /solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateTriggerIntegration= Test_3E05F21542EA0DDC-001/tempDir-001/node4/. [junit4] 2> 2840568 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45106.so= lr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@70b84e7f [junit4] 2> 2840581 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55479.so= lr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@70b84e7f [junit4] 2> 2840608 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55479.so= lr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@70b84e7f [junit4] 2> 2840608 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55479.so= lr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserve= r.JmxMBeanServer@70b84e7f [junit4] 2> 2840609 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions unde= rneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build= /solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateTriggerIntegration= Test_3E05F21542EA0DDC-001/tempDir-001/node1/. [junit4] 2> 2840610 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45106.so= lr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@70b84e7f [junit4] 2> 2840610 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45106.so= lr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserve= r.JmxMBeanServer@70b84e7f [junit4] 2> 2840611 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions unde= rneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build= /solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateTriggerIntegration= Test_3E05F21542EA0DDC-001/tempDir-001/node2/. [junit4] 2> 2840665 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_47352.so= lr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@70b84e7f [junit4] 2> 2840677 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_47352.so= lr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@70b84e7f [junit4] 2> 2840678 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_47352.so= lr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserve= r.JmxMBeanServer@70b84e7f [junit4] 2> 2840679 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions unde= rneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build= /solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateTriggerIntegration= Test_3E05F21542EA0DDC-001/tempDir-001/node5/. [junit4] 2> 2840687 INFO (zkConnectionManagerCallback-9197-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840688 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (5) [junit4] 2> 2840689 INFO (jetty-launcher-9134-thread-1) [n:127.0.0.1:= 55479_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0= .1:51535/solr ready [junit4] 2> 2840694 INFO (zkConnectionManagerCallback-9202-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840695 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (5) [junit4] 2> 2840696 INFO (jetty-launcher-9134-thread-2) [n:127.0.0.1:= 45106_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0= .1:51535/solr ready [junit4] 2> 2840728 INFO (zkConnectionManagerCallback-9207-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840729 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (5) [junit4] 2> 2840730 INFO (jetty-launcher-9134-thread-5) [n:127.0.0.1:= 47352_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0= .1:51535/solr ready [junit4] 2> 2840746 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56580.so= lr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@70b84e7f [junit4] 2> 2840758 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56580.so= lr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.Jm= xMBeanServer@70b84e7f [junit4] 2> 2840758 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_56580.so= lr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserve= r.JmxMBeanServer@70b84e7f [junit4] 2> 2840760 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions unde= rneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build= /solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateTriggerIntegration= Test_3E05F21542EA0DDC-001/tempDir-001/node3/. [junit4] 2> 2840764 INFO (zkConnectionManagerCallback-9212-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840765 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper..= . (0) -> (5) [junit4] 2> 2840766 INFO (jetty-launcher-9134-thread-3) [n:127.0.0.1:= 56580_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0= .1:51535/solr ready [junit4] 2> 2840900 INFO (zkConnectionManagerCallback-9214-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840904 INFO (zkConnectionManagerCallback-9219-thread-1) = [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2840905 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nod= es from ZooKeeper... (0) -> (5) [junit4] 2> 2840906 INFO (SUITE-SearchRateTriggerIntegrationTest-seed= #[3E05F21542EA0DDC]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider= Cluster at 127.0.0.1:51535/solr ready [junit4] 2> 2840912 INFO (qtp383890381-29308) [n:127.0.0.1:41962_solr= ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/metrics para= ms=3D{prefix=3DCONTAINER.fs.usableSpace,CORE.coreName&wt=3Djavabin&version= =3D2&group=3Dsolr.node,solr.core} status=3D0 QTime=3D0 [junit4] 2> 2840914 INFO (qtp819115919-29302) [n:127.0.0.1:45106_solr= ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/metrics para= ms=3D{prefix=3DCONTAINER.fs.usableSpace,CORE.coreName&wt=3Djavabin&version= =3D2&group=3Dsolr.node,solr.core} status=3D0 QTime=3D0 [junit4] 2> 2840915 INFO (qtp38137509-29327) [n:127.0.0.1:47352_solr = ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/metrics param= s=3D{prefix=3DCONTAINER.fs.usableSpace,CORE.coreName&wt=3Djavabin&version= =3D2&group=3Dsolr.node,solr.core} status=3D0 QTime=3D0 [junit4] 2> 2840917 INFO (qtp1926686775-29292) [n:127.0.0.1:55479_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/metrics par= ams=3D{prefix=3DCONTAINER.fs.usableSpace,CORE.coreName&wt=3Djavabin&version= =3D2&group=3Dsolr.node,solr.core} status=3D0 QTime=3D0 [junit4] 2> 2840918 INFO (qtp1748060497-29332) [n:127.0.0.1:56580_sol= r ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/metrics par= ams=3D{prefix=3DCONTAINER.fs.usableSpace,CORE.coreName&wt=3Djavabin&version= =3D2&group=3Dsolr.node,solr.core} status=3D0 QTime=3D0 [junit4] 2> 2840918 DEBUG (qtp383890381-29313) [n:127.0.0.1:41962_solr= ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2840919 INFO (qtp383890381-29313) [n:127.0.0.1:41962_solr= ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/cluster/autoscalin= g params=3D{wt=3Djavabin&version=3D2} status=3D0 QTime=3D8 [junit4] 2> 2840921 DEBUG (zkCallback-9181-thread-1) [ ] o.a.s.c.a.= OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 2840922 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Processed trigger updates upto znodeVersion 2 [junit4] 2> 2840924 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread -- clean old nodeAdded markers [junit4] 2> 2840924 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 2840988 INFO (TEST-SearchRateTriggerIntegrationTest.testB= elowSearchRate-seed#[3E05F21542EA0DDC]) [ ] o.a.s.SolrTestCaseJ4 ###Star= ting testBelowSearchRate [junit4] 2> 2840989 INFO (TEST-SearchRateTriggerIntegrationTest.testB= elowSearchRate-seed#[3E05F21542EA0DDC]) [ ] o.a.s.c.c.ZkStateReader Upda= ted live nodes from ZooKeeper... (0) -> (5) [junit4] 2> 2840991 INFO (TEST-SearchRateTriggerIntegrationTest.testB= elowSearchRate-seed#[3E05F21542EA0DDC]) [ ] o.a.s.c.a.SearchRateTriggerI= ntegrationTest /autoscaling.json reset, new znode version 3 [junit4] 2> 2840991 DEBUG (zkCallback-9181-thread-1) [ ] o.a.s.c.a.= OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 2840991 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Processed trigger updates upto znodeVersion 3 [junit4] 2> 2840993 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread -- clean old nodeLost markers [junit4] 2> 2840994 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread -- clean old nodeAdded markers [junit4] 2> 2840994 DEBUG (OverseerAutoScalingTriggerThread-7381189548= 0287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTrigger= Thread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 2845998 INFO (qtp819115919-29285) [n:127.0.0.1:45106_solr= ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with p= arams replicationFactor=3D2&collection.configName=3Dconf&name=3DbelowRate_c= ollection&nrtReplicas=3D2&action=3DCREATE&numShards=3D1&wt=3Djavabin&versio= n=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2846001 INFO (OverseerThreadFactory-8656-thread-1) [ ]= o.a.s.c.a.c.CreateCollectionCmd Create collection belowRate_collection [junit4] 2> 2846114 INFO (OverseerStateUpdate-73811895480287243-127.0= .0.1:41962_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica()= { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"belowRate_collection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"belowRate_collection_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:47352/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 2846118 INFO (OverseerStateUpdate-73811895480287243-127.0= .0.1:41962_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica()= { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"belowRate_collection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"belowRate_collection_shard1_replica_n3", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:41962/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"}=20 [junit4] 2> 2846321 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = x:belowRate_collection_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation c= ore create command qt=3D/admin/cores&coreNodeName=3Dcore_node2&collection.c= onfigName=3Dconf&newCollection=3Dtrue&name=3DbelowRate_collection_shard1_re= plica_n1&action=3DCREATE&numShards=3D1&collection=3DbelowRate_collection&sh= ard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DNRT [junit4] 2> 2846321 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= x:belowRate_collection_shard1_replica_n3] o.a.s.h.a.CoreAdminOperation = core create command qt=3D/admin/cores&coreNodeName=3Dcore_node4&collection.= configName=3Dconf&newCollection=3Dtrue&name=3DbelowRate_collection_shard1_r= eplica_n3&action=3DCREATE&numShards=3D1&collection=3DbelowRate_collection&s= hard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DNRT [junit4] 2> 2847335 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0 [junit4] 2> 2847335 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0 [junit4] 2> 2847348 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.s.IndexSchema [belowRate_collection_shard1_replica_n3] S= chema name=3Dminimal [junit4] 2> 2847366 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.s.IndexSchema [belowRate_collection_shard1_replica_n1] Sc= hema name=3Dminimal [junit4] 2> 2847369 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid fie= ld id [junit4] 2> 2847369 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'belowRate_collection_s= hard1_replica_n1' using configuration from collection belowRate_collection,= trusted=3Dtrue [junit4] 2> 2847370 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_47352.solr.c= ore.belowRate_collection.shard1.replica_n1' (registry 'solr.core.belowRate_= collection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.J= mxMBeanServer@70b84e7f [junit4] 2> 2847370 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2847370 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.SolrCore [[belowRate_collection_shard1_replica_n1] ] Op= ening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Test= s-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateTr= iggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node5/belowRate_colle= ction_shard1_replica_n1], dataDir=3D[/x1/jenkins/jenkins-slave/workspace/Lu= cene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscalin= g.SearchRateTriggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node5/.= /belowRate_collection_shard1_replica_n1/data/] [junit4] 2> 2847375 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid fi= eld id [junit4] 2> 2847375 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.c.CoreContainer Creating SolrCore 'belowRate_collection_= shard1_replica_n3' using configuration from collection belowRate_collection= , trusted=3Dtrue [junit4] 2> 2847376 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41962.solr.= core.belowRate_collection.shard1.replica_n3' (registry 'solr.core.belowRate= _collection.shard1.replica_n3') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@70b84e7f [junit4] 2> 2847376 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2847376 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.c.SolrCore [[belowRate_collection_shard1_replica_n3] ] O= pening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tes= ts-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateT= riggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node4/belowRate_coll= ection_shard1_replica_n3], dataDir=3D[/x1/jenkins/jenkins-slave/workspace/L= ucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscali= ng.SearchRateTriggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node4/= ./belowRate_collection_shard1_replica_n3/data/] [junit4] 2> 2847476 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apac= he.solr.update.UpdateLog [junit4] 2> 2847476 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull defau= ltSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersion= Buckets=3D65536 [junit4] 2> 2847477 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2847478 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2847478 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apach= e.solr.update.UpdateLog [junit4] 2> 2847478 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull defaul= tSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionB= uckets=3D65536 [junit4] 2> 2847479 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2847479 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2847479 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.s.SolrIndexSearcher Opening [Searcher@3fc34de5[belowRate= _collection_shard1_replica_n3] main] [junit4] 2> 2847481 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@62322bba[belowRate_= collection_shard1_replica_n1] main] [junit4] 2> 2847481 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO w= ith znodeBase: /configs/conf [junit4] 2> 2847482 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_manag= ed.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 2847483 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO wi= th znodeBase: /configs/conf [junit4] 2> 2847483 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_manage= d.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 2847483 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.h.ReplicationHandler Commits will be reserved for 10000m= s. [junit4] 2> 2847484 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms= . [junit4] 2> 2847484 INFO (searcherExecutor-8668-thread-1-processing-n= :127.0.0.1:41962_solr x:belowRate_collection_shard1_replica_n3 c:belowRate_= collection s:shard1 r:core_node4) [n:127.0.0.1:41962_solr c:belowRate_colle= ction s:shard1 r:core_node4 x:belowRate_collection_shard1_replica_n3] o.a.s= .c.SolrCore [belowRate_collection_shard1_replica_n3] Registered new searche= r Searcher@3fc34de5[belowRate_collection_shard1_replica_n3] main{ExitableDi= rectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2847484 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent= updates, using new clock 1600668697988431872 [junit4] 2> 2847484 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.u.UpdateLog Could not find max version in index or recen= t updates, using new clock 1600668697988431872 [junit4] 2> 2847487 INFO (searcherExecutor-8667-thread-1-processing-n= :127.0.0.1:47352_solr x:belowRate_collection_shard1_replica_n1 c:belowRate_= collection s:shard1 r:core_node2) [n:127.0.0.1:47352_solr c:belowRate_colle= ction s:shard1 r:core_node2 x:belowRate_collection_shard1_replica_n1] o.a.s= .c.SolrCore [belowRate_collection_shard1_replica_n1] Registered new searche= r Searcher@62322bba[belowRate_collection_shard1_replica_n1] main{ExitableDi= rectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2847492 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections= /belowRate_collection/terms/shard1 to Terms{values=3D{core_node2=3D0}, vers= ion=3D0} [junit4] 2> 2847495 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.c.ZkShardTerms Successful update of terms at /collection= s/belowRate_collection/terms/shard1 to Terms{values=3D{core_node2=3D0, core= _node4=3D0}, version=3D1} [junit4] 2> 2847499 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to con= tinue. [junit4] 2> 2847499 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - tr= y and sync [junit4] 2> 2847499 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:47352/so= lr/belowRate_collection_shard1_replica_n1/ [junit4] 2> 2847499 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.u.PeerSync PeerSync: core=3DbelowRate_collection_shard1_r= eplica_n1 url=3Dhttp://127.0.0.1:47352/solr START replicas=3D[http://127.0.= 0.1:41962/solr/belowRate_collection_shard1_replica_n3/] nUpdates=3D100 [junit4] 2> 2847502 INFO (qtp383890381-29312) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.c.S.Request [belowRate_collection_shard1_replica_n3] we= bapp=3D/solr path=3D/get params=3D{distrib=3Dfalse&qt=3D/get&fingerprint=3D= false&getVersions=3D100&wt=3Djavabin&version=3D2} status=3D0 QTime=3D0 [junit4] 2> 2847800 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.u.PeerSync PeerSync: core=3DbelowRate_collection_shard1_r= eplica_n1 url=3Dhttp://127.0.0.1:47352/solr DONE. We have no versions. sy= nc failed. [junit4] 2> 2847800 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed= , moving to the next candidate [junit4] 2> 2847800 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have = no versions - we can't sync in that case - we were active before, so become= leader anyway [junit4] 2> 2847800 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participa= ting in election, clear LIR [junit4] 2> 2847804 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://= 127.0.0.1:47352/solr/belowRate_collection_shard1_replica_n1/ shard1 [junit4] 2> 2847906 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2847909 INFO (qtp38137509-29320) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores = params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node2&collection.configName= =3Dconf&newCollection=3Dtrue&name=3DbelowRate_collection_shard1_replica_n1&= action=3DCREATE&numShards=3D1&collection=3DbelowRate_collection&shard=3Dsha= rd1&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D0 QTime=3D1588 [junit4] 2> 2848009 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2848501 INFO (qtp383890381-29309) [n:127.0.0.1:41962_solr= c:belowRate_collection s:shard1 r:core_node4 x:belowRate_collection_shard1= _replica_n3] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores= params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node4&collection.configNam= e=3Dconf&newCollection=3Dtrue&name=3DbelowRate_collection_shard1_replica_n3= &action=3DCREATE&numShards=3D1&collection=3DbelowRate_collection&shard=3Dsh= ard1&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D0 QTime=3D2180 [junit4] 2> 2848504 INFO (qtp819115919-29285) [n:127.0.0.1:45106_solr= ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for= at most 30 seconds. Check all shard replicas [junit4] 2> 2848506 INFO (OverseerCollectionConfigSetProcessor-738118= 95480287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQ= ueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn= 't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 2848602 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2848602 INFO (zkCallback-9162-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2849505 INFO (qtp819115919-29285) [n:127.0.0.1:45106_solr= ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/collections = params=3D{replicationFactor=3D2&collection.configName=3Dconf&name=3DbelowRa= te_collection&nrtReplicas=3D2&action=3DCREATE&numShards=3D1&wt=3Djavabin&ve= rsion=3D2} status=3D0 QTime=3D3506 [junit4] 2> 2849506 INFO (qtp819115919-29301) [n:127.0.0.1:45106_solr= ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica wi= th params action=3DADDREPLICA&collection=3DbelowRate_collection&shard=3Dsha= rd1&type=3DNRT&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2849511 INFO (OverseerThreadFactory-8656-thread-2) [ c:be= lowRate_collection s:shard1 ] o.a.s.c.a.c.AddReplicaCmd Node Identified 12= 7.0.0.1:45106_solr for creating new replica [junit4] 2> 2849515 INFO (OverseerStateUpdate-73811895480287243-127.0= .0.1:41962_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica()= { [junit4] 2> "operation":"addreplica", [junit4] 2> "collection":"belowRate_collection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"belowRate_collection_shard1_replica_n5", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:45106/solr", [junit4] 2> "node_name":"127.0.0.1:45106_solr", [junit4] 2> "type":"NRT"}=20 [junit4] 2> 2849617 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2849618 INFO (zkCallback-9162-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2849717 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= x:belowRate_collection_shard1_replica_n5] o.a.s.h.a.CoreAdminOperation = core create command qt=3D/admin/cores&coreNodeName=3Dcore_node6&collection.= configName=3Dconf&name=3DbelowRate_collection_shard1_replica_n5&action=3DCR= EATE&collection=3DbelowRate_collection&shard=3Dshard1&wt=3Djavabin&version= =3D2&replicaType=3DNRT [junit4] 2> 2849731 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0 [junit4] 2> 2849739 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.s.IndexSchema [belowRate_collection_shard1_replica_n5] S= chema name=3Dminimal [junit4] 2> 2849742 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid fi= eld id [junit4] 2> 2849742 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.c.CoreContainer Creating SolrCore 'belowRate_collection_= shard1_replica_n5' using configuration from collection belowRate_collection= , trusted=3Dtrue [junit4] 2> 2849742 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45106.solr.= core.belowRate_collection.shard1.replica_n5' (registry 'solr.core.belowRate= _collection.shard1.replica_n5') enabled at server: com.sun.jmx.mbeanserver.= JmxMBeanServer@70b84e7f [junit4] 2> 2849742 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2849742 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.c.SolrCore [[belowRate_collection_shard1_replica_n5] ] O= pening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tes= ts-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRateT= riggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node2/belowRate_coll= ection_shard1_replica_n5], dataDir=3D[/x1/jenkins/jenkins-slave/workspace/L= ucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscali= ng.SearchRateTriggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node2/= ./belowRate_collection_shard1_replica_n5/data/] [junit4] 2> 2849810 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apac= he.solr.update.UpdateLog [junit4] 2> 2849810 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull defau= ltSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersion= Buckets=3D65536 [junit4] 2> 2849812 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2849812 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2849814 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.s.SolrIndexSearcher Opening [Searcher@69025bdd[belowRate= _collection_shard1_replica_n5] main] [junit4] 2> 2849815 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO w= ith znodeBase: /configs/conf [junit4] 2> 2849816 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_manag= ed.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 2849817 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.h.ReplicationHandler Commits will be reserved for 10000m= s. [junit4] 2> 2849817 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.u.UpdateLog Could not find max version in index or recen= t updates, using new clock 1600668700434759680 [junit4] 2> 2849819 INFO (searcherExecutor-8677-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .c.SolrCore [belowRate_collection_shard1_replica_n5] Registered new searche= r Searcher@69025bdd[belowRate_collection_shard1_replica_n5] main{ExitableDi= rectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2849825 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2849825 INFO (zkCallback-9162-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2849825 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.c.ZkShardTerms Successful update of terms at /collection= s/belowRate_collection/terms/shard1 to Terms{values=3D{core_node2=3D0, core= _node6=3D0, core_node4=3D0}, version=3D2} [junit4] 2> 2849829 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.c.ZkController Core needs to recover:belowRate_collectio= n_shard1_replica_n5 [junit4] 2> 2849829 INFO (updateExecutor-9158-thread-1-processing-n:1= 27.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_co= llection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_collect= ion s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s.u= .DefaultSolrCoreState Running recovery [junit4] 2> 2849829 INFO (recoveryExecutor-9159-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=3Dtru= e [junit4] 2> 2849830 INFO (recoveryExecutor-9159-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .c.RecoveryStrategy ###### startupVersions=3D[[]] [junit4] 2> 2849831 INFO (qtp819115919-29298) [n:127.0.0.1:45106_solr= c:belowRate_collection s:shard1 r:core_node6 x:belowRate_collection_shard1= _replica_n5] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/cores= params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node6&collection.configNam= e=3Dconf&name=3DbelowRate_collection_shard1_replica_n5&action=3DCREATE&coll= ection=3DbelowRate_collection&shard=3Dshard1&wt=3Djavabin&version=3D2&repli= caType=3DNRT} status=3D0 QTime=3D113 [junit4] 2> 2849833 INFO (qtp38137509-29322) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.S.Request [belowRate_collection_shard1_replica_n1] web= app=3D/solr path=3D/admin/ping params=3D{wt=3Djavabin&version=3D2} hits=3D0= status=3D0 QTime=3D0 [junit4] 2> 2849833 INFO (qtp38137509-29322) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.S.Request [belowRate_collection_shard1_replica_n1] web= app=3D/solr path=3D/admin/ping params=3D{wt=3Djavabin&version=3D2} status= =3D0 QTime=3D0 [junit4] 2> 2849833 INFO (recoveryExecutor-9159-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .c.RecoveryStrategy Begin buffering updates. core=3D[belowRate_collection_s= hard1_replica_n5] [junit4] 2> 2849833 INFO (recoveryExecutor-9159-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .u.UpdateLog Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4] 2> 2849833 INFO (recoveryExecutor-9159-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .c.RecoveryStrategy Publishing state of core [belowRate_collection_shard1_r= eplica_n5] as recovering, leader is [http://127.0.0.1:47352/solr/belowRate_= collection_shard1_replica_n1/] and I am [http://127.0.0.1:45106/solr/belowR= ate_collection_shard1_replica_n5/] [junit4] 2> 2849835 INFO (qtp819115919-29301) [n:127.0.0.1:45106_solr= c:belowRate_collection ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path= =3D/admin/collections params=3D{action=3DADDREPLICA&collection=3DbelowRate_= collection&shard=3Dshard1&type=3DNRT&wt=3Djavabin&version=3D2} status=3D0 Q= Time=3D328 [junit4] 2> 2849836 INFO (qtp819115919-29304) [n:127.0.0.1:45106_solr= ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica wi= th params action=3DADDREPLICA&collection=3DbelowRate_collection&shard=3Dsha= rd1&type=3DTLOG&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2849836 INFO (recoveryExecutor-9159-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .c.ZkShardTerms Successful update of terms at /collections/belowRate_collec= tion/terms/shard1 to Terms{values=3D{core_node6=3D0, core_node6_recovering= =3D0, core_node2=3D0, core_node4=3D0}, version=3D3} [junit4] 2> 2849839 INFO (recoveryExecutor-9159-thread-1-processing-n= :127.0.0.1:45106_solr x:belowRate_collection_shard1_replica_n5 c:belowRate_= collection s:shard1 r:core_node6) [n:127.0.0.1:45106_solr c:belowRate_colle= ction s:shard1 r:core_node6 x:belowRate_collection_shard1_replica_n5] o.a.s= .c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:4735= 2/solr]; [WaitForState: action=3DPREPRECOVERY&core=3DbelowRate_collection_s= hard1_replica_n1&nodeName=3D127.0.0.1:45106_solr&coreNodeName=3Dcore_node6&= state=3Drecovering&checkLive=3Dtrue&onlyIfLeader=3Dtrue&onlyIfLeaderActive= =3Dtrue] [junit4] 2> 2849840 INFO (qtp38137509-29325) [n:127.0.0.1:47352_solr = x:belowRate_collection_shard1_replica_n1] o.a.s.h.a.PrepRecoveryOp Going= to wait for coreNodeName: core_node6, state: recovering, checkLive: true, = onlyIfLeader: true, onlyIfLeaderActive: true, maxTime: 183 s [junit4] 2> 2849840 INFO (qtp38137509-29325) [n:127.0.0.1:47352_solr = x:belowRate_collection_shard1_replica_n1] o.a.s.h.a.PrepRecoveryOp In Wa= itForState(recovering): collection=3DbelowRate_collection, shard=3Dshard1, = thisCore=3DbelowRate_collection_shard1_replica_n1, leaderDoesNotNeedRecover= y=3Dfalse, isLeader? true, live=3Dtrue, checkLive=3Dtrue, currentState=3Ddo= wn, localState=3Dactive, nodeName=3D127.0.0.1:45106_solr, coreNodeName=3Dco= re_node6, onlyIfActiveCheckResult=3Dfalse, nodeProps: core_node6:{"core":"b= elowRate_collection_shard1_replica_n5","base_url":"http://127.0.0.1:45106/s= olr","node_name":"127.0.0.1:45106_solr","state":"down","type":"NRT","force_= set_state":"false"} [junit4] 2> 2849842 INFO (OverseerCollectionConfigSetProcessor-738118= 95480287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQ= ueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn= 't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 2849843 INFO (OverseerThreadFactory-8656-thread-3) [ c:be= lowRate_collection s:shard1 ] o.a.s.c.a.c.AddReplicaCmd Node Identified 12= 7.0.0.1:55479_solr for creating new replica [junit4] 2> 2849846 INFO (OverseerStateUpdate-73811895480287243-127.0= .0.1:41962_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica()= { [junit4] 2> "operation":"addreplica", [junit4] 2> "collection":"belowRate_collection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"belowRate_collection_shard1_replica_t7", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:55479/solr", [junit4] 2> "node_name":"127.0.0.1:55479_solr", [junit4] 2> "type":"TLOG"}=20 [junit4] 2> 2849947 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2849947 INFO (zkCallback-9174-thread-2) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2849948 INFO (zkCallback-9162-thread-3) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2850048 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r x:belowRate_collection_shard1_replica_t7] o.a.s.h.a.CoreAdminOperation= core create command qt=3D/admin/cores&coreNodeName=3Dcore_node8&collection= .configName=3Dconf&name=3DbelowRate_collection_shard1_replica_t7&action=3DC= REATE&collection=3DbelowRate_collection&shard=3Dshard1&wt=3Djavabin&version= =3D2&replicaType=3DTLOG [junit4] 2> 2850048 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r x:belowRate_collection_shard1_replica_t7] o.a.s.c.TransientSolrCoreCac= heDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2850060 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0 [junit4] 2> 2850067 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.s.IndexSchema [belowRate_collection_shard1_replica_t7] = Schema name=3Dminimal [junit4] 2> 2850070 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid f= ield id [junit4] 2> 2850070 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.c.CoreContainer Creating SolrCore 'belowRate_collection= _shard1_replica_t7' using configuration from collection belowRate_collectio= n, trusted=3Dtrue [junit4] 2> 2850071 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_55479.solr= .core.belowRate_collection.shard1.replica_t7' (registry 'solr.core.belowRat= e_collection.shard1.replica_t7') enabled at server: com.sun.jmx.mbeanserver= .JmxMBeanServer@70b84e7f [junit4] 2> 2850071 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2850071 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.c.SolrCore [[belowRate_collection_shard1_replica_t7] ] = Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Te= sts-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.SearchRate= TriggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node1/belowRate_col= lection_shard1_replica_t7], dataDir=3D[/x1/jenkins/jenkins-slave/workspace/= Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscal= ing.SearchRateTriggerIntegrationTest_3E05F21542EA0DDC-001/tempDir-001/node1= /./belowRate_collection_shard1_replica_t7/data/] [junit4] 2> 2850152 INFO (zkCallback-9162-thread-3) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2850152 INFO (zkCallback-9183-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2850152 INFO (zkCallback-9174-thread-2) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/belowRate_collection/state.json] for co= llection [belowRate_collection] has occurred - updating... (live nodes size= : [5]) [junit4] 2> 2850165 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apa= che.solr.update.UpdateLog [junit4] 2> 2850165 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=3Dnull defa= ultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersio= nBuckets=3D65536 [junit4] 2> 2850166 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2850166 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2850168 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.s.SolrIndexSearcher Opening [Searcher@44dffc8a[belowRat= e_collection_shard1_replica_t7] main] [junit4] 2> 2850170 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO = with znodeBase: /configs/conf [junit4] 2> 2850170 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_mana= ged.json using ZooKeeperStorageIO:path=3D/configs/conf [junit4] 2> 2850171 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.h.ReplicationHandler Commits will be reserved for 10000= ms. [junit4] 2> 2850172 INFO (searcherExecutor-8682-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.SolrCore [belowRate_collection_shard1_replica_t7] Registered new searche= r Searcher@44dffc8a[belowRate_collection_shard1_replica_t7] main{ExitableDi= rectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2850172 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.u.UpdateLog Could not find max version in index or rece= nt updates, using new clock 1600668700807004160 [junit4] 2> 2850178 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.c.ZkShardTerms Successful update of terms at /collectio= ns/belowRate_collection/terms/shard1 to Terms{values=3D{core_node6=3D0, cor= e_node8=3D0, core_node6_recovering=3D0, core_node2=3D0, core_node4=3D0}, ve= rsion=3D4} [junit4] 2> 2850180 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.c.ZkController Core needs to recover:belowRate_collecti= on_shard1_replica_t7 [junit4] 2> 2850181 INFO (updateExecutor-9144-thread-1-processing-n:1= 27.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_co= llection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_collect= ion s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s.u= .DefaultSolrCoreState Running recovery [junit4] 2> 2850181 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=3Dtru= e [junit4] 2> 2850184 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.RecoveryStrategy ###### startupVersions=3D[[]] [junit4] 2> 2850184 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.ZkController belowRate_collection_shard1_replica_t7 stopping background = replication from leader [junit4] 2> 2850185 INFO (qtp1926686775-29286) [n:127.0.0.1:55479_sol= r c:belowRate_collection s:shard1 r:core_node8 x:belowRate_collection_shard= 1_replica_t7] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path=3D/admin/core= s params=3D{qt=3D/admin/cores&coreNodeName=3Dcore_node8&collection.configNa= me=3Dconf&name=3DbelowRate_collection_shard1_replica_t7&action=3DCREATE&col= lection=3DbelowRate_collection&shard=3Dshard1&wt=3Djavabin&version=3D2&repl= icaType=3DTLOG} status=3D0 QTime=3D137 [junit4] 2> 2850189 INFO (qtp38137509-29322) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.S.Request [belowRate_collection_shard1_replica_n1] web= app=3D/solr path=3D/admin/ping params=3D{wt=3Djavabin&version=3D2} hits=3D0= status=3D0 QTime=3D0 [junit4] 2> 2850190 INFO (qtp38137509-29322) [n:127.0.0.1:47352_solr = c:belowRate_collection s:shard1 r:core_node2 x:belowRate_collection_shard1_= replica_n1] o.a.s.c.S.Request [belowRate_collection_shard1_replica_n1] web= app=3D/solr path=3D/admin/ping params=3D{wt=3Djavabin&version=3D2} status= =3D0 QTime=3D0 [junit4] 2> 2850190 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.RecoveryStrategy Begin buffering updates. core=3D[belowRate_collection_s= hard1_replica_t7] [junit4] 2> 2850190 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .u.UpdateLog Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4] 2> 2850190 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.RecoveryStrategy Publishing state of core [belowRate_collection_shard1_r= eplica_t7] as recovering, leader is [http://127.0.0.1:47352/solr/belowRate_= collection_shard1_replica_n1/] and I am [http://127.0.0.1:55479/solr/belowR= ate_collection_shard1_replica_t7/] [junit4] 2> 2850191 INFO (qtp819115919-29304) [n:127.0.0.1:45106_solr= c:belowRate_collection ] o.a.s.s.HttpSolrCall [admin] webapp=3Dnull path= =3D/admin/collections params=3D{action=3DADDREPLICA&collection=3DbelowRate_= collection&shard=3Dshard1&type=3DTLOG&wt=3Djavabin&version=3D2} status=3D0 = QTime=3D355 [junit4] 2> 2850192 INFO (qtp819115919-29301) [n:127.0.0.1:45106_solr= ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica wi= th params action=3DADDREPLICA&collection=3DbelowRate_collection&shard=3Dsha= rd1&type=3DPULL&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 2850193 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.ZkShardTerms Successful update of terms at /collections/belowRate_collec= tion/terms/shard1 to Terms{values=3D{core_node6=3D0, core_node8_recovering= =3D0, core_node8=3D0, core_node6_recovering=3D0, core_node2=3D0, core_node4= =3D0}, version=3D5} [junit4] 2> 2850195 INFO (recoveryExecutor-9147-thread-1-processing-n= :127.0.0.1:55479_solr x:belowRate_collection_shard1_replica_t7 c:belowRate_= collection s:shard1 r:core_node8) [n:127.0.0.1:55479_solr c:belowRate_colle= ction s:shard1 r:core_node8 x:belowRate_collection_shard1_replica_t7] o.a.s= .c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:4735= 2/solr]; [WaitForState: action=3DPREPRECOVERY&core=3DbelowRate_collection_s= hard1_replica_n1&nodeName=3D127.0.0.1:55479_solr&coreNodeName=3Dcore_node8&= state=3Drecovering&checkLive=3Dtrue&onlyIfLeader=3Dtrue&onlyIfLeaderActive= =3Dtrue] [junit4] 2> 2850200 INFO (qtp38137509-29326) [n:127.0.0.1:47352_solr = x:belowRate_collection_shard1_replica_n1] o.a.s.h.a.PrepRecoveryOp Going= to wait for coreNodeName: core_node8, state: recovering, checkLive: true, = onlyIfLeader: true, onlyIfLeaderActive: true, maxTime: 183 s [junit4] 2> 2850200 INFO (qtp38137509-29326) [n:127.0.0.1:47352_solr = x:belowRate_collection_shard1_replica_n1] o.a.s.h.a.PrepRecoveryOp In Wa= itForState(recovering): collection=3DbelowRate_collection, shard=3Dshard1, = thisCore=3DbelowRate_collection_shard1_replica_n1, leaderDoesNotNeedRecover= y=3Dfalse, isLeader? true, live=3Dtrue, checkLive=3Dtrue, currentState=3Ddo= wn, localState=3Dactive, nodeName=3D127.0.0.1:55479_solr, coreNodeName=3Dco= re_node8, onlyIfActiveCheckResult=3Dfalse, nodeProps: core_node8:{"core":"b= elowRate_collection_shard1_replica_t7","base_url":"http://127.0.0.1:55479/s= olr","node_name":"127.0.0.1:55479_solr","state":"down","type":"TLOG","force= _set_state":"false"} [junit4] 2> 2850207 INFO (OverseerCollectionConfigSetProcessor-738118= 95480287243-127.0.0.1:41962_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskQ= ueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn= 't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 2850213 INFO (OverseerThreadFactory-8656-thread-4) [ c:be= lowRate_collection s:shard1 ] o.a.s.c.a.c.AddReplicaCmd Node Identified 12= 7.0.0.1:56580_solr for creating new replica [junit4] 2> 2850217 INFO (OverseerStateUpdate-73811895480287243-127.0= .0.1:41962_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica()= { [junit4] 2> "operation":"addreplica", [junit4] 2> "collection":"belowRate_collection", [junit4] 2> "shard":"shard1", [junit4] 2> "core":"belowRate_co [...truncated too long message...] y-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: jar-checksums: [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Te= sts-7.x/lucene/null1292292988 [copy] Copying 39 files to /x1/jenkins/jenkins-slave/workspace/Lucene-= Solr-Tests-7.x/lucene/null1292292988 [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-S= olr-Tests-7.x/lucene/null1292292988 resolve-example: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: resolve-server: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length i= s 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file =3D /x1/jenkins/jenkins-slave/w= orkspace/Lucene-Solr-Tests-7.x/lucene/top-level-ivy-settings.xml resolve: jar-checksums: [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Te= sts-7.x/solr/null52612863 [copy] Copying 246 files to /x1/jenkins/jenkins-slave/workspace/Lucene= -Solr-Tests-7.x/solr/null52612863 [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-S= olr-Tests-7.x/solr/null52612863 check-working-copy: [ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.j= git-caller;working [ivy:cachepath] =09confs: [default] [ivy:cachepath] =09found org.eclipse.jgit#org.eclipse.jgit;4.6.0.2016122319= 35-r in public [ivy:cachepath] =09found com.jcraft#jsch;0.1.53 in public [ivy:cachepath] =09found com.googlecode.javaewah#JavaEWAH;1.1.6 in public [ivy:cachepath] =09found org.apache.httpcomponents#httpclient;4.3.6 in publ= ic [ivy:cachepath] =09found org.apache.httpcomponents#httpcore;4.3.3 in public [ivy:cachepath] =09found commons-logging#commons-logging;1.1.3 in public [ivy:cachepath] =09found commons-codec#commons-codec;1.6 in public [ivy:cachepath] =09found org.slf4j#slf4j-api;1.7.2 in public [ivy:cachepath] :: resolution report :: resolve 64ms :: artifacts dl 6ms =09--------------------------------------------------------------------- =09| | modules || artifacts | =09| conf | number| search|dwnlded|evicted|| number|dwnlded| =09--------------------------------------------------------------------- =09| default | 8 | 0 | 0 | 0 || 8 | 0 | =09--------------------------------------------------------------------- [wc-checker] Initializing working copy... [wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder= ". [wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation [wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder = for further details. [wc-checker] Checking working copy status... -jenkins-base: BUILD SUCCESSFUL Total time: 155 minutes 25 seconds Archiving artifacts WARN: No artifacts found that match the file pattern "**/*.events,heapdumps= /**,**/hs_err_pid*". Configuration error? WARN: java.lang.InterruptedException: no matches found within 10000 Recording test results Build step 'Publish JUnit test result report' changed build result to UNSTA= BLE Email was triggered for: Unstable (Test Failures) Sending email for trigger: Unstable (Test Failures) ------=_Part_292_1442514761.1526519999191 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_292_1442514761.1526519999191--