Return-Path: X-Original-To: archive-asf-public-internal@cust-asf2.ponee.io Delivered-To: archive-asf-public-internal@cust-asf2.ponee.io Received: from cust-asf.ponee.io (cust-asf.ponee.io [163.172.22.183]) by cust-asf2.ponee.io (Postfix) with ESMTP id 642AE200CF5 for ; Sun, 27 Aug 2017 17:53:42 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 627E2164158; Sun, 27 Aug 2017 15:53:42 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id BA59B164157 for ; Sun, 27 Aug 2017 17:53:39 +0200 (CEST) Received: (qmail 68268 invoked by uid 500); 27 Aug 2017 15:53:38 -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 68253 invoked by uid 99); 27 Aug 2017 15:53:37 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Sun, 27 Aug 2017 15:53:37 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id 3B83D1A293B for ; Sun, 27 Aug 2017 15:53:37 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: -0.3 X-Spam-Level: X-Spam-Status: No, score=-0.3 tagged_above=-999 required=6.31 tests=[KAM_BADIPHTTP=2, RCVD_IN_DNSWL_MED=-2.3, SPF_PASS=-0.001, WEIRD_PORT=0.001] autolearn=disabled Received: from mx1-lw-us.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id isQ9Zb41u4K1 for ; Sun, 27 Aug 2017 15:53:20 +0000 (UTC) Received: from serv1.sd-datasolutions.de (serv1.sd-datasolutions.de [88.99.242.108]) by mx1-lw-us.apache.org (ASF Mail Server at mx1-lw-us.apache.org) with ESMTP id 2916460D92 for ; Sun, 27 Aug 2017 15:53:19 +0000 (UTC) Received: from serv1 (ip6-localhost [IPv6:::1]) by serv1.sd-datasolutions.de (Postfix) with ESMTP id DED581080115 for ; Sun, 27 Aug 2017 15:53:17 +0000 (UTC) Date: Sun, 27 Aug 2017 15:52:01 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <959713212.151.1503849197913.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS-EA] Lucene-Solr-master-Linux (64bit/jdk-9-ea+181) - Build # 20381 - Unstable! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_150_551122485.1503849197881" X-Jenkins-Job: Lucene-Solr-master-Linux X-Jenkins-Result: UNSTABLE X-Priority: 5 (Low) archived-at: Sun, 27 Aug 2017 15:53:42 -0000 ------=_Part_150_551122485.1503849197881 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/20381/ Java: 64bit/jdk-9-ea+181 -XX:+UseCompressedOops -XX:+UseG1GC --illegal-acce= ss=3Ddeny 1 tests failed. FAILED: org.apache.solr.cloud.HttpPartitionTest.test Error Message: Doc with id=3D1 not found in http://127.0.0.1:35835/d/w/collMinRf_1x3 due t= o: Path not found: /id; rsp=3D{doc=3Dnull} Stack Trace: java.lang.AssertionError: Doc with id=3D1 not found in http://127.0.0.1:358= 35/d/w/collMinRf_1x3 due to: Path not found: /id; rsp=3D{doc=3Dnull} =09at __randomizedtesting.SeedInfo.seed([BE90AC88155A84BF:36C49352BBA6E947]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.junit.Assert.assertTrue(Assert.java:43) =09at org.apache.solr.cloud.HttpPartitionTest.assertDocExists(HttpPartition= Test.java:603) =09at org.apache.solr.cloud.HttpPartitionTest.assertDocsExistInAllReplicas(= HttpPartitionTest.java:558) =09at org.apache.solr.cloud.HttpPartitionTest.testMinRf(HttpPartitionTest.j= ava:249) =09at org.apache.solr.cloud.HttpPartitionTest.test(HttpPartitionTest.java:1= 27) =09at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Nativ= e Method) =09at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Native= MethodAccessorImpl.java:62) =09at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(De= legatingMethodAccessorImpl.java:43) =09at java.base/java.lang.reflect.Method.invoke(Method.java:564) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1713) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:907) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(Random= izedRunner.java:943) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(Rando= mizedRunner.java:957) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= FixedStatement.callStatement(BaseDistributedSearchTestCase.java:993) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= Statement.evaluate(BaseDistributedSearchTestCase.java:968) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:49) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:368) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:817) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:468) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:916) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:802) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:852) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:863) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:41) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at 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.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 12306 lines...] [junit4] Suite: org.apache.solr.cloud.HttpPartitionTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-mast= er-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE9= 0AC88155A84BF-001/init-core-data-001 [junit4] 2> 1590400 WARN (SUITE-HttpPartitionTest-seed#[BE90AC88155A8= 4BF]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens= =3D102 numCloses=3D102 [junit4] 2> 1590400 INFO (SUITE-HttpPartitionTest-seed#[BE90AC88155A8= 4BF]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_= SYSPROP=3Dtrue) w/NUMERIC_DOCVALUES_SYSPROP=3Dfalse [junit4] 2> 1590401 INFO (SUITE-HttpPartitionTest-seed#[BE90AC88155A8= 4BF]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientA= uth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=3D"http= s://issues.apache.org/jira/browse/SOLR-5776") [junit4] 2> 1590401 INFO (SUITE-HttpPartitionTest-seed#[BE90AC88155A8= 4BF]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.s= olr.allowed.securerandom=3Dnull & java.security.egd=3Dfile:/dev/./urandom [junit4] 2> 1590401 INFO (SUITE-HttpPartitionTest-seed#[BE90AC88155A8= 4BF]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext= system property: /d/w [junit4] 2> 1590402 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1590402 INFO (Thread-3072) [ ] o.a.s.c.ZkTestServer cl= ient port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1590402 INFO (Thread-3072) [ ] o.a.s.c.ZkTestServer St= arting server [junit4] 2> 1590403 ERROR (Thread-3072) [ ] 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> 1590502 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkTestServer start zk server on port:38471 [junit4] 2> 1590505 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/solrco= nfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 1590506 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/schema= .xml to /configs/conf1/schema.xml [junit4] 2> 1590506 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/solrco= nfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.ran= domindexconfig.xml [junit4] 2> 1590507 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/stopwo= rds.txt to /configs/conf1/stopwords.txt [junit4] 2> 1590508 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/protwo= rds.txt to /configs/conf1/protwords.txt [junit4] 2> 1590508 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/curren= cy.xml to /configs/conf1/currency.xml [junit4] 2> 1590508 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/enumsC= onfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 1590509 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/open-e= xchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 1590509 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/mappin= g-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 1590510 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/old_sy= nonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 1590510 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Luc= ene-Solr-master-Linux/solr/core/src/test-files/solr/collection1/conf/synony= ms.txt to /configs/conf1/synonyms.txt [junit4] 2> 1590511 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Will use TLOG replic= as unless explicitly asked otherwise [junit4] 2> 1590605 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 1590606 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHan= dler@5e89a9a2{/d/w,null,AVAILABLE} [junit4] 2> 1590607 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@de829c7{= HTTP/1.1,[http/1.1]}{127.0.0.1:37081} [junit4] 2> 1590607 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server Started @1592646ms [junit4] 2> 1590607 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext= =3D/d/w, solr.data.dir=3D/home/jenkins/workspace/Lucene-Solr-master-Linux/s= olr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A8= 4BF-001/tempDir-001/control/data, hostPort=3D36227, coreRootDirectory=3D/ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/= temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/control-001/cores} [junit4] 2> 1590607 ERROR (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.d= ir. Logging may be missing or incomplete. [junit4] 2> 1590607 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Ap= ache Solr? version 8.0.0 [junit4] 2> 1590607 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in c= loud mode on port null [junit4] 2> 1590608 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: = null, Default config dir: null [junit4] 2> 1590608 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2= 017-08-27T15:18:53.667053Z [junit4] 2> 1590609 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome = (not found in ZooKeeper) [junit4] 2> 1590609 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from= /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test= /J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/control-001/solr= .xml [junit4] 2> 1590611 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbea= nserver.JmxMBeanServer@6cdb1b64, but no JMX reporters were configured - add= ing default JMX reporter. [junit4] 2> 1590612 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.1:38471/sol= r [junit4] 2> 1590652 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1590652 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leade= r 127.0.0.1:36227_d%2Fw [junit4] 2> 1590652 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.Overseer Overseer (id=3D98556125738565636-127.0.0.= 1:36227_d%2Fw-n_0000000000) starting [junit4] 2> 1590655 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:36227_d%2Fw [junit4] 2> 1590655 INFO (zkCallback-3310-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1590706 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@6cdb1b64 [junit4] 2> 1590716 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@6cdb1b64 [junit4] 2> 1590716 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@6cdb1b64 [junit4] 2> 1590717 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-co= re/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/control-0= 01/cores [junit4] 2> 1590733 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (1) [junit4] 2> 1590733 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.= 0.1:38471/solr ready [junit4] 2> 1590734 INFO (SocketProxy-Acceptor-36227) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D51250,localport=3D3622= 7], receiveBufferSize:531000 [junit4] 2> 1590736 INFO (SocketProxy-Acceptor-36227) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D37081,localpor= t=3D47122], receiveBufferSize=3D530904 [junit4] 2> 1590736 INFO (qtp526403968-14767) [ ] o.a.s.h.a.Collec= tionsHandler Invoked Collection Action :create with params replicationFacto= r=3D1&collection.configName=3Dconf1&name=3Dcontrol_collection&nrtReplicas= =3D1&action=3DCREATE&numShards=3D1&createNodeSet=3D127.0.0.1:36227_d%252Fw&= wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1590737 INFO (OverseerThreadFactory-6000-thread-1) [ ]= o.a.s.c.CreateCollectionCmd Create collection control_collection [junit4] 2> 1590840 INFO (SocketProxy-Acceptor-36227) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D51254,localport=3D3622= 7], receiveBufferSize:531000 [junit4] 2> 1590840 INFO (SocketProxy-Acceptor-36227) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D37081,localpor= t=3D47126], receiveBufferSize=3D530904 [junit4] 2> 1590840 INFO (qtp526403968-14769) [ ] o.a.s.h.a.CoreAd= minOperation core create command qt=3D/admin/cores&collection.configName=3D= conf1&newCollection=3Dtrue&name=3Dcontrol_collection_shard1_replica_n1&acti= on=3DCREATE&numShards=3D1&collection=3Dcontrol_collection&shard=3Dshard1&wt= =3Djavabin&version=3D2&replicaType=3DNRT [junit4] 2> 1590840 INFO (qtp526403968-14769) [ ] o.a.s.c.Transien= tSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1590947 INFO (zkCallback-3310-thread-2) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/control_collection/state.json] for coll= ection [control_collection] has occurred - updating... (live nodes size: [1= ]) [junit4] 2> 1591848 INFO (qtp526403968-14769) [ ] o.a.s.c.SolrConf= ig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1591857 INFO (qtp526403968-14769) [ ] o.a.s.s.IndexSch= ema [control_collection_shard1_replica_n1] Schema name=3Dtest [junit4] 2> 1591913 INFO (qtp526403968-14769) [ ] o.a.s.s.IndexSch= ema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 1591920 INFO (qtp526403968-14769) [ ] o.a.s.c.CoreCont= ainer Creating SolrCore 'control_collection_shard1_replica_n1' using config= uration from collection control_collection, trusted=3Dtrue [junit4] 2> 1591920 INFO (qtp526403968-14769) [ ] o.a.s.m.r.SolrJm= xReporter JMX monitoring for 'solr.core.control_collection.shard1.replica_n= 1' (registry 'solr.core.control_collection.shard1.replica_n1') enabled at s= erver: com.sun.jmx.mbeanserver.JmxMBeanServer@6cdb1b64 [junit4] 2> 1591920 INFO (qtp526403968-14769) [ ] o.a.s.c.SolrCore= solr.RecoveryStrategy.Builder [junit4] 2> 1591920 INFO (qtp526403968-14769) [ ] o.a.s.c.SolrCore= [[control_collection_shard1_replica_n1] ] Opening new SolrCore at [/home/j= enkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp= /solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/control-001/cores/contro= l_collection_shard1_replica_n1], dataDir=3D[/home/jenkins/workspace/Lucene-= Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitio= nTest_BE90AC88155A84BF-001/control-001/cores/control_collection_shard1_repl= ica_n1/data/] [junit4] 2> 1591922 INFO (qtp526403968-14769) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D30, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D45.302734375, floorSegmentMB=3D2.0224609375, fo= rceMergeDeletesPctAllowed=3D27.27224679176982, segmentsPerTier=3D12.0, maxC= FSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1591923 WARN (qtp526403968-14769) [ ] o.a.s.c.RequestH= andlers INVALID paramSet a in requestHandler {type =3D requestHandler,name = =3D /dump,class =3D DumpRequestHandler,attributes =3D {initParams=3Da, name= =3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 1591944 INFO (qtp526403968-14769) [ ] o.a.s.u.UpdateHa= ndler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 1591944 INFO (qtp526403968-14769) [ ] o.a.s.u.UpdateLo= g Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH numRecordsToK= eep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1591945 INFO (qtp526403968-14769) [ ] o.a.s.u.CommitTr= acker Hard AutoCommit: disabled [junit4] 2> 1591945 INFO (qtp526403968-14769) [ ] o.a.s.u.CommitTr= acker Soft AutoCommit: disabled [junit4] 2> 1591945 INFO (qtp526403968-14769) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D46, maxMergeAtOnceExplicit= =3D11, maxMergedSegmentMB=3D26.1796875, floorSegmentMB=3D0.85546875, forceM= ergeDeletesPctAllowed=3D19.058050301803423, segmentsPerTier=3D11.0, maxCFSS= egmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.47530423083228757 [junit4] 2> 1591946 INFO (qtp526403968-14769) [ ] o.a.s.s.SolrInde= xSearcher Opening [Searcher@d19a795[control_collection_shard1_replica_n1] m= ain] [junit4] 2> 1591946 INFO (qtp526403968-14769) [ ] o.a.s.r.ManagedR= esourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1591946 INFO (qtp526403968-14769) [ ] o.a.s.r.ManagedR= esourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorag= eIO:path=3D/configs/conf1 [junit4] 2> 1591946 INFO (qtp526403968-14769) [ ] o.a.s.h.Replicat= ionHandler Commits will be reserved for 10000 [junit4] 2> 1591947 INFO (searcherExecutor-6003-thread-1) [ ] o.a.= s.c.SolrCore [control_collection_shard1_replica_n1] Registered new searcher= Searcher@d19a795[control_collection_shard1_replica_n1] main{ExitableDirect= oryReader(UninvertingDirectoryReader())} [junit4] 2> 1591947 INFO (qtp526403968-14769) [ ] o.a.s.u.UpdateLo= g Could not find max version in index or recent updates, using new clock 15= 76898013436051456 [junit4] 2> 1591950 INFO (qtp526403968-14769) [ ] o.a.s.c.ShardLea= derElectionContext Enough replicas found to continue. [junit4] 2> 1591950 INFO (qtp526403968-14769) [ ] o.a.s.c.ShardLea= derElectionContext I may be the new leader - try and sync [junit4] 2> 1591950 INFO (qtp526403968-14769) [ ] o.a.s.c.SyncStra= tegy Sync replicas to http://127.0.0.1:36227/d/w/control_collection_shard1_= replica_n1/ [junit4] 2> 1591950 INFO (qtp526403968-14769) [ ] o.a.s.c.SyncStra= tegy Sync Success - now sync replicas to me [junit4] 2> 1591950 INFO (qtp526403968-14769) [ ] o.a.s.c.SyncStra= tegy http://127.0.0.1:36227/d/w/control_collection_shard1_replica_n1/ has n= o replicas [junit4] 2> 1591950 INFO (qtp526403968-14769) [ ] o.a.s.c.ShardLea= derElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 1591954 INFO (qtp526403968-14769) [ ] o.a.s.c.ShardLea= derElectionContext I am the new leader: http://127.0.0.1:36227/d/w/control_= collection_shard1_replica_n1/ shard1 [junit4] 2> 1592055 INFO (zkCallback-3310-thread-2) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/control_collection/state.json] for coll= ection [control_collection] has occurred - updating... (live nodes size: [1= ]) [junit4] 2> 1592105 INFO (qtp526403968-14769) [ ] o.a.s.c.ZkContro= ller I am the leader, no recovery necessary [junit4] 2> 1592106 INFO (qtp526403968-14769) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&= collection.configName=3Dconf1&newCollection=3Dtrue&name=3Dcontrol_collectio= n_shard1_replica_n1&action=3DCREATE&numShards=3D1&collection=3Dcontrol_coll= ection&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D= 0 QTime=3D1265 [junit4] 2> 1592107 INFO (qtp526403968-14767) [ ] o.a.s.h.a.Collec= tionsHandler Wait for new collection to be active for at most 30 seconds. C= heck all shard replicas [junit4] 2> 1592207 INFO (zkCallback-3310-thread-2) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/control_collection/state.json] for coll= ection [control_collection] has occurred - updating... (live nodes size: [1= ]) [junit4] 2> 1592738 INFO (OverseerCollectionConfigSetProcessor-985561= 25738565636-127.0.0.1:36227_d%2Fw-n_0000000000) [ ] o.a.s.c.OverseerTask= Queue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 does= n't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1593107 INFO (qtp526403968-14767) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/collections params=3D{replicationF= actor=3D1&collection.configName=3Dconf1&name=3Dcontrol_collection&nrtReplic= as=3D1&action=3DCREATE&numShards=3D1&createNodeSet=3D127.0.0.1:36227_d%252F= w&wt=3Djavabin&version=3D2} status=3D0 QTime=3D2370 [junit4] 2> 1593113 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (1) [junit4] 2> 1593114 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.= 0.1:38471/solr ready [junit4] 2> 1593114 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false c= ause connection loss:false [junit4] 2> 1593114 INFO (SocketProxy-Acceptor-36227) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D51274,localport=3D3622= 7], receiveBufferSize:531000 [junit4] 2> 1593118 INFO (SocketProxy-Acceptor-36227) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D37081,localpor= t=3D47146], receiveBufferSize=3D530904 [junit4] 2> 1593120 INFO (qtp526403968-14764) [ ] o.a.s.h.a.Collec= tionsHandler Invoked Collection Action :create with params replicationFacto= r=3D1&collection.configName=3Dconf1&name=3Dcollection1&nrtReplicas=3D1&acti= on=3DCREATE&numShards=3D2&createNodeSet=3D&stateFormat=3D2&wt=3Djavabin&ver= sion=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1593121 INFO (OverseerThreadFactory-6000-thread-2) [ ]= o.a.s.c.CreateCollectionCmd Create collection collection1 [junit4] 2> 1593121 WARN (OverseerThreadFactory-6000-thread-2) [ ]= o.a.s.c.CreateCollectionCmd It is unusual to create a collection (collecti= on1) without cores. [junit4] 2> 1593323 INFO (qtp526403968-14764) [ ] o.a.s.h.a.Collec= tionsHandler Wait for new collection to be active for at most 30 seconds. C= heck all shard replicas [junit4] 2> 1593323 INFO (qtp526403968-14764) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/collections params=3D{replicationF= actor=3D1&collection.configName=3Dconf1&name=3Dcollection1&nrtReplicas=3D1&= action=3DCREATE&numShards=3D2&createNodeSet=3D&stateFormat=3D2&wt=3Djavabin= &version=3D2} status=3D0 QTime=3D203 [junit4] 2> 1593416 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in di= rectory /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-co= re/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-1-0= 01 of type TLOG [junit4] 2> 1593416 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 1593417 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHan= dler@55e06d60{/d/w,null,AVAILABLE} [junit4] 2> 1593417 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@62010858= {HTTP/1.1,[http/1.1]}{127.0.0.1:42751} [junit4] 2> 1593417 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server Started @1595456ms [junit4] 2> 1593417 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext= =3D/d/w, solrconfig=3Dsolrconfig.xml, solr.data.dir=3D/home/jenkins/workspa= ce/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.Ht= tpPartitionTest_BE90AC88155A84BF-001/tempDir-001/jetty1, hostPort=3D33589, = coreRootDirectory=3D/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/b= uild/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-0= 01/shard-1-001/cores, replicaType=3DTLOG} [junit4] 2> 1593418 ERROR (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.d= ir. Logging may be missing or incomplete. [junit4] 2> 1593418 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Ap= ache Solr? version 8.0.0 [junit4] 2> 1593418 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in c= loud mode on port null [junit4] 2> 1593418 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: = null, Default config dir: null [junit4] 2> 1593418 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2= 017-08-27T15:18:56.477286Z [junit4] 2> 1593419 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome = (not found in ZooKeeper) [junit4] 2> 1593419 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from= /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test= /J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-1-001/solr= .xml [junit4] 2> 1593421 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbea= nserver.JmxMBeanServer@6cdb1b64, but no JMX reporters were configured - add= ing default JMX reporter. [junit4] 2> 1593423 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.1:38471/sol= r [junit4] 2> 1593426 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (1) [junit4] 2> 1593426 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1593427 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:33589_d%2Fw [junit4] 2> 1593428 INFO (zkCallback-3310-thread-2) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1593428 INFO (zkCallback-3317-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1593429 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1593451 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@6cdb1b64 [junit4] 2> 1593458 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@6cdb1b64 [junit4] 2> 1593459 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@6cdb1b64 [junit4] 2> 1593460 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-co= re/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-1-0= 01/cores [junit4] 2> 1593475 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52490,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1593475 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D35968], receiveBufferSize=3D530904 [junit4] 2> 1593476 INFO (qtp946316246-14816) [ ] o.a.s.h.a.Collec= tionsHandler Invoked Collection Action :addreplica with params node=3D127.0= .0.1:33589_d%252Fw&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd2&type=3DTLOG&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1593477 INFO (OverseerCollectionConfigSetProcessor-985561= 25738565636-127.0.0.1:36227_d%2Fw-n_0000000000) [ ] o.a.s.c.OverseerTask= Queue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 does= n't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1593477 INFO (OverseerThreadFactory-6000-thread-3) [ ]= o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:33589_d%2Fw for creating n= ew replica [junit4] 2> 1593478 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52494,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1593478 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D35972], receiveBufferSize=3D530904 [junit4] 2> 1593478 INFO (qtp946316246-14812) [ ] o.a.s.h.a.CoreAd= minOperation core create command qt=3D/admin/cores&collection.configName=3D= conf1&name=3Dcollection1_shard2_replica_t41&action=3DCREATE&collection=3Dco= llection1&shard=3Dshard2&wt=3Djavabin&version=3D2&replicaType=3DTLOG [junit4] 2> 1593479 INFO (qtp946316246-14812) [ ] o.a.s.c.Transien= tSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1593581 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 1594486 INFO (qtp946316246-14812) [ ] o.a.s.c.SolrConf= ig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1594495 INFO (qtp946316246-14812) [ ] o.a.s.s.IndexSch= ema [collection1_shard2_replica_t41] Schema name=3Dtest [junit4] 2> 1594544 INFO (qtp946316246-14812) [ ] o.a.s.s.IndexSch= ema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 1594550 INFO (qtp946316246-14812) [ ] o.a.s.c.CoreCont= ainer Creating SolrCore 'collection1_shard2_replica_t41' using configuratio= n from collection collection1, trusted=3Dtrue [junit4] 2> 1594550 INFO (qtp946316246-14812) [ ] o.a.s.m.r.SolrJm= xReporter JMX monitoring for 'solr.core.collection1.shard2.replica_t41' (re= gistry 'solr.core.collection1.shard2.replica_t41') enabled at server: com.s= un.jmx.mbeanserver.JmxMBeanServer@6cdb1b64 [junit4] 2> 1594551 INFO (qtp946316246-14812) [ ] o.a.s.c.SolrCore= solr.RecoveryStrategy.Builder [junit4] 2> 1594551 INFO (qtp946316246-14812) [ ] o.a.s.c.SolrCore= [[collection1_shard2_replica_t41] ] Opening new SolrCore at [/home/jenkins= /workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.= cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-1-001/cores/collection1_= shard2_replica_t41], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC= 88155A84BF-001/shard-1-001/cores/collection1_shard2_replica_t41/data/] [junit4] 2> 1594552 INFO (qtp946316246-14812) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D30, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D45.302734375, floorSegmentMB=3D2.0224609375, fo= rceMergeDeletesPctAllowed=3D27.27224679176982, segmentsPerTier=3D12.0, maxC= FSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1594554 WARN (qtp946316246-14812) [ ] o.a.s.c.RequestH= andlers INVALID paramSet a in requestHandler {type =3D requestHandler,name = =3D /dump,class =3D DumpRequestHandler,attributes =3D {initParams=3Da, name= =3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 1594596 INFO (qtp946316246-14812) [ ] o.a.s.u.UpdateHa= ndler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 1594596 INFO (qtp946316246-14812) [ ] o.a.s.u.UpdateLo= g Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH numRecordsToK= eep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1594597 INFO (qtp946316246-14812) [ ] o.a.s.u.CommitTr= acker Hard AutoCommit: disabled [junit4] 2> 1594597 INFO (qtp946316246-14812) [ ] o.a.s.u.CommitTr= acker Soft AutoCommit: disabled [junit4] 2> 1594598 INFO (qtp946316246-14812) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D46, maxMergeAtOnceExplicit= =3D11, maxMergedSegmentMB=3D26.1796875, floorSegmentMB=3D0.85546875, forceM= ergeDeletesPctAllowed=3D19.058050301803423, segmentsPerTier=3D11.0, maxCFSS= egmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.47530423083228757 [junit4] 2> 1594599 INFO (qtp946316246-14812) [ ] o.a.s.s.SolrInde= xSearcher Opening [Searcher@6eac4c51[collection1_shard2_replica_t41] main] [junit4] 2> 1594599 INFO (qtp946316246-14812) [ ] o.a.s.r.ManagedR= esourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1594599 INFO (qtp946316246-14812) [ ] o.a.s.r.ManagedR= esourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorag= eIO:path=3D/configs/conf1 [junit4] 2> 1594600 INFO (qtp946316246-14812) [ ] o.a.s.h.Replicat= ionHandler Commits will be reserved for 10000 [junit4] 2> 1594600 INFO (searcherExecutor-6014-thread-1) [ ] o.a.= s.c.SolrCore [collection1_shard2_replica_t41] Registered new searcher Searc= her@6eac4c51[collection1_shard2_replica_t41] main{ExitableDirectoryReader(U= ninvertingDirectoryReader())} [junit4] 2> 1594600 INFO (qtp946316246-14812) [ ] o.a.s.u.UpdateLo= g Could not find max version in index or recent updates, using new clock 15= 76898016217923584 [junit4] 2> 1594603 INFO (qtp946316246-14812) [ ] o.a.s.c.ShardLea= derElectionContext Enough replicas found to continue. [junit4] 2> 1594603 INFO (qtp946316246-14812) [ ] o.a.s.c.ShardLea= derElectionContext I may be the new leader - try and sync [junit4] 2> 1594603 INFO (qtp946316246-14812) [ ] o.a.s.c.SyncStra= tegy Sync replicas to http://127.0.0.1:33589/d/w/collection1_shard2_replica= _t41/ [junit4] 2> 1594603 INFO (qtp946316246-14812) [ ] o.a.s.c.SyncStra= tegy Sync Success - now sync replicas to me [junit4] 2> 1594603 INFO (qtp946316246-14812) [ ] o.a.s.c.SyncStra= tegy http://127.0.0.1:33589/d/w/collection1_shard2_replica_t41/ has no repl= icas [junit4] 2> 1594603 INFO (qtp946316246-14812) [ ] o.a.s.c.ShardLea= derElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 1594603 INFO (qtp946316246-14812) [ ] o.a.s.c.ZkContro= ller collection1_shard2_replica_t41 stopping background replication from le= ader [junit4] 2> 1594604 INFO (qtp946316246-14812) [ ] o.a.s.c.ShardLea= derElectionContext I am the new leader: http://127.0.0.1:33589/d/w/collecti= on1_shard2_replica_t41/ shard2 [junit4] 2> 1594706 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 1594755 INFO (qtp946316246-14812) [ ] o.a.s.c.ZkContro= ller I am the leader, no recovery necessary [junit4] 2> 1594756 INFO (qtp946316246-14812) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&= collection.configName=3Dconf1&name=3Dcollection1_shard2_replica_t41&action= =3DCREATE&collection=3Dcollection1&shard=3Dshard2&wt=3Djavabin&version=3D2&= replicaType=3DTLOG} status=3D0 QTime=3D1277 [junit4] 2> 1594757 INFO (qtp946316246-14816) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/collections params=3D{node=3D127.0= .0.1:33589_d%252Fw&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd2&type=3DTLOG&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1281 [junit4] 2> 1594836 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in di= rectory /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-co= re/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-2-0= 01 of type TLOG [junit4] 2> 1594836 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 1594837 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHan= dler@412e9e30{/d/w,null,AVAILABLE} [junit4] 2> 1594837 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1699e1ac= {HTTP/1.1,[http/1.1]}{127.0.0.1:46087} [junit4] 2> 1594838 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server Started @1596876ms [junit4] 2> 1594838 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext= =3D/d/w, solrconfig=3Dsolrconfig.xml, solr.data.dir=3D/home/jenkins/workspa= ce/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.Ht= tpPartitionTest_BE90AC88155A84BF-001/tempDir-001/jetty2, hostPort=3D34765, = coreRootDirectory=3D/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/b= uild/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-0= 01/shard-2-001/cores, replicaType=3DTLOG} [junit4] 2> 1594838 ERROR (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.d= ir. Logging may be missing or incomplete. [junit4] 2> 1594838 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Ap= ache Solr? version 8.0.0 [junit4] 2> 1594838 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in c= loud mode on port null [junit4] 2> 1594838 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: = null, Default config dir: null [junit4] 2> 1594838 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2= 017-08-27T15:18:57.897395Z [junit4] 2> 1594839 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome = (not found in ZooKeeper) [junit4] 2> 1594839 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from= /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test= /J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-2-001/solr= .xml [junit4] 2> 1594841 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbea= nserver.JmxMBeanServer@6cdb1b64, but no JMX reporters were configured - add= ing default JMX reporter. [junit4] 2> 1594842 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.1:38471/sol= r [junit4] 2> 1594846 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (2) [junit4] 2> 1594846 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1594847 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:34765_d%2Fw [junit4] 2> 1594847 INFO (zkCallback-3310-thread-2) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1594848 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1594848 INFO (zkCallback-3317-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1594849 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1594877 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@6cdb1b64 [junit4] 2> 1594886 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@6cdb1b64 [junit4] 2> 1594886 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@6cdb1b64 [junit4] 2> 1594887 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-co= re/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-2-0= 01/cores [junit4] 2> 1594915 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D45816,localport=3D3476= 5], receiveBufferSize:531000 [junit4] 2> 1594915 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D46087,localpor= t=3D39734], receiveBufferSize=3D530904 [junit4] 2> 1594918 INFO (qtp327702480-14850) [ ] o.a.s.h.a.Collec= tionsHandler Invoked Collection Action :addreplica with params node=3D127.0= .0.1:34765_d%252Fw&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd1&type=3DTLOG&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1594919 INFO (OverseerCollectionConfigSetProcessor-985561= 25738565636-127.0.0.1:36227_d%2Fw-n_0000000000) [ ] o.a.s.c.OverseerTask= Queue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 does= n't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1594919 INFO (OverseerThreadFactory-6000-thread-4) [ ]= o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:34765_d%2Fw for creating n= ew replica [junit4] 2> 1594919 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D45820,localport=3D3476= 5], receiveBufferSize:531000 [junit4] 2> 1594920 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D46087,localpor= t=3D39738], receiveBufferSize=3D530904 [junit4] 2> 1594920 INFO (qtp327702480-14852) [ ] o.a.s.h.a.CoreAd= minOperation core create command qt=3D/admin/cores&collection.configName=3D= conf1&name=3Dcollection1_shard1_replica_t43&action=3DCREATE&collection=3Dco= llection1&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DTLOG [junit4] 2> 1594920 INFO (qtp327702480-14852) [ ] o.a.s.c.Transien= tSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1595022 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1595022 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1595927 INFO (qtp327702480-14852) [ ] o.a.s.c.SolrConf= ig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1595933 INFO (qtp327702480-14852) [ ] o.a.s.s.IndexSch= ema [collection1_shard1_replica_t43] Schema name=3Dtest [junit4] 2> 1595989 INFO (qtp327702480-14852) [ ] o.a.s.s.IndexSch= ema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 1595996 INFO (qtp327702480-14852) [ ] o.a.s.c.CoreCont= ainer Creating SolrCore 'collection1_shard1_replica_t43' using configuratio= n from collection collection1, trusted=3Dtrue [junit4] 2> 1595996 INFO (qtp327702480-14852) [ ] o.a.s.m.r.SolrJm= xReporter JMX monitoring for 'solr.core.collection1.shard1.replica_t43' (re= gistry 'solr.core.collection1.shard1.replica_t43') enabled at server: com.s= un.jmx.mbeanserver.JmxMBeanServer@6cdb1b64 [junit4] 2> 1595996 INFO (qtp327702480-14852) [ ] o.a.s.c.SolrCore= solr.RecoveryStrategy.Builder [junit4] 2> 1595996 INFO (qtp327702480-14852) [ ] o.a.s.c.SolrCore= [[collection1_shard1_replica_t43] ] Opening new SolrCore at [/home/jenkins= /workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.= cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-2-001/cores/collection1_= shard1_replica_t43], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC= 88155A84BF-001/shard-2-001/cores/collection1_shard1_replica_t43/data/] [junit4] 2> 1595998 INFO (qtp327702480-14852) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D30, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D45.302734375, floorSegmentMB=3D2.0224609375, fo= rceMergeDeletesPctAllowed=3D27.27224679176982, segmentsPerTier=3D12.0, maxC= FSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1595999 WARN (qtp327702480-14852) [ ] o.a.s.c.RequestH= andlers INVALID paramSet a in requestHandler {type =3D requestHandler,name = =3D /dump,class =3D DumpRequestHandler,attributes =3D {initParams=3Da, name= =3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 1596072 INFO (qtp327702480-14852) [ ] o.a.s.u.UpdateHa= ndler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 1596072 INFO (qtp327702480-14852) [ ] o.a.s.u.UpdateLo= g Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH numRecordsToK= eep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1596073 INFO (qtp327702480-14852) [ ] o.a.s.u.CommitTr= acker Hard AutoCommit: disabled [junit4] 2> 1596073 INFO (qtp327702480-14852) [ ] o.a.s.u.CommitTr= acker Soft AutoCommit: disabled [junit4] 2> 1596074 INFO (qtp327702480-14852) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D46, maxMergeAtOnceExplicit= =3D11, maxMergedSegmentMB=3D26.1796875, floorSegmentMB=3D0.85546875, forceM= ergeDeletesPctAllowed=3D19.058050301803423, segmentsPerTier=3D11.0, maxCFSS= egmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.47530423083228757 [junit4] 2> 1596074 INFO (qtp327702480-14852) [ ] o.a.s.s.SolrInde= xSearcher Opening [Searcher@5d4f2f7[collection1_shard1_replica_t43] main] [junit4] 2> 1596075 INFO (qtp327702480-14852) [ ] o.a.s.r.ManagedR= esourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1596075 INFO (qtp327702480-14852) [ ] o.a.s.r.ManagedR= esourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorag= eIO:path=3D/configs/conf1 [junit4] 2> 1596076 INFO (qtp327702480-14852) [ ] o.a.s.h.Replicat= ionHandler Commits will be reserved for 10000 [junit4] 2> 1596076 INFO (searcherExecutor-6025-thread-1) [ ] o.a.= s.c.SolrCore [collection1_shard1_replica_t43] Registered new searcher Searc= her@5d4f2f7[collection1_shard1_replica_t43] main{ExitableDirectoryReader(Un= invertingDirectoryReader())} [junit4] 2> 1596076 INFO (qtp327702480-14852) [ ] o.a.s.u.UpdateLo= g Could not find max version in index or recent updates, using new clock 15= 76898017765621760 [junit4] 2> 1596080 INFO (qtp327702480-14852) [ ] o.a.s.c.ShardLea= derElectionContext Enough replicas found to continue. [junit4] 2> 1596080 INFO (qtp327702480-14852) [ ] o.a.s.c.ShardLea= derElectionContext I may be the new leader - try and sync [junit4] 2> 1596080 INFO (qtp327702480-14852) [ ] o.a.s.c.SyncStra= tegy Sync replicas to http://127.0.0.1:34765/d/w/collection1_shard1_replica= _t43/ [junit4] 2> 1596080 INFO (qtp327702480-14852) [ ] o.a.s.c.SyncStra= tegy Sync Success - now sync replicas to me [junit4] 2> 1596080 INFO (qtp327702480-14852) [ ] o.a.s.c.SyncStra= tegy http://127.0.0.1:34765/d/w/collection1_shard1_replica_t43/ has no repl= icas [junit4] 2> 1596080 INFO (qtp327702480-14852) [ ] o.a.s.c.ShardLea= derElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 1596080 INFO (qtp327702480-14852) [ ] o.a.s.c.ZkContro= ller collection1_shard1_replica_t43 stopping background replication from le= ader [junit4] 2> 1596081 INFO (qtp327702480-14852) [ ] o.a.s.c.ShardLea= derElectionContext I am the new leader: http://127.0.0.1:34765/d/w/collecti= on1_shard1_replica_t43/ shard1 [junit4] 2> 1596182 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1596182 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1596232 INFO (qtp327702480-14852) [ ] o.a.s.c.ZkContro= ller I am the leader, no recovery necessary [junit4] 2> 1596233 INFO (qtp327702480-14852) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&= collection.configName=3Dconf1&name=3Dcollection1_shard1_replica_t43&action= =3DCREATE&collection=3Dcollection1&shard=3Dshard1&wt=3Djavabin&version=3D2&= replicaType=3DTLOG} status=3D0 QTime=3D1312 [junit4] 2> 1596234 INFO (qtp327702480-14850) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/collections params=3D{node=3D127.0= .0.1:34765_d%252Fw&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd1&type=3DTLOG&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1316 [junit4] 2> 1596300 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in di= rectory /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-co= re/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-3-0= 01 of type TLOG [junit4] 2> 1596300 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 1596301 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHan= dler@3140489e{/d/w,null,AVAILABLE} [junit4] 2> 1596301 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7a2848f7= {HTTP/1.1,[http/1.1]}{127.0.0.1:35693} [junit4] 2> 1596301 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.Server Started @1598340ms [junit4] 2> 1596301 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext= =3D/d/w, solrconfig=3Dsolrconfig.xml, solr.data.dir=3D/home/jenkins/workspa= ce/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.Ht= tpPartitionTest_BE90AC88155A84BF-001/tempDir-001/jetty3, hostPort=3D35835, = coreRootDirectory=3D/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/b= uild/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-0= 01/shard-3-001/cores, replicaType=3DTLOG} [junit4] 2> 1596301 ERROR (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.d= ir. Logging may be missing or incomplete. [junit4] 2> 1596302 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Ap= ache Solr? version 8.0.0 [junit4] 2> 1596302 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in c= loud mode on port null [junit4] 2> 1596302 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: = null, Default config dir: null [junit4] 2> 1596302 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2= 017-08-27T15:18:59.361165Z [junit4] 2> 1596303 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome = (not found in ZooKeeper) [junit4] 2> 1596303 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from= /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test= /J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-3-001/solr= .xml [junit4] 2> 1596305 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbea= nserver.JmxMBeanServer@6cdb1b64, but no JMX reporters were configured - add= ing default JMX reporter. [junit4] 2> 1596307 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.1:38471/sol= r [junit4] 2> 1596310 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper.= .. (0) -> (3) [junit4] 2> 1596311 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1596312 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/l= ive_nodes/127.0.0.1:35835_d%2Fw [junit4] 2> 1596313 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1596313 INFO (zkCallback-3310-thread-2) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1596314 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1596313 INFO (zkCallback-3317-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1596314 INFO (zkCallback-3334-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1596349 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (= registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanSe= rver@6cdb1b64 [junit4] 2> 1596357 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (r= egistry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServ= er@6cdb1b64 [junit4] 2> 1596357 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' = (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBean= Server@6cdb1b64 [junit4] 2> 1596358 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions und= erneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-co= re/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-3-0= 01/cores [junit4] 2> 1596387 INFO (qtp327702480-14851) [ ] o.a.s.h.a.Collec= tionsHandler Invoked Collection Action :addreplica with params node=3D127.0= .0.1:35835_d%252Fw&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd2&type=3DTLOG&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1596389 INFO (OverseerCollectionConfigSetProcessor-985561= 25738565636-127.0.0.1:36227_d%2Fw-n_0000000000) [ ] o.a.s.c.OverseerTask= Queue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 does= n't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1596389 INFO (OverseerThreadFactory-6000-thread-5) [ ]= o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:35835_d%2Fw for creating n= ew replica [junit4] 2> 1596390 INFO (SocketProxy-Acceptor-35835) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D47662,localport=3D3583= 5], receiveBufferSize:531000 [junit4] 2> 1596390 INFO (SocketProxy-Acceptor-35835) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D35693,localpor= t=3D43012], receiveBufferSize=3D530904 [junit4] 2> 1596391 INFO (qtp834275956-14884) [ ] o.a.s.h.a.CoreAd= minOperation core create command qt=3D/admin/cores&collection.configName=3D= conf1&name=3Dcollection1_shard2_replica_t45&action=3DCREATE&collection=3Dco= llection1&shard=3Dshard2&wt=3Djavabin&version=3D2&replicaType=3DTLOG [junit4] 2> 1596391 INFO (qtp834275956-14884) [ ] o.a.s.c.Transien= tSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1596493 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1596493 INFO (zkCallback-3334-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1596493 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1597399 INFO (qtp834275956-14884) [ ] o.a.s.c.SolrConf= ig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1597406 INFO (qtp834275956-14884) [ ] o.a.s.s.IndexSch= ema [collection1_shard2_replica_t45] Schema name=3Dtest [junit4] 2> 1597475 INFO (qtp834275956-14884) [ ] o.a.s.s.IndexSch= ema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 1597483 INFO (qtp834275956-14884) [ ] o.a.s.c.CoreCont= ainer Creating SolrCore 'collection1_shard2_replica_t45' using configuratio= n from collection collection1, trusted=3Dtrue [junit4] 2> 1597483 INFO (qtp834275956-14884) [ ] o.a.s.m.r.SolrJm= xReporter JMX monitoring for 'solr.core.collection1.shard2.replica_t45' (re= gistry 'solr.core.collection1.shard2.replica_t45') enabled at server: com.s= un.jmx.mbeanserver.JmxMBeanServer@6cdb1b64 [junit4] 2> 1597483 INFO (qtp834275956-14884) [ ] o.a.s.c.SolrCore= solr.RecoveryStrategy.Builder [junit4] 2> 1597483 INFO (qtp834275956-14884) [ ] o.a.s.c.SolrCore= [[collection1_shard2_replica_t45] ] Opening new SolrCore at [/home/jenkins= /workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.= cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-3-001/cores/collection1_= shard2_replica_t45], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC= 88155A84BF-001/shard-3-001/cores/collection1_shard2_replica_t45/data/] [junit4] 2> 1597486 INFO (qtp834275956-14884) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D30, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D45.302734375, floorSegmentMB=3D2.0224609375, fo= rceMergeDeletesPctAllowed=3D27.27224679176982, segmentsPerTier=3D12.0, maxC= FSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1597488 WARN (qtp834275956-14884) [ ] o.a.s.c.RequestH= andlers INVALID paramSet a in requestHandler {type =3D requestHandler,name = =3D /dump,class =3D DumpRequestHandler,attributes =3D {initParams=3Da, name= =3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 1597516 INFO (qtp834275956-14884) [ ] o.a.s.u.UpdateHa= ndler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 1597516 INFO (qtp834275956-14884) [ ] o.a.s.u.UpdateLo= g Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH numRecordsToK= eep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1597517 INFO (qtp834275956-14884) [ ] o.a.s.u.CommitTr= acker Hard AutoCommit: disabled [junit4] 2> 1597517 INFO (qtp834275956-14884) [ ] o.a.s.u.CommitTr= acker Soft AutoCommit: disabled [junit4] 2> 1597518 INFO (qtp834275956-14884) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D46, maxMergeAtOnceExplicit= =3D11, maxMergedSegmentMB=3D26.1796875, floorSegmentMB=3D0.85546875, forceM= ergeDeletesPctAllowed=3D19.058050301803423, segmentsPerTier=3D11.0, maxCFSS= egmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.47530423083228757 [junit4] 2> 1597518 INFO (qtp834275956-14884) [ ] o.a.s.s.SolrInde= xSearcher Opening [Searcher@6fe1dae9[collection1_shard2_replica_t45] main] [junit4] 2> 1597518 INFO (qtp834275956-14884) [ ] o.a.s.r.ManagedR= esourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1597519 INFO (qtp834275956-14884) [ ] o.a.s.r.ManagedR= esourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorag= eIO:path=3D/configs/conf1 [junit4] 2> 1597519 INFO (qtp834275956-14884) [ ] o.a.s.h.Replicat= ionHandler Commits will be reserved for 10000 [junit4] 2> 1597520 INFO (searcherExecutor-6036-thread-1) [ ] o.a.= s.c.SolrCore [collection1_shard2_replica_t45] Registered new searcher Searc= her@6fe1dae9[collection1_shard2_replica_t45] main{ExitableDirectoryReader(U= ninvertingDirectoryReader())} [junit4] 2> 1597520 INFO (qtp834275956-14884) [ ] o.a.s.u.UpdateLo= g Could not find max version in index or recent updates, using new clock 15= 76898019279765504 [junit4] 2> 1597522 INFO (qtp834275956-14884) [ ] o.a.s.c.ZkContro= ller Core needs to recover:collection1_shard2_replica_t45 [junit4] 2> 1597523 INFO (updateExecutor-3331-thread-1) [ ] o.a.s.= u.DefaultSolrCoreState Running recovery [junit4] 2> 1597523 INFO (qtp834275956-14884) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&= collection.configName=3Dconf1&name=3Dcollection1_shard2_replica_t45&action= =3DCREATE&collection=3Dcollection1&shard=3Dshard2&wt=3Djavabin&version=3D2&= replicaType=3DTLOG} status=3D0 QTime=3D1132 [junit4] 2> 1597523 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=3Dtr= ue [junit4] 2> 1597523 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy ###### startupVersions=3D[[]] [junit4] 2> 1597523 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.ZkController collection1_shard2_replica_t45 stopping background replica= tion from leader [junit4] 2> 1597523 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Begin buffering updates. core=3D[collection1_shard2_re= plica_t45] [junit4] 2> 1597523 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4] 2> 1597524 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Publishing state of core [collection1_shard2_replica_t= 45] as recovering, leader is [http://127.0.0.1:33589/d/w/collection1_shard2= _replica_t41/] and I am [http://127.0.0.1:35835/d/w/collection1_shard2_repl= ica_t45/] [junit4] 2> 1597524 INFO (qtp327702480-14851) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/collections params=3D{node=3D127.0= .0.1:35835_d%252Fw&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd2&type=3DTLOG&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1137 [junit4] 2> 1597525 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:335= 89/d/w]; [WaitForState: action=3DPREPRECOVERY&core=3Dcollection1_shard2_rep= lica_t41&nodeName=3D127.0.0.1:35835_d%252Fw&coreNodeName=3Dcore_node46&stat= e=3Drecovering&checkLive=3Dtrue&onlyIfLeader=3Dtrue&onlyIfLeaderActive=3Dtr= ue] [junit4] 2> 1597525 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52566,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1597525 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D36044], receiveBufferSize=3D530904 [junit4] 2> 1597527 INFO (qtp946316246-14813) [ ] o.a.s.h.a.PrepRe= coveryOp Going to wait for coreNodeName: core_node46, state: recovering, ch= eckLive: true, onlyIfLeader: true, onlyIfLeaderActive: true, maxTime: 183 s [junit4] 2> 1597528 INFO (qtp946316246-14813) [ ] o.a.s.h.a.PrepRe= coveryOp In WaitForState(recovering): collection=3Dcollection1, shard=3Dsha= rd2, thisCore=3Dcollection1_shard2_replica_t41, leaderDoesNotNeedRecovery= =3Dfalse, isLeader? true, live=3Dtrue, checkLive=3Dtrue, currentState=3Ddow= n, localState=3Dactive, nodeName=3D127.0.0.1:35835_d%2Fw, coreNodeName=3Dco= re_node46, onlyIfActiveCheckResult=3Dfalse, nodeProps: core_node46:{"core":= "collection1_shard2_replica_t45","base_url":"http://127.0.0.1:35835/d/w","n= ode_name":"127.0.0.1:35835_d%2Fw","state":"down","type":"TLOG"} [junit4] 2> 1597528 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test [junit4] 2> 1597528 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Wait for recoveries = to finish - wait 30000 for each attempt [junit4] 2> 1597528 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to f= inish - collection: collection1 failOnTimeout:true timeout (sec):30000 [junit4] 2> 1597628 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1597628 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1597628 INFO (zkCallback-3334-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1598390 INFO (OverseerCollectionConfigSetProcessor-985561= 25738565636-127.0.0.1:36227_d%2Fw-n_0000000000) [ ] o.a.s.c.OverseerTask= Queue Response ZK path: /overseer/collection-queue-work/qnr-0000000008 does= n't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1598528 INFO (qtp946316246-14813) [ ] o.a.s.h.a.PrepRe= coveryOp In WaitForState(recovering): collection=3Dcollection1, shard=3Dsha= rd2, thisCore=3Dcollection1_shard2_replica_t41, leaderDoesNotNeedRecovery= =3Dfalse, isLeader? true, live=3Dtrue, checkLive=3Dtrue, currentState=3Drec= overing, localState=3Dactive, nodeName=3D127.0.0.1:35835_d%2Fw, coreNodeNam= e=3Dcore_node46, onlyIfActiveCheckResult=3Dfalse, nodeProps: core_node46:{"= core":"collection1_shard2_replica_t45","base_url":"http://127.0.0.1:35835/d= /w","node_name":"127.0.0.1:35835_d%2Fw","state":"recovering","type":"TLOG"} [junit4] 2> 1598528 INFO (qtp946316246-14813) [ ] o.a.s.h.a.PrepRe= coveryOp Waited coreNodeName: core_node46, state: recovering, checkLive: tr= ue, onlyIfLeader: true for: 1 seconds. [junit4] 2> 1598528 INFO (qtp946316246-14813) [ ] o.a.s.s.HttpSolr= Call [admin] webapp=3Dnull path=3D/admin/cores params=3D{nodeName=3D127.0.0= .1:35835_d%252Fw&onlyIfLeaderActive=3Dtrue&core=3Dcollection1_shard2_replic= a_t41&coreNodeName=3Dcore_node46&action=3DPREPRECOVERY&checkLive=3Dtrue&sta= te=3Drecovering&onlyIfLeader=3Dtrue&wt=3Djavabin&version=3D2} status=3D0 QT= ime=3D1000 [junit4] 2> 1599028 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting Replication Recovery. [junit4] 2> 1599028 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Attempting to replicate from [http://127.0.0.1:33589/d= /w/collection1_shard2_replica_t41/]. [junit4] 2> 1599029 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52576,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1599029 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D36054], receiveBufferSize=3D530904 [junit4] 2> 1599030 INFO (qtp946316246-14816) [ ] o.a.s.u.DirectUp= dateHandler2 start commit{_version_=3D1576898020863115264,optimize=3Dfalse,= openSearcher=3Dfalse,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit= =3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 1599030 INFO (qtp946316246-14816) [ ] o.a.s.u.DirectUp= dateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1599031 INFO (qtp946316246-14816) [ ] o.a.s.u.DirectUp= dateHandler2 end_commit_flush [junit4] 2> 1599031 INFO (qtp946316246-14816) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1_shard2_replica_t41] webapp=3D/d/w path=3D= /update params=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&commit=3Dtrue&so= ftCommit=3Dfalse&commit_end_point=3Dtrue&wt=3Djavabin&version=3D2}{commit= =3D} 0 1 [junit4] 2> 1599033 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52580,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1599033 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D36058], receiveBufferSize=3D530904 [junit4] 2> 1599034 INFO (qtp946316246-14811) [ ] o.a.s.c.S.Reques= t [collection1_shard2_replica_t41] webapp=3D/d/w path=3D/replication param= s=3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} sta= tus=3D0 QTime=3D0 [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.h.IndexFetcher Master's generation: 1 [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.h.IndexFetcher Master's version: 0 [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.h.IndexFetcher Slave's version: 0 [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Replication Recovery was successful. [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.ZkController collection1_shard2_replica_t45 starting background replica= tion from leader [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.ReplicateFromLeader Will start replication from leader with poll interv= al: 00:00:03 [junit4] 2> 1599034 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.h.ReplicationHandler Poll scheduled at an interval of 3000ms [junit4] 2> 1599035 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Updating version bucket highest from index after succe= ssful recovery. [junit4] 2> 1599035 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.u.UpdateLog Could not find max version in index or recent updates, using = new clock 1576898020868358144 [junit4] 2> 1599036 INFO (recoveryExecutor-3332-thread-1) [ ] o.a.= s.c.RecoveryStrategy Finished recovery process, successful=3D[true] [junit4] 2> 1599136 INFO (zkCallback-3322-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1599136 INFO (zkCallback-3334-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1599136 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1599529 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - co= llection: collection1 [junit4] 2> 1599530 INFO (qtp526403968-14767) [ ] o.a.s.u.DirectUp= dateHandler2 start commit{_version_=3D1576898021387403264,optimize=3Dfalse,= openSearcher=3Dtrue,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit= =3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 1599530 INFO (qtp526403968-14767) [ ] o.a.s.u.DirectUp= dateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1599530 INFO (qtp526403968-14767) [ ] o.a.s.u.DirectUp= dateHandler2 end_commit_flush [junit4] 2> 1599530 INFO (qtp526403968-14767) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/d/w p= ath=3D/update params=3D{waitSearcher=3Dtrue&commit=3Dtrue&softCommit=3Dfals= e&wt=3Djavabin&version=3D2}{commit=3D} 0 0 [junit4] 2> 1599531 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D45894,localport=3D3476= 5], receiveBufferSize:531000 [junit4] 2> 1599532 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52602,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1599532 INFO (SocketProxy-Acceptor-35835) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D47716,localport=3D3583= 5], receiveBufferSize:531000 [junit4] 2> 1599532 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D46087,localpor= t=3D39816], receiveBufferSize=3D530904 [junit4] 2> 1599532 INFO (SocketProxy-Acceptor-35835) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D35693,localpor= t=3D43070], receiveBufferSize=3D530904 [junit4] 2> 1599532 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D36084], receiveBufferSize=3D530904 [junit4] 2> 1599533 INFO (qtp834275956-14886) [ ] o.a.s.u.TestInje= ction Start waiting for replica in sync with leader [junit4] 2> 1599533 INFO (qtp327702480-14850) [ ] o.a.s.u.DirectUp= dateHandler2 start commit{_version_=3D1576898021390548992,optimize=3Dfalse,= openSearcher=3Dtrue,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit= =3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 1599533 INFO (qtp946316246-14813) [ ] o.a.s.u.DirectUp= dateHandler2 start commit{_version_=3D1576898021390548992,optimize=3Dfalse,= openSearcher=3Dtrue,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit= =3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 1599533 INFO (qtp327702480-14850) [ ] o.a.s.u.DirectUp= dateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1599533 INFO (qtp946316246-14813) [ ] o.a.s.u.DirectUp= dateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1599533 INFO (qtp327702480-14850) [ ] o.a.s.u.DirectUp= dateHandler2 end_commit_flush [junit4] 2> 1599533 INFO (qtp946316246-14813) [ ] o.a.s.u.DirectUp= dateHandler2 end_commit_flush [junit4] 2> 1599533 INFO (qtp327702480-14850) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1_shard1_replica_t43] webapp=3D/d/w path=3D= /update params=3D{update.distrib=3DFROMLEADER&waitSearcher=3Dtrue&openSearc= her=3Dtrue&commit=3Dtrue&softCommit=3Dfalse&distrib.from=3Dhttp://127.0.0.1= :34765/d/w/collection1_shard1_replica_t43/&commit_end_point=3Dtrue&wt=3Djav= abin&version=3D2&expungeDeletes=3Dfalse}{commit=3D} 0 0 [junit4] 2> 1599533 INFO (qtp946316246-14813) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1_shard2_replica_t41] webapp=3D/d/w path=3D= /update params=3D{update.distrib=3DFROMLEADER&waitSearcher=3Dtrue&openSearc= her=3Dtrue&commit=3Dtrue&softCommit=3Dfalse&distrib.from=3Dhttp://127.0.0.1= :34765/d/w/collection1_shard1_replica_t43/&commit_end_point=3Dtrue&wt=3Djav= abin&version=3D2&expungeDeletes=3Dfalse}{commit=3D} 0 0 [junit4] 2> 1599534 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52612,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1599540 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D36090], receiveBufferSize=3D530904 [junit4] 2> 1599540 INFO (qtp946316246-14811) [ ] o.a.s.c.S.Reques= t [collection1_shard2_replica_t41] webapp=3D/d/w path=3D/replication param= s=3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Ddetails} status= =3D0 QTime=3D0 [junit4] 2> 1599541 INFO (qtp834275956-14886) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1_shard2_replica_t45] webapp=3D/d/w path=3D= /update params=3D{update.distrib=3DFROMLEADER&waitSearcher=3Dtrue&openSearc= her=3Dtrue&commit=3Dtrue&softCommit=3Dfalse&distrib.from=3Dhttp://127.0.0.1= :34765/d/w/collection1_shard1_replica_t43/&commit_end_point=3Dtrue&wt=3Djav= abin&version=3D2&expungeDeletes=3Dfalse}{commit=3D} 0 8 [junit4] 2> 1599541 INFO (qtp327702480-14846) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1_shard1_replica_t43] webapp=3D/d/w path=3D= /update params=3D{_stateVer_=3Dcollection1:7&waitSearcher=3Dtrue&commit=3Dt= rue&softCommit=3Dfalse&wt=3Djavabin&version=3D2}{commit=3D} 0 10 [junit4] 2> 1599542 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D52616,localport=3D3358= 9], receiveBufferSize:531000 [junit4] 2> 1599546 INFO (SocketProxy-Acceptor-33589) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D42751,localpor= t=3D36094], receiveBufferSize=3D530904 [junit4] 2> 1599546 INFO (qtp946316246-14811) [ ] o.a.s.c.S.Reques= t [collection1_shard2_replica_t41] webapp=3D/d/w path=3D/select params=3D{= q=3D*:*&distrib=3Dfalse&tests=3DcheckShardConsistency&rows=3D0&wt=3Djavabin= &version=3D2} hits=3D0 status=3D0 QTime=3D0 [junit4] 2> 1599546 INFO (SocketProxy-Acceptor-35835) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D47732,localport=3D3583= 5], receiveBufferSize:531000 [junit4] 2> 1599547 INFO (SocketProxy-Acceptor-35835) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D35693,localpor= t=3D43082], receiveBufferSize=3D530904 [junit4] 2> 1599547 INFO (qtp834275956-14879) [ ] o.a.s.c.S.Reques= t [collection1_shard2_replica_t45] webapp=3D/d/w path=3D/select params=3D{= q=3D*:*&distrib=3Dfalse&tests=3DcheckShardConsistency&rows=3D0&wt=3Djavabin= &version=3D2} hits=3D0 status=3D0 QTime=3D0 [junit4] 2> 1599548 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D45918,localport=3D3476= 5], receiveBufferSize:531000 [junit4] 2> 1599548 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D46087,localpor= t=3D39836], receiveBufferSize=3D530904 [junit4] 2> 1599549 INFO (qtp327702480-14847) [ ] o.a.s.c.S.Reques= t [collection1_shard1_replica_t43] webapp=3D/d/w path=3D/select params=3D{= q=3D*:*&distrib=3Dfalse&tests=3DcheckShardConsistency&rows=3D0&wt=3Djavabin= &version=3D2} hits=3D0 status=3D0 QTime=3D0 [junit4] 2> 1601213 INFO (indexFetcher-6042-thread-1) [ ] o.a.s.h.= IndexFetcher Updated masterUrl to http://127.0.0.1:33589/d/w/collection1_sh= ard2_replica_t41/ [junit4] 2> 1601213 INFO (qtp946316246-14816) [ ] o.a.s.c.S.Reques= t [collection1_shard2_replica_t41] webapp=3D/d/w path=3D/replication param= s=3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} sta= tus=3D0 QTime=3D0 [junit4] 2> 1601213 INFO (indexFetcher-6042-thread-1) [ ] o.a.s.h.= IndexFetcher Master's generation: 1 [junit4] 2> 1601213 INFO (indexFetcher-6042-thread-1) [ ] o.a.s.h.= IndexFetcher Master's version: 0 [junit4] 2> 1601213 INFO (indexFetcher-6042-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's generation: 1 [junit4] 2> 1601213 INFO (indexFetcher-6042-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's version: 0 [junit4] 2> 1601551 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy accepted Socket[addr=3D/127.0.0.1,port=3D45958,localport=3D3476= 5], receiveBufferSize:531000 [junit4] 2> 1601551 INFO (SocketProxy-Acceptor-34765) [ ] o.a.s.c.= SocketProxy proxy connection Socket[addr=3D/127.0.0.1,port=3D46087,localpor= t=3D39876], receiveBufferSize=3D530904 [junit4] 2> 1601551 INFO (qtp327702480-14846) [ ] o.a.s.h.a.Collec= tionsHandler Invoked Collection Action :create with params pullReplicas=3D0= &maxShardsPerNode=3D1&collection.configName=3Dconf1&nrtReplicas=3D0&name=3D= c8n_crud_1x2&action=3DCREATE&numShards=3D1&tlogReplicas=3D2&wt=3Djavabin&ve= rsion=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1601552 INFO (OverseerThreadFactory-6000-thread-5) [ ]= o.a.s.c.CreateCollectionCmd Create collection c8n_crud_1x2 [junit4] 2> 1601655 INFO (qtp834275956-14885) [ ] o.a.s.h.a.CoreAd= minOperation core create command qt=3D/admin/cores&collection.configName=3D= conf1&newCollection=3Dtrue&name=3Dc8n_crud_1x2_shard1_replica_t1&action=3DC= REATE&numShards=3D1&collection=3Dc8n_crud_1x2&shard=3Dshard1&wt=3Djavabin&v= ersion=3D2&replicaType=3DTLOG [junit4] 2> 1601656 INFO (qtp327702480-14848) [ ] o.a.s.h.a.CoreAd= minOperation core create command qt=3D/admin/cores&collection.configName=3D= conf1&newCollection=3Dtrue&name=3Dc8n_crud_1x2_shard1_replica_t2&action=3DC= REATE&numShards=3D1&collection=3Dc8n_crud_1x2&shard=3Dshard1&wt=3Djavabin&v= ersion=3D2&replicaType=3DTLOG [junit4] 2> 1601763 INFO (zkCallback-3334-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/c8n_crud_1x2/state.json] for collection= [c8n_crud_1x2] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1601763 INFO (zkCallback-3328-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/c8n_crud_1x2/state.json] for collection= [c8n_crud_1x2] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1602665 INFO (qtp834275956-14885) [ ] o.a.s.c.SolrConf= ig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1602666 INFO (qtp327702480-14848) [ ] o.a.s.c.SolrConf= ig Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1602673 INFO (qtp834275956-14885) [ ] o.a.s.s.IndexSch= ema [c8n_crud_1x2_shard1_replica_t1] Schema name=3Dtest [junit4] 2> 1602673 INFO (qtp327702480-14848) [ ] o.a.s.s.IndexSch= ema [c8n_crud_1x2_shard1_replica_t2] Schema name=3Dtest [junit4] 2> 1602730 INFO (qtp327702480-14848) [ ] o.a.s.s.IndexSch= ema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 1602736 INFO (qtp327702480-14848) [ ] o.a.s.c.CoreCont= ainer Creating SolrCore 'c8n_crud_1x2_shard1_replica_t2' using configuratio= n from collection c8n_crud_1x2, trusted=3Dtrue [junit4] 2> 1602736 INFO (qtp327702480-14848) [ ] o.a.s.m.r.SolrJm= xReporter JMX monitoring for 'solr.core.c8n_crud_1x2.shard1.replica_t2' (re= gistry 'solr.core.c8n_crud_1x2.shard1.replica_t2') enabled at server: com.s= un.jmx.mbeanserver.JmxMBeanServer@6cdb1b64 [junit4] 2> 1602736 INFO (qtp327702480-14848) [ ] o.a.s.c.SolrCore= solr.RecoveryStrategy.Builder [junit4] 2> 1602736 INFO (qtp327702480-14848) [ ] o.a.s.c.SolrCore= [[c8n_crud_1x2_shard1_replica_t2] ] Opening new SolrCore at [/home/jenkins= /workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.= cloud.HttpPartitionTest_BE90AC88155A84BF-001/shard-2-001/cores/c8n_crud_1x2= _shard1_replica_t2], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J1/temp/solr.cloud.HttpPartitionTest_BE90AC= 88155A84BF-001/shard-2-001/cores/c8n_crud_1x2_shard1_replica_t2/data/] [junit4] 2> 1602738 INFO (qtp327702480-14848) [ ] o.a.s.u.RandomMe= rgePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMe= rgePolicy: [TieredMergePolicy: maxMergeAtOnce=3D30, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D45.302734375, floorSegmentMB=3D2.0224609375, fo= rceMergeDeletesPctAllowed=3D27.27224679176982, segmentsPerTier=3D12.0, maxC= FSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1602739 WARN (qtp327702480-14848) [ ] o.a.s.c.RequestH= andlers INVALID paramSet a in requestHandler {type =3D requestHandler,name = =3D /dump,class =3D DumpRequestHandler,attributes =3D {initParams=3Da, name= =3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a=3DA,b=3DB}}} [junit4] 2> 1602749 INFO (qtp834275956-14885) [ ] o.a.s.s.IndexSch= ema Loaded schema test/1.0 with uniqueid field id [junit4] 2> 1602760 INFO (qtp834275956-14885) [ ] o.a.s.c.CoreCont= ainer Creating SolrCore 'c8n_crud_1x2_shard1_replica_t1' using configuratio= n from collection c8n_crud_1x2, trusted=3Dtrue [junit4] 2> 1602760 INFO (qtp834275956-14885) [ ] o.a.s.m.r.SolrJm= xReporter JMX monitoring for 'solr.core.c8n_crud_1x2.shard1.replica_t1' (re= gistry 'solr.core.c8n_crud_1x2.shard1.replica_t1') enabled at server: com.s= un.jmx.mbeanserver.JmxMBeanServer@6cdb1b64 [junit4] 2> 1602761 INFO (qtp834275956-14885) [ ] o.a.s.c.SolrCore= solr.RecoveryStrategy.Builder [junit4] 2> 1602761 INFO ( [...truncated too long message...] ll] for registry solr.core.collMinRf_1x3.shard1.replica_t2 / com.codahale.m= etrics.MetricRegistry@5e59cbb0 [junit4] 2> 1619043 INFO (zkCallback-3334-thread-4) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for registry=3Dsolr.collection.col= lMinRf_1x3.shard1.leader, tag=3D704011771 [junit4] 2> 1619543 WARN (zkCallback-3334-thread-1) [ ] o.a.s.c.c.= ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [Keepe= rErrorCode =3D Session expired for /live_nodes] [junit4] 2> 1619544 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7a2848f7= {HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 1619544 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHan= dler@3140489e{/d/w,null,UNAVAILABLE} [junit4] 2> 1619545 ERROR (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registere= d, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server st= ate changes [junit4] 2> 1619545 INFO (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:38471 38471 [junit4] 2> 1634573 INFO (Thread-3072) [ ] o.a.s.c.ZkTestServer co= nnecting to 127.0.0.1:38471 38471 [junit4] 2> 1634574 WARN (Thread-3072) [ ] o.a.s.c.ZkTestServer Wa= tch limit violations:=20 [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2>=20 [junit4] 2> =096=09/solr/aliases.json [junit4] 2> =094=09/solr/security.json [junit4] 2> =094=09/solr/configs/conf1 [junit4] 2>=20 [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2>=20 [junit4] 2> =096=09/solr/clusterprops.json [junit4] 2> =096=09/solr/clusterstate.json [junit4] 2> =093=09/solr/collections/collection1/state.json [junit4] 2> =093=09/solr/collections/collMinRf_1x3/state.json [junit4] 2> =092=09/solr/collections/c8n_crud_1x2/state.json [junit4] 2> =092=09/solr/collections/collMinRf_1x3/leader_elect/shard1= /election/98556125738565644-core_node5-n_0000000000 [junit4] 2>=20 [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2>=20 [junit4] 2> =096=09/solr/live_nodes [junit4] 2> =096=09/solr/collections [junit4] 2> =094=09/solr/overseer/queue [junit4] 2> =094=09/solr/overseer/collection-queue-work [junit4] 2>=20 [junit4] 2> 1634574 WARN (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SocketProxy Closing 3 connections to: http://127.0= .0.1:33589/d/w, target: http://127.0.0.1:42751/d/w [junit4] 2> 1634574 WARN (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SocketProxy Closing 3 connections to: http://127.0= .0.1:36227/d/w, target: http://127.0.0.1:37081/d/w [junit4] 2> 1634574 WARN (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SocketProxy Closing 6 connections to: http://127.0= .0.1:35835/d/w, target: http://127.0.0.1:35693/d/w [junit4] 2> 1634574 WARN (TEST-HttpPartitionTest.test-seed#[BE90AC881= 55A84BF]) [ ] o.a.s.c.SocketProxy Closing 12 connections to: http://127.= 0.0.1:34765/d/w, target: http://127.0.0.1:46087/d/w [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DHttpPartition= Test -Dtests.method=3Dtest -Dtests.seed=3DBE90AC88155A84BF -Dtests.multipli= er=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Den-MS -Dtests.timezone=3DEtc/GM= T0 -Dtests.asserts=3Dtrue -Dtests.file.encoding=3DISO-8859-1 [junit4] FAILURE 44.2s J1 | HttpPartitionTest.test <<< [junit4] > Throwable #1: java.lang.AssertionError: Doc with id=3D1 no= t found in http://127.0.0.1:35835/d/w/collMinRf_1x3 due to: Path not found:= /id; rsp=3D{doc=3Dnull} [junit4] > =09at __randomizedtesting.SeedInfo.seed([BE90AC88155A84BF:= 36C49352BBA6E947]:0) [junit4] > =09at org.apache.solr.cloud.HttpPartitionTest.assertDocExi= sts(HttpPartitionTest.java:603) [junit4] > =09at org.apache.solr.cloud.HttpPartitionTest.assertDocsEx= istInAllReplicas(HttpPartitionTest.java:558) [junit4] > =09at org.apache.solr.cloud.HttpPartitionTest.testMinRf(Ht= tpPartitionTest.java:249) [junit4] > =09at org.apache.solr.cloud.HttpPartitionTest.test(HttpPar= titionTest.java:127) [junit4] > =09at java.base/jdk.internal.reflect.NativeMethodAccessorI= mpl.invoke0(Native Method) [junit4] > =09at java.base/jdk.internal.reflect.NativeMethodAccessorI= mpl.invoke(NativeMethodAccessorImpl.java:62) [junit4] > =09at java.base/jdk.internal.reflect.DelegatingMethodAcces= sorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit4] > =09at java.base/java.lang.reflect.Method.invoke(Method.jav= a:564) [junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase$Shards= RepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase= .java:993) [junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase$Shards= RepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968) [junit4] > =09at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/wo= rkspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.clo= ud.HttpPartitionTest_BE90AC88155A84BF-001 [junit4] 2> NOTE: test params are: codec=3DAsserting(Lucene70): {multi= Default=3DPostingsFormat(name=3DLuceneVarGapFixedInterval), a_t=3DFSTOrd50,= id=3DTestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50= (blocksize=3D128))), text=3DPostingsFormat(name=3DAsserting)}, docValues:{r= ange_facet_l_dv=3DDocValuesFormat(name=3DAsserting), _version_=3DDocValuesF= ormat(name=3DLucene70), range_facet_i_dv=3DDocValuesFormat(name=3DLucene70)= , intDvoDefault=3DDocValuesFormat(name=3DDirect), timestamp=3DDocValuesForm= at(name=3DLucene70)}, maxPointsInLeafNode=3D1830, maxMBSortInHeap=3D7.00241= 7133515667, sim=3DRandomSimilarity(queryNorm=3Dtrue): {}, locale=3Den-MS, t= imezone=3DEtc/GMT0 [junit4] 2> NOTE: Linux 4.10.0-27-generic amd64/Oracle Corporation 9 (= 64-bit)/cpus=3D8,threads=3D1,free=3D215370448,total=3D536870912 [junit4] 2> NOTE: All tests run in this JVM: [TestLegacyFieldReuse, Te= stHdfsCloudBackupRestore, SuggesterTSTTest, TestLeaderInitiatedRecoveryThre= ad, TestDocBasedVersionConstraints, ScriptEngineTest, TestClusterStateMutat= or, TestDistribDocBasedVersion, TestSegmentSorting, TestConfigsApi, BitVect= orTest, TestAuthorizationFramework, WrapperMergePolicyFactoryTest, TestEmbe= ddedSolrServerConstructors, TestFuzzyAnalyzedSuggestions, ImplicitSnitchTes= t, HdfsSyncSliceTest, DistributedFacetPivotLongTailTest, TestMaxScoreQueryP= arser, AssignBackwardCompatibilityTest, TestAnalyzeInfixSuggestions, ZkCont= rollerTest, TestManagedSchemaThreadSafety, DirectSolrSpellCheckerTest, Test= NoOpRegenerator, TestRawResponseWriter, TestCloudDeleteByQuery, IndexSchema= Test, HdfsLockFactoryTest, TestRestManager, BlockJoinFacetDistribTest, Test= CursorMarkWithoutUniqueKey, TestCustomDocTransformer, MoveReplicaTest, Test= CollectionsAPIViaSolrCloudCluster, SampleTest, TestOrdValues, TestSolrCloud= WithHadoopAuthPlugin, DeleteInactiveReplicaTest, TestQueryTypes, TestTlogRe= plica, DistributedIntervalFacetingTest, SolrGraphiteReporterTest, EnumField= Test, ZkCLITest, TestReloadDeadlock, SoftAutoCommitTest, MetricUtilsTest, T= estExactSharedStatsCache, TestSchemaNameResource, ShardRoutingCustomTest, H= LLSerializationTest, TestXIncludeConfig, ConnectionReuseTest, NoCacheHeader= Test, SystemInfoHandlerTest, SubstringBytesRefFilterTest, CollectionsAPIDis= tributedZkTest, TestRequestForwarding, ZkSolrClientTest, AtomicUpdatesTest,= OverseerTaskQueueTest, DOMUtilTest, DistributedQueueTest, UpdateRequestPro= cessorFactoryTest, TestChildDocTransformer, TestScoreJoinQPNoScore, TestUni= fiedSolrHighlighter, TestSubQueryTransformerDistrib, HdfsRecoverLeaseTest, = TestSolrJ, TestTrackingShardHandlerFactory, SolrSlf4jReporterTest, DocValue= sMultiTest, CleanupOldIndexTest, TestCoreDiscovery, TestSQLHandler, StatsRe= loadRaceTest, ShardRoutingTest, JSONWriterTest, QueryParsingTest, TestUpdat= e, SuggestComponentContextFilterQueryTest, BadComponentTest, TestSchemaless= BufferedUpdates, TestSolrIndexConfig, ConvertedLegacyTest, TestBM25Similari= tyFactory, TestReloadAndDeleteDocs, IgnoreCommitOptimizeUpdateProcessorFact= oryTest, TestConfigSetProperties, TestGraphMLResponseWriter, SpellCheckComp= onentTest, V2StandaloneTest, AlternateDirectoryTest, DocValuesTest, SolrMet= ricReporterTest, CollectionsAPISolrJTest, TestDynamicFieldCollectionResourc= e, ExitableDirectoryReaderTest, FileBasedSpellCheckerTest, TestRTGBase, Tes= tSearchPerf, TestAtomicUpdateErrorCases, JsonLoaderTest, SOLR749Test, Chaos= MonkeySafeLeaderTest, SliceStateTest, VersionInfoTest, TestFieldSortValues,= TlogReplayBufferedWhileIndexingTest, TestStressRecovery, TestConfigSetsAPI= ZkFailure, CSVRequestHandlerTest, LukeRequestHandlerTest, TestRandomRequest= Distribution, TestSolrConfigHandler, MoreLikeThisHandlerTest, TestMaxTokenL= enTokenizer, BlockDirectoryTest, BlobRepositoryCloudTest, TestDistributedGr= ouping, TermVectorComponentDistributedTest, TestRealTimeGet, TestJoin, Test= RangeQuery, SolrCmdDistributorTest, QueryElevationComponentTest, PeerSyncTe= st, TestFunctionQuery, BasicFunctionalityTest, TestLazyCores, CoreAdminHand= lerTest, SuggesterWFSTTest, TestWordDelimiterFilterFactory, QueryEqualityTe= st, SortByFunctionTest, TestRemoteStreaming, DistanceFunctionTest, SolrInfo= BeanTest, CacheHeaderTest, TestSurroundQueryParser, DisMaxRequestHandlerTes= t, TestValueSourceCache, TermVectorComponentTest, IndexSchemaRuntimeFieldTe= st, SolrPluginUtilsTest, ReturnFieldsTest, UniqFieldsUpdateProcessorFactory= Test, TestPartialUpdateDeduplication, TestLFUCache, AsyncCallRequestStatusR= esponseTest, CollectionStateFormat2Test, CollectionTooManyReplicasTest, Con= nectionManagerTest, DeleteLastCustomShardedReplicaTest, DeleteReplicaTest, = DistribCursorPagingTest, DistribJoinFromCollectionTest, DistributedVersionI= nfoTest, HttpPartitionTest] [junit4] Completed [474/732 (1!)] on J1 in 44.19s, 1 test, 1 failure <<<= FAILURES! [...truncated 37416 lines...] ------=_Part_150_551122485.1503849197881 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_150_551122485.1503849197881--