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 22D2C200CC3 for ; Sat, 15 Jul 2017 19:42:27 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id 20FBE167E4A; Sat, 15 Jul 2017 17:42:27 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (unknown [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 956FE167E3D for ; Sat, 15 Jul 2017 19:42:24 +0200 (CEST) Received: (qmail 54657 invoked by uid 500); 15 Jul 2017 17:42:23 -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 54647 invoked by uid 99); 15 Jul 2017 17:42:23 -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; Sat, 15 Jul 2017 17:42:23 +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 8BBB91A07AB for ; Sat, 15 Jul 2017 17:42:22 +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-eu.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id 84SjR3PWRkjE for ; Sat, 15 Jul 2017 17:42:04 +0000 (UTC) Received: from serv1.sd-datasolutions.de (serv1.sd-datasolutions.de [88.99.242.108]) by mx1-lw-eu.apache.org (ASF Mail Server at mx1-lw-eu.apache.org) with ESMTPS id 42CEB5F2AB for ; Sat, 15 Jul 2017 17:42:04 +0000 (UTC) Received: from serv1 (ip6-localhost [IPv6:::1]) by serv1.sd-datasolutions.de (Postfix) with ESMTP id 526C910800EF for ; Sat, 15 Jul 2017 17:41:58 +0000 (UTC) Date: Sat, 15 Jul 2017 17:41:37 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <1781625410.119.1500140518338.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS-EA] Lucene-Solr-master-Linux (32bit/jdk-9-ea+175) - Build # 20136 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_118_1017302733.1500140518302" X-Jenkins-Job: Lucene-Solr-master-Linux X-Jenkins-Result: FAILURE X-Priority: 5 (Low) archived-at: Sat, 15 Jul 2017 17:42:27 -0000 ------=_Part_118_1017302733.1500140518302 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/20136/ Java: 32bit/jdk-9-ea+175 -server -XX:+UseG1GC --illegal-access=3Ddeny 1 tests failed. FAILED: org.apache.solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest.te= st Error Message: Timed out waiting for replica core_node2 (1500139227759) to replicate from = leader core_node1 (1500139243738) Stack Trace: java.lang.AssertionError: Timed out waiting for replica core_node2 (1500139= 227759) to replicate from leader core_node1 (1500139243738) =09at __randomizedtesting.SeedInfo.seed([DD6974B43CA6B012:553D4B6E925ADDEA]= :0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForReplicatio= nFromReplicas(AbstractFullDistribZkTestBase.java:2133) =09at org.apache.solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest.test(= ChaosMonkeySafeLeaderWithPullReplicasTest.java:209) =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:985) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= Statement.evaluate(BaseDistributedSearchTestCase.java:960) =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 12456 lines...] [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderWithPullRepli= casTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-mast= er-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeader= WithPullReplicasTest_DD6974B43CA6B012-001/init-core-data-001 [junit4] 2> 1587607 WARN (SUITE-ChaosMonkeySafeLeaderWithPullReplicas= Test-seed#[DD6974B43CA6B012]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrack= ingSearchers: numOpens=3D1 numCloses=3D1 [junit4] 2> 1587607 INFO (SUITE-ChaosMonkeySafeLeaderWithPullReplicas= Test-seed#[DD6974B43CA6B012]-worker) [ ] o.a.s.SolrTestCaseJ4 Using Trie= Fields (NUMERIC_POINTS_SYSPROP=3Dfalse) w/NUMERIC_DOCVALUES_SYSPROP=3Dfalse [junit4] 2> 1587608 INFO (SUITE-ChaosMonkeySafeLeaderWithPullReplicas= Test-seed#[DD6974B43CA6B012]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized= ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(r= eason=3D"", ssl=3D0.0/0.0, value=3D0.0/0.0, clientAuth=3D0.0/0.0) [junit4] 2> 1587609 INFO (SUITE-ChaosMonkeySafeLeaderWithPullReplicas= Test-seed#[DD6974B43CA6B012]-worker) [ ] o.a.s.BaseDistributedSearchTest= Case Setting hostContext system property: /se/v [junit4] 2> 1587609 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ChaosMonkeySafeLeaderWithP= ullReplicasTest Starting ChaosMonkey test with 1 shards and 3 nodes [junit4] 2> 1587611 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkTestServer STARTING ZK T= EST SERVER [junit4] 2> 1587611 INFO (Thread-3469) [ ] o.a.s.c.ZkTestServer cl= ient port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1587611 INFO (Thread-3469) [ ] o.a.s.c.ZkTestServer St= arting server [junit4] 2> 1587614 ERROR (Thread-3469) [ ] 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> 1587711 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkTestServer start zk serv= er on port:40583 [junit4] 2> 1587723 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 1587724 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/schema15.xml to /configs/conf1/schema.xml [junit4] 2> 1587726 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf= 1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 1587727 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 1587728 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 1587729 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 1587730 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 1587737 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-= rates.json [junit4] 2> 1587738 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISO= Latin1Accent.txt [junit4] 2> 1587739 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 1587740 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractZkTestCase put /ho= me/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/src/test-files/solr= /collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 1587746 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractFullDistribZkTestB= ase Will use TLOG replicas unless explicitly asked otherwise [junit4] 2> 1587818 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server jetty-9.3.14.v20161= 028 [junit4] 2> 1587819 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.h.ContextHandler Started o= .e.j.s.ServletContextHandler@1df6489{/se/v,null,AVAILABLE} [junit4] 2> 1587821 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.AbstractConnector Started = ServerConnector@2cc603{SSL,[ssl, http/1.1]}{127.0.0.1:42709} [junit4] 2> 1587821 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server Started @1588797ms [junit4] 2> 1587821 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty = properties: {hostContext=3D/se/v, solr.data.dir=3D/home/jenkins/workspace/L= ucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosM= onkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/tempDir-001/contro= l/data, hostPort=3D42709, coreRootDirectory=3D/home/jenkins/workspace/Lucen= e-Solr-master-Linux/solr/build/solr-core/test/J2/../../../../../../../../..= /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/= J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B0= 12-001/control-001/cores} [junit4] 2> 1587821 ERROR (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.StartupLoggingUtils Missin= g Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1587821 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter ___ = _ Welcome to Apache Solr=E2=84=A2 version 8.0.0 [junit4] 2> 1587821 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter / __| _= __| |_ _ Starting in cloud mode on port null [junit4] 2> 1587821 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ = _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 1587821 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter |___/\_= __/_|_| Start time: 2017-07-15T17:20:15.727791Z [junit4] 2> 1587823 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter Loading= solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 1587823 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig Loading cont= ainer configuration from /home/jenkins/workspace/Lucene-Solr-master-Linux/s= olr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullRe= plicasTest_DD6974B43CA6B012-001/control-001/solr.xml [junit4] 2> 1587824 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig MBean server= found: com.sun.jmx.mbeanserver.JmxMBeanServer@1418a7, but no JMX reporters= were configured - adding default JMX reporter. [junit4] 2> 1587826 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkContainer Zookeeper clie= nt=3D127.0.0.1:40583/solr [junit4] 2> 1587854 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.Overseer Overseer (id=3Dnu= ll) closing [junit4] 2> 1587855 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.OverseerElectionContext I = am going to be the leader 127.0.0.1:42709_se%2Fv [junit4] 2> 1587855 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.Overseer Overseer (id=3D98= 313123628187653-127.0.0.1:42709_se%2Fv-n_0000000000) starting [junit4] 2> 1587857 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkController Register node= as live in ZooKeeper:/live_nodes/127.0.0.1:42709_se%2Fv [junit4] 2> 1587857 INFO (zkCallback-2418-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1587897 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jm= x.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1587900 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.= mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1587900 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.= jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1587901 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.CorePropertiesLocator Foun= d 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/= workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.c= loud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/control= -001/cores [junit4] 2> 1587911 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.c.ZkStateReader Updated li= ve nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1587911 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.s.i.ZkClientClusterStatePr= ovider Cluster at 127.0.0.1:40583/solr ready [junit4] 2> 1587940 INFO (qtp1153753-15270) [ ] o.a.s.h.a.Collecti= onsHandler Invoked Collection Action :create with params replicationFactor= =3D1&collection.configName=3Dconf1&name=3Dcontrol_collection&nrtReplicas=3D= 1&action=3DCREATE&numShards=3D1&createNodeSet=3D127.0.0.1:42709_se%252Fv&wt= =3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1587941 INFO (OverseerThreadFactory-7483-thread-1) [ ]= o.a.s.c.CreateCollectionCmd Create collection control_collection [junit4] 2> 1588047 INFO (qtp1153753-15277) [ ] o.a.s.h.a.CoreAdmi= nOperation core create command qt=3D/admin/cores&collection.configName=3Dco= nf1&newCollection=3Dtrue&name=3Dcontrol_collection_shard1_replica_n1&action= =3DCREATE&numShards=3D1&collection=3Dcontrol_collection&shard=3Dshard1&wt= =3Djavabin&version=3D2&replicaType=3DNRT [junit4] 2> 1588048 INFO (qtp1153753-15277) [ ] o.a.s.c.TransientS= olrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1588151 INFO (zkCallback-2418-thread-1) [ ] 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> 1589055 INFO (qtp1153753-15277) [ ] o.a.s.c.SolrConfig= Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1589063 INFO (qtp1153753-15277) [ ] o.a.s.s.IndexSchem= a [control_collection_shard1_replica_n1] Schema name=3Dtest [junit4] 2> 1589106 INFO (qtp1153753-15277) [ ] o.a.s.s.IndexSchem= a Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1589119 INFO (qtp1153753-15277) [ ] o.a.s.c.CoreContai= ner Creating SolrCore 'control_collection_shard1_replica_n1' using configur= ation from collection control_collection, trusted=3Dtrue [junit4] 2> 1589119 INFO (qtp1153753-15277) [ ] o.a.s.m.r.SolrJmxR= eporter JMX monitoring for 'solr.core.control_collection.shard1.replica_n1'= (registry 'solr.core.control_collection.shard1.replica_n1') enabled at ser= ver: com.sun.jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1589119 INFO (qtp1153753-15277) [ ] o.a.s.c.SolrCore s= olr.RecoveryStrategy.Builder [junit4] 2> 1589120 INFO (qtp1153753-15277) [ ] o.a.s.c.SolrCore [= [control_collection_shard1_replica_n1] ] Opening new SolrCore at [/home/jen= kins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/s= olr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/co= ntrol-001/cores/control_collection_shard1_replica_n1], dataDir=3D[/home/jen= kins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/../../= ../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/b= uild/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplica= sTest_DD6974B43CA6B012-001/control-001/cores/control_collection_shard1_repl= ica_n1/data/] [junit4] 2> 1589122 INFO (qtp1153753-15277) [ ] o.a.s.u.RandomMerg= ePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMerg= ePolicy: [TieredMergePolicy: maxMergeAtOnce=3D10, maxMergeAtOnceExplicit=3D= 10, maxMergedSegmentMB=3D2.728515625, floorSegmentMB=3D1.0537109375, forceM= ergeDeletesPctAllowed=3D9.49150832494291, segmentsPerTier=3D29.0, maxCFSSeg= mentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1589157 WARN (qtp1153753-15277) [ ] o.a.s.c.RequestHan= dlers 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> 1589200 INFO (qtp1153753-15277) [ ] o.a.s.u.UpdateHand= ler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 1589200 INFO (qtp1153753-15277) [ ] o.a.s.u.UpdateLog = Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH numRecordsToKee= p=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1589201 INFO (qtp1153753-15277) [ ] o.a.s.u.CommitTrac= ker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1589202 INFO (qtp1153753-15277) [ ] o.a.s.u.CommitTrac= ker Soft AutoCommit: disabled [junit4] 2> 1589203 INFO (qtp1153753-15277) [ ] o.a.s.u.RandomMerg= ePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMerg= ePolicy: [TieredMergePolicy: maxMergeAtOnce=3D37, maxMergeAtOnceExplicit=3D= 49, maxMergedSegmentMB=3D39.982421875, floorSegmentMB=3D0.7265625, forceMer= geDeletesPctAllowed=3D3.977644137257724, segmentsPerTier=3D33.0, maxCFSSegm= entSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.5811959463862607 [junit4] 2> 1589203 INFO (qtp1153753-15277) [ ] o.a.s.s.SolrIndexS= earcher Opening [Searcher@1eea3c1[control_collection_shard1_replica_n1] mai= n] [junit4] 2> 1589208 INFO (qtp1153753-15277) [ ] o.a.s.r.ManagedRes= ourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1589208 INFO (qtp1153753-15277) [ ] o.a.s.r.ManagedRes= ourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageI= O:path=3D/configs/conf1 [junit4] 2> 1589209 INFO (qtp1153753-15277) [ ] o.a.s.h.Replicatio= nHandler Commits will be reserved for 10000 [junit4] 2> 1589210 INFO (searcherExecutor-7486-thread-1) [ ] o.a.= s.c.SolrCore [control_collection_shard1_replica_n1] Registered new searcher= Searcher@1eea3c1[control_collection_shard1_replica_n1] main{ExitableDirect= oryReader(UninvertingDirectoryReader())} [junit4] 2> 1589210 INFO (qtp1153753-15277) [ ] o.a.s.u.UpdateLog = Could not find max version in index or recent updates, using new clock 1573= 009979726626816 [junit4] 2> 1589213 INFO (qtp1153753-15277) [ ] o.a.s.c.ShardLeade= rElectionContext Enough replicas found to continue. [junit4] 2> 1589213 INFO (qtp1153753-15277) [ ] o.a.s.c.ShardLeade= rElectionContext I may be the new leader - try and sync [junit4] 2> 1589213 INFO (qtp1153753-15277) [ ] o.a.s.c.SyncStrate= gy Sync replicas to https://127.0.0.1:42709/se/v/control_collection_shard1_= replica_n1/ [junit4] 2> 1589213 INFO (qtp1153753-15277) [ ] o.a.s.c.SyncStrate= gy Sync Success - now sync replicas to me [junit4] 2> 1589213 INFO (qtp1153753-15277) [ ] o.a.s.c.SyncStrate= gy https://127.0.0.1:42709/se/v/control_collection_shard1_replica_n1/ has n= o replicas [junit4] 2> 1589213 INFO (qtp1153753-15277) [ ] o.a.s.c.ShardLeade= rElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 1589214 INFO (qtp1153753-15277) [ ] o.a.s.c.ShardLeade= rElectionContext I am the new leader: https://127.0.0.1:42709/se/v/control_= collection_shard1_replica_n1/ shard1 [junit4] 2> 1589316 INFO (zkCallback-2418-thread-1) [ ] 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> 1589365 INFO (qtp1153753-15277) [ ] o.a.s.c.ZkControll= er I am the leader, no recovery necessary [junit4] 2> 1589368 INFO (qtp1153753-15277) [ ] o.a.s.s.HttpSolrCa= ll [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&co= llection.configName=3Dconf1&newCollection=3Dtrue&name=3Dcontrol_collection_= shard1_replica_n1&action=3DCREATE&numShards=3D1&collection=3Dcontrol_collec= tion&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DNRT} status=3D0 = QTime=3D1320 [junit4] 2> 1589369 INFO (qtp1153753-15270) [ ] o.a.s.h.a.Collecti= onsHandler Wait for new collection to be active for at most 30 seconds. Che= ck all shard replicas [junit4] 2> 1589467 INFO (zkCallback-2418-thread-1) [ ] 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> 1589942 INFO (OverseerCollectionConfigSetProcessor-983131= 23628187653-127.0.0.1:42709_se%2Fv-n_0000000000) [ ] o.a.s.c.OverseerTas= kQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doe= sn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1590369 INFO (qtp1153753-15270) [ ] o.a.s.s.HttpSolrCa= ll [admin] webapp=3Dnull path=3D/admin/collections params=3D{replicationFac= tor=3D1&collection.configName=3Dconf1&name=3Dcontrol_collection&nrtReplicas= =3D1&action=3DCREATE&numShards=3D1&createNodeSet=3D127.0.0.1:42709_se%252Fv= &wt=3Djavabin&version=3D2} status=3D0 QTime=3D2429 [junit4] 2> 1590376 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.c.ZkStateReader Updated li= ve nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1590377 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.s.i.ZkClientClusterStatePr= ovider Cluster at 127.0.0.1:40583/solr ready [junit4] 2> 1590377 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ChaosMonkey monkey: init -= expire sessions:false cause connection loss:false [junit4] 2> 1590380 INFO (qtp1153753-15275) [ ] o.a.s.h.a.Collecti= onsHandler Invoked Collection Action :create with params replicationFactor= =3D1&collection.configName=3Dconf1&name=3Dcollection1&nrtReplicas=3D1&actio= n=3DCREATE&numShards=3D1&createNodeSet=3D&stateFormat=3D1&wt=3Djavabin&vers= ion=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1590382 INFO (OverseerThreadFactory-7483-thread-2) [ ]= o.a.s.c.CreateCollectionCmd Create collection collection1 [junit4] 2> 1590383 WARN (OverseerThreadFactory-7483-thread-2) [ ]= o.a.s.c.CreateCollectionCmd It is unusual to create a collection (collecti= on1) without cores. [junit4] 2> 1590586 INFO (qtp1153753-15275) [ ] o.a.s.h.a.Collecti= onsHandler Wait for new collection to be active for at most 30 seconds. Che= ck all shard replicas [junit4] 2> 1590586 INFO (qtp1153753-15275) [ ] o.a.s.s.HttpSolrCa= ll [admin] webapp=3Dnull path=3D/admin/collections params=3D{replicationFac= tor=3D1&collection.configName=3Dconf1&name=3Dcollection1&nrtReplicas=3D1&ac= tion=3DCREATE&numShards=3D1&createNodeSet=3D&stateFormat=3D1&wt=3Djavabin&v= ersion=3D2} status=3D0 QTime=3D206 [junit4] 2> 1590673 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractFullDistribZkTestB= ase create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWit= hPullReplicasTest_DD6974B43CA6B012-001/shard-1-001 of type TLOG [junit4] 2> 1590673 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server jetty-9.3.14.v20161= 028 [junit4] 2> 1590674 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.h.ContextHandler Started o= .e.j.s.ServletContextHandler@4f59a{/se/v,null,AVAILABLE} [junit4] 2> 1590674 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.AbstractConnector Started = ServerConnector@51ab59{SSL,[ssl, http/1.1]}{127.0.0.1:36441} [junit4] 2> 1590674 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server Started @1591651ms [junit4] 2> 1590675 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty = properties: {hostContext=3D/se/v, solrconfig=3Dsolrconfig.xml, solr.data.di= r=3D/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/t= est/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43C= A6B012-001/tempDir-001/jetty1, hostPort=3D36441, coreRootDirectory=3D/home/= jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/../= ../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/sol= r/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullRepl= icasTest_DD6974B43CA6B012-001/shard-1-001/cores, replicaType=3DTLOG} [junit4] 2> 1590675 ERROR (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.StartupLoggingUtils Missin= g Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1590675 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter ___ = _ Welcome to Apache Solr=E2=84=A2 version 8.0.0 [junit4] 2> 1590675 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter / __| _= __| |_ _ Starting in cloud mode on port null [junit4] 2> 1590675 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ = _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 1590675 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter |___/\_= __/_|_| Start time: 2017-07-15T17:20:18.581517Z [junit4] 2> 1590677 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter Loading= solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 1590677 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig Loading cont= ainer configuration from /home/jenkins/workspace/Lucene-Solr-master-Linux/s= olr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullRe= plicasTest_DD6974B43CA6B012-001/shard-1-001/solr.xml [junit4] 2> 1590679 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig MBean server= found: com.sun.jmx.mbeanserver.JmxMBeanServer@1418a7, but no JMX reporters= were configured - adding default JMX reporter. [junit4] 2> 1590681 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkContainer Zookeeper clie= nt=3D127.0.0.1:40583/solr [junit4] 2> 1590685 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.c.ZkStateReader Updated li= ve nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1590685 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.Overseer Overseer (id=3Dnu= ll) closing [junit4] 2> 1590686 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkController Register node= as live in ZooKeeper:/live_nodes/127.0.0.1:36441_se%2Fv [junit4] 2> 1590686 INFO (zkCallback-2425-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1590686 INFO (zkCallback-2418-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1590686 INFO (zkCallback-2430-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1590789 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jm= x.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1590793 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.= mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1590793 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.= jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1590794 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.CorePropertiesLocator Foun= d 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/= workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.c= loud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/shard-1= -001/cores [junit4] 2> 1590806 INFO (qtp1153753-15277) [ ] o.a.s.h.a.Collecti= onsHandler Invoked Collection Action :addreplica with params node=3D127.0.0= .1:36441_se%252Fv&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dshar= d1&type=3DTLOG&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1590808 INFO (OverseerCollectionConfigSetProcessor-983131= 23628187653-127.0.0.1:42709_se%2Fv-n_0000000000) [ ] o.a.s.c.OverseerTas= kQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doe= sn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1590808 INFO (OverseerThreadFactory-7483-thread-3) [ ]= o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:36441_se%2Fv for creating = new replica [junit4] 2> 1590836 INFO (qtp19653279-15311) [ ] o.a.s.h.a.CoreAdm= inOperation core create command qt=3D/admin/cores&collection.configName=3Dc= onf1&name=3Dcollection1_shard1_replica_t0&action=3DCREATE&collection=3Dcoll= ection1&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DTLOG [junit4] 2> 1590836 INFO (qtp19653279-15311) [ ] o.a.s.c.Transient= SolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1591847 INFO (qtp19653279-15311) [ ] o.a.s.c.SolrConfi= g Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1591856 INFO (qtp19653279-15311) [ ] o.a.s.s.IndexSche= ma [collection1_shard1_replica_t0] Schema name=3Dtest [junit4] 2> 1591899 INFO (qtp19653279-15311) [ ] o.a.s.s.IndexSche= ma Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1591905 INFO (qtp19653279-15311) [ ] o.a.s.c.CoreConta= iner Creating SolrCore 'collection1_shard1_replica_t0' using configuration = from collection collection1, trusted=3Dtrue [junit4] 2> 1591905 INFO (qtp19653279-15311) [ ] o.a.s.m.r.SolrJmx= Reporter JMX monitoring for 'solr.core.collection1.shard1.replica_t0' (regi= stry 'solr.core.collection1.shard1.replica_t0') enabled at server: com.sun.= jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1591905 INFO (qtp19653279-15311) [ ] o.a.s.c.SolrCore = solr.RecoveryStrategy.Builder [junit4] 2> 1591905 INFO (qtp19653279-15311) [ ] o.a.s.c.SolrCore = [[collection1_shard1_replica_t0] ] Opening new SolrCore at [/home/jenkins/w= orkspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cl= oud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/shard-1-= 001/cores/collection1_shard1_replica_t0], dataDir=3D[/home/jenkins/workspac= e/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/../../../../../../.= ./../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-cor= e/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B= 43CA6B012-001/shard-1-001/cores/collection1_shard1_replica_t0/data/] [junit4] 2> 1591908 INFO (qtp19653279-15311) [ ] o.a.s.u.RandomMer= gePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMer= gePolicy: [TieredMergePolicy: maxMergeAtOnce=3D10, maxMergeAtOnceExplicit= =3D10, maxMergedSegmentMB=3D2.728515625, floorSegmentMB=3D1.0537109375, for= ceMergeDeletesPctAllowed=3D9.49150832494291, segmentsPerTier=3D29.0, maxCFS= SegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1591928 WARN (qtp19653279-15311) [ ] o.a.s.c.RequestHa= ndlers 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> 1591965 INFO (qtp19653279-15311) [ ] o.a.s.u.UpdateHan= dler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 1591965 INFO (qtp19653279-15311) [ ] o.a.s.u.UpdateLog= Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH numRecordsToKe= ep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1591966 INFO (qtp19653279-15311) [ ] o.a.s.u.CommitTra= cker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1591966 INFO (qtp19653279-15311) [ ] o.a.s.u.CommitTra= cker Soft AutoCommit: disabled [junit4] 2> 1591967 INFO (qtp19653279-15311) [ ] o.a.s.u.RandomMer= gePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMer= gePolicy: [TieredMergePolicy: maxMergeAtOnce=3D37, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D39.982421875, floorSegmentMB=3D0.7265625, force= MergeDeletesPctAllowed=3D3.977644137257724, segmentsPerTier=3D33.0, maxCFSS= egmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.5811959463862607 [junit4] 2> 1591967 INFO (qtp19653279-15311) [ ] o.a.s.s.SolrIndex= Searcher Opening [Searcher@5aa802[collection1_shard1_replica_t0] main] [junit4] 2> 1591968 INFO (qtp19653279-15311) [ ] o.a.s.r.ManagedRe= sourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1591968 INFO (qtp19653279-15311) [ ] o.a.s.r.ManagedRe= sourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorage= IO:path=3D/configs/conf1 [junit4] 2> 1591969 INFO (qtp19653279-15311) [ ] o.a.s.h.Replicati= onHandler Commits will be reserved for 10000 [junit4] 2> 1591970 INFO (searcherExecutor-7497-thread-1) [ ] o.a.= s.c.SolrCore [collection1_shard1_replica_t0] Registered new searcher Search= er@5aa802[collection1_shard1_replica_t0] main{ExitableDirectoryReader(Uninv= ertingDirectoryReader())} [junit4] 2> 1591970 INFO (qtp19653279-15311) [ ] o.a.s.u.UpdateLog= Could not find max version in index or recent updates, using new clock 157= 3009982620696576 [junit4] 2> 1591973 INFO (qtp19653279-15311) [ ] o.a.s.c.ShardLead= erElectionContext Enough replicas found to continue. [junit4] 2> 1591973 INFO (qtp19653279-15311) [ ] o.a.s.c.ShardLead= erElectionContext I may be the new leader - try and sync [junit4] 2> 1591973 INFO (qtp19653279-15311) [ ] o.a.s.c.SyncStrat= egy Sync replicas to https://127.0.0.1:36441/se/v/collection1_shard1_replic= a_t0/ [junit4] 2> 1591973 INFO (qtp19653279-15311) [ ] o.a.s.c.SyncStrat= egy Sync Success - now sync replicas to me [junit4] 2> 1591973 INFO (qtp19653279-15311) [ ] o.a.s.c.SyncStrat= egy https://127.0.0.1:36441/se/v/collection1_shard1_replica_t0/ has no repl= icas [junit4] 2> 1591973 INFO (qtp19653279-15311) [ ] o.a.s.c.ShardLead= erElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 1591973 INFO (qtp19653279-15311) [ ] o.a.s.c.ZkControl= ler collection1_shard1_replica_t0 stopping background replication from lead= er [junit4] 2> 1591974 INFO (qtp19653279-15311) [ ] o.a.s.c.ShardLead= erElectionContext I am the new leader: https://127.0.0.1:36441/se/v/collect= ion1_shard1_replica_t0/ shard1 [junit4] 2> 1592125 INFO (qtp19653279-15311) [ ] o.a.s.c.ZkControl= ler I am the leader, no recovery necessary [junit4] 2> 1592126 INFO (qtp19653279-15311) [ ] o.a.s.s.HttpSolrC= all [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&c= ollection.configName=3Dconf1&name=3Dcollection1_shard1_replica_t0&action=3D= CREATE&collection=3Dcollection1&shard=3Dshard1&wt=3Djavabin&version=3D2&rep= licaType=3DTLOG} status=3D0 QTime=3D1290 [junit4] 2> 1592128 INFO (qtp1153753-15277) [ ] o.a.s.s.HttpSolrCa= ll [admin] webapp=3Dnull path=3D/admin/collections params=3D{node=3D127.0.0= .1:36441_se%252Fv&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dshar= d1&type=3DTLOG&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1321 [junit4] 2> 1592199 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractFullDistribZkTestB= ase create jetty 2 in directory /home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWit= hPullReplicasTest_DD6974B43CA6B012-001/shard-2-001 of type PULL [junit4] 2> 1592200 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server jetty-9.3.14.v20161= 028 [junit4] 2> 1592201 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.h.ContextHandler Started o= .e.j.s.ServletContextHandler@e92bb{/se/v,null,AVAILABLE} [junit4] 2> 1592201 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.AbstractConnector Started = ServerConnector@1e45ba5{SSL,[ssl, http/1.1]}{127.0.0.1:36095} [junit4] 2> 1592201 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server Started @1593178ms [junit4] 2> 1592201 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty = properties: {hostContext=3D/se/v, solrconfig=3Dsolrconfig.xml, solr.data.di= r=3D/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/t= est/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43C= A6B012-001/tempDir-001/jetty2, hostPort=3D36095, coreRootDirectory=3D/home/= jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/../= ../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/sol= r/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullRepl= icasTest_DD6974B43CA6B012-001/shard-2-001/cores, replicaType=3DPULL} [junit4] 2> 1592201 ERROR (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.StartupLoggingUtils Missin= g Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1592201 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter ___ = _ Welcome to Apache Solr=E2=84=A2 version 8.0.0 [junit4] 2> 1592202 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter / __| _= __| |_ _ Starting in cloud mode on port null [junit4] 2> 1592202 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ = _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 1592202 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter |___/\_= __/_|_| Start time: 2017-07-15T17:20:20.108103Z [junit4] 2> 1592203 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter Loading= solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 1592203 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig Loading cont= ainer configuration from /home/jenkins/workspace/Lucene-Solr-master-Linux/s= olr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullRe= plicasTest_DD6974B43CA6B012-001/shard-2-001/solr.xml [junit4] 2> 1592205 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig MBean server= found: com.sun.jmx.mbeanserver.JmxMBeanServer@1418a7, but no JMX reporters= were configured - adding default JMX reporter. [junit4] 2> 1592207 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkContainer Zookeeper clie= nt=3D127.0.0.1:40583/solr [junit4] 2> 1592211 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.c.ZkStateReader Updated li= ve nodes from ZooKeeper... (0) -> (2) [junit4] 2> 1592211 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.Overseer Overseer (id=3Dnu= ll) closing [junit4] 2> 1592212 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkController Register node= as live in ZooKeeper:/live_nodes/127.0.0.1:36095_se%2Fv [junit4] 2> 1592213 INFO (zkCallback-2430-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1592213 INFO (zkCallback-2436-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1592213 INFO (zkCallback-2425-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1592213 INFO (zkCallback-2418-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1592357 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jm= x.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1592361 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.= mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1592361 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.= jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1592362 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.CorePropertiesLocator Foun= d 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/= workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.c= loud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/shard-2= -001/cores [junit4] 2> 1592382 INFO (qtp19653279-15318) [ ] o.a.s.h.a.Collect= ionsHandler Invoked Collection Action :addreplica with params node=3D127.0.= 0.1:36095_se%252Fv&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd1&type=3DPULL&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1592383 INFO (OverseerCollectionConfigSetProcessor-983131= 23628187653-127.0.0.1:42709_se%2Fv-n_0000000000) [ ] o.a.s.c.OverseerTas= kQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doe= sn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1592383 INFO (OverseerThreadFactory-7483-thread-4) [ ]= o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:36095_se%2Fv for creating = new replica [junit4] 2> 1592416 INFO (qtp20591503-15341) [ ] o.a.s.h.a.CoreAdm= inOperation core create command qt=3D/admin/cores&collection.configName=3Dc= onf1&name=3Dcollection1_shard1_replica_p1&action=3DCREATE&collection=3Dcoll= ection1&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DPULL [junit4] 2> 1592416 INFO (qtp20591503-15341) [ ] o.a.s.c.Transient= SolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1593433 INFO (qtp20591503-15341) [ ] o.a.s.c.SolrConfi= g Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1593449 INFO (qtp20591503-15341) [ ] o.a.s.s.IndexSche= ma [collection1_shard1_replica_p1] Schema name=3Dtest [junit4] 2> 1593498 INFO (qtp20591503-15341) [ ] o.a.s.s.IndexSche= ma Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1593505 INFO (qtp20591503-15341) [ ] o.a.s.c.CoreConta= iner Creating SolrCore 'collection1_shard1_replica_p1' using configuration = from collection collection1, trusted=3Dtrue [junit4] 2> 1593506 INFO (qtp20591503-15341) [ ] o.a.s.m.r.SolrJmx= Reporter JMX monitoring for 'solr.core.collection1.shard1.replica_p1' (regi= stry 'solr.core.collection1.shard1.replica_p1') enabled at server: com.sun.= jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1593506 INFO (qtp20591503-15341) [ ] o.a.s.c.SolrCore = solr.RecoveryStrategy.Builder [junit4] 2> 1593506 INFO (qtp20591503-15341) [ ] o.a.s.c.SolrCore = [[collection1_shard1_replica_p1] ] Opening new SolrCore at [/home/jenkins/w= orkspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cl= oud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/shard-2-= 001/cores/collection1_shard1_replica_p1], dataDir=3D[/home/jenkins/workspac= e/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/../../../../../../.= ./../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-cor= e/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B= 43CA6B012-001/shard-2-001/cores/collection1_shard1_replica_p1/data/] [junit4] 2> 1593508 INFO (qtp20591503-15341) [ ] o.a.s.u.RandomMer= gePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMer= gePolicy: [TieredMergePolicy: maxMergeAtOnce=3D10, maxMergeAtOnceExplicit= =3D10, maxMergedSegmentMB=3D2.728515625, floorSegmentMB=3D1.0537109375, for= ceMergeDeletesPctAllowed=3D9.49150832494291, segmentsPerTier=3D29.0, maxCFS= SegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1593526 WARN (qtp20591503-15341) [ ] o.a.s.c.RequestHa= ndlers 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> 1593558 INFO (qtp20591503-15341) [ ] o.a.s.u.CommitTra= cker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1593558 INFO (qtp20591503-15341) [ ] o.a.s.u.CommitTra= cker Soft AutoCommit: disabled [junit4] 2> 1593559 INFO (qtp20591503-15341) [ ] o.a.s.u.RandomMer= gePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMer= gePolicy: [TieredMergePolicy: maxMergeAtOnce=3D37, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D39.982421875, floorSegmentMB=3D0.7265625, force= MergeDeletesPctAllowed=3D3.977644137257724, segmentsPerTier=3D33.0, maxCFSS= egmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.5811959463862607 [junit4] 2> 1593560 INFO (qtp20591503-15341) [ ] o.a.s.s.SolrIndex= Searcher Opening [Searcher@1449e33[collection1_shard1_replica_p1] main] [junit4] 2> 1593561 INFO (qtp20591503-15341) [ ] o.a.s.r.ManagedRe= sourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1593575 INFO (qtp20591503-15341) [ ] o.a.s.r.ManagedRe= sourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorage= IO:path=3D/configs/conf1 [junit4] 2> 1593576 INFO (qtp20591503-15341) [ ] o.a.s.h.Replicati= onHandler Commits will be reserved for 10000 [junit4] 2> 1593576 INFO (qtp20591503-15341) [ ] o.a.s.c.ZkControl= ler collection1_shard1_replica_p1 starting background replication from lead= er [junit4] 2> 1593576 INFO (qtp20591503-15341) [ ] o.a.s.c.Replicate= FromLeader Will start replication from leader with poll interval: 0:0:7 [junit4] 2> 1593576 INFO (searcherExecutor-7508-thread-1) [ ] o.a.= s.c.SolrCore [collection1_shard1_replica_p1] Registered new searcher Search= er@1449e33[collection1_shard1_replica_p1] main{ExitableDirectoryReader(Unin= vertingDirectoryReader())} [junit4] 2> 1593577 INFO (qtp20591503-15341) [ ] o.a.s.h.Replicati= onHandler Poll scheduled at an interval of 7000ms [junit4] 2> 1593577 INFO (indexFetcher-7513-thread-1) [ ] o.a.s.h.= IndexFetcher Updated masterUrl to https://127.0.0.1:36441/se/v/collection1_= shard1_replica_t0/ [junit4] 2> 1593577 INFO (qtp20591503-15341) [ ] o.a.s.c.ZkControl= ler Core needs to recover:collection1_shard1_replica_p1 [junit4] 2> 1593577 INFO (updateExecutor-2433-thread-1) [ ] o.a.s.= u.DefaultSolrCoreState Running recovery [junit4] 2> 1593577 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=3Dtr= ue [junit4] 2> 1593578 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Publishing state of core [collection1_shard1_replica_p= 1] as recovering, leader is [https://127.0.0.1:36441/se/v/collection1_shard= 1_replica_t0/] and I am [https://127.0.0.1:36095/se/v/collection1_shard1_re= plica_p1/] [junit4] 2> 1593578 INFO (qtp20591503-15341) [ ] o.a.s.s.HttpSolrC= all [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&c= ollection.configName=3Dconf1&name=3Dcollection1_shard1_replica_p1&action=3D= CREATE&collection=3Dcollection1&shard=3Dshard1&wt=3Djavabin&version=3D2&rep= licaType=3DPULL} status=3D0 QTime=3D1161 [junit4] 2> 1593578 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting Replication Recovery. [junit4] 2> 1593578 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Stopping background replicate from leader process [junit4] 2> 1593578 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.ZkController collection1_shard1_replica_p1 stopping background replicat= ion from leader [junit4] 2> 1593578 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Attempting to replicate from [https://127.0.0.1:36441/= se/v/collection1_shard1_replica_t0/]. [junit4] 2> 1593580 INFO (qtp19653279-15317) [ ] o.a.s.c.S.Request= [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/replication params= =3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} stat= us=3D0 QTime=3D0 [junit4] 2> 1593580 INFO (indexFetcher-7513-thread-1) [ ] o.a.s.h.= IndexFetcher Master's generation: 1 [junit4] 2> 1593580 INFO (indexFetcher-7513-thread-1) [ ] o.a.s.h.= IndexFetcher Master's version: 0 [junit4] 2> 1593580 INFO (indexFetcher-7513-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's generation: 1 [junit4] 2> 1593580 INFO (indexFetcher-7513-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's version: 0 [junit4] 2> 1593580 INFO (qtp19653279-15318) [ ] o.a.s.s.HttpSolrC= all [admin] webapp=3Dnull path=3D/admin/collections params=3D{node=3D127.0.= 0.1:36095_se%252Fv&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd1&type=3DPULL&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1198 [junit4] 2> 1593581 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 start commit{_version_=3D1573009984309952512,optimize=3Dfalse,o= penSearcher=3Dfalse,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit= =3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 1593581 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1593581 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 end_commit_flush [junit4] 2> 1593582 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&commit=3Dtrue&sof= tCommit=3Dfalse&commit_end_point=3Dtrue&wt=3Djavabin&version=3D2}{commit=3D= } 0 0 [junit4] 2> 1593583 INFO (qtp19653279-15312) [ ] o.a.s.c.S.Request= [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/replication params= =3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} stat= us=3D0 QTime=3D0 [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.h.IndexFetcher Master's generation: 1 [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.h.IndexFetcher Master's version: 0 [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.h.IndexFetcher Slave's version: 0 [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Replication Recovery was successful. [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Restaring background replicate from leader process [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.ZkController collection1_shard1_replica_p1 starting background replicat= ion from leader [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.ReplicateFromLeader Will start replication from leader with poll interv= al: 0:0:7 [junit4] 2> 1593583 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.h.ReplicationHandler Poll scheduled at an interval of 7000ms [junit4] 2> 1593584 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 1593584 INFO (indexFetcher-7515-thread-1) [ ] o.a.s.h.= IndexFetcher Updated masterUrl to https://127.0.0.1:36441/se/v/collection1_= shard1_replica_t0/ [junit4] 2> 1593584 INFO (recoveryExecutor-2434-thread-1) [ ] o.a.= s.c.RecoveryStrategy Finished recovery process, successful=3D[true] [junit4] 2> 1593584 INFO (qtp19653279-15314) [ ] o.a.s.c.S.Request= [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/replication params= =3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} stat= us=3D0 QTime=3D0 [junit4] 2> 1593584 INFO (indexFetcher-7515-thread-1) [ ] o.a.s.h.= IndexFetcher Master's generation: 1 [junit4] 2> 1593584 INFO (indexFetcher-7515-thread-1) [ ] o.a.s.h.= IndexFetcher Master's version: 0 [junit4] 2> 1593584 INFO (indexFetcher-7515-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's generation: 1 [junit4] 2> 1593584 INFO (indexFetcher-7515-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's version: 0 [junit4] 2> 1593655 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractFullDistribZkTestB= ase create jetty 3 in directory /home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWit= hPullReplicasTest_DD6974B43CA6B012-001/shard-3-001 of type PULL [junit4] 2> 1593656 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server jetty-9.3.14.v20161= 028 [junit4] 2> 1593657 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.h.ContextHandler Started o= .e.j.s.ServletContextHandler@8495ed{/se/v,null,AVAILABLE} [junit4] 2> 1593657 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.AbstractConnector Started = ServerConnector@a737da{SSL,[ssl, http/1.1]}{127.0.0.1:37743} [junit4] 2> 1593657 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.Server Started @1594634ms [junit4] 2> 1593658 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty = properties: {hostContext=3D/se/v, solrconfig=3Dsolrconfig.xml, solr.data.di= r=3D/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/t= est/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43C= A6B012-001/tempDir-001/jetty3, hostPort=3D37743, coreRootDirectory=3D/home/= jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/../= ../../../../../../../../home/jenkins/workspace/Lucene-Solr-master-Linux/sol= r/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullRepl= icasTest_DD6974B43CA6B012-001/shard-3-001/cores, replicaType=3DPULL} [junit4] 2> 1593658 ERROR (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.StartupLoggingUtils Missin= g Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1593658 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter ___ = _ Welcome to Apache Solr=E2=84=A2 version 8.0.0 [junit4] 2> 1593658 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter / __| _= __| |_ _ Starting in cloud mode on port null [junit4] 2> 1593658 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ = _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 1593658 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter |___/\_= __/_|_| Start time: 2017-07-15T17:20:21.564600Z [junit4] 2> 1593660 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.s.SolrDispatchFilter Loading= solr.xml from SolrHome (not found in ZooKeeper) [junit4] 2> 1593660 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig Loading cont= ainer configuration from /home/jenkins/workspace/Lucene-Solr-master-Linux/s= olr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullRe= plicasTest_DD6974B43CA6B012-001/shard-3-001/solr.xml [junit4] 2> 1593662 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.SolrXmlConfig MBean server= found: com.sun.jmx.mbeanserver.JmxMBeanServer@1418a7, but no JMX reporters= were configured - adding default JMX reporter. [junit4] 2> 1593664 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkContainer Zookeeper clie= nt=3D127.0.0.1:40583/solr [junit4] 2> 1593665 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ = ] o.a.z.s.NIOServerCnxn caught end of stream exception [junit4] 2> EndOfStreamException: Unable to read additional data from = client sessionid 0x15d4743da9e000f, likely client has closed socket [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOSe= rverCnxn.java:239) [junit4] 2> =09at org.apache.zookeeper.server.NIOServerCnxnFactory.run= (NIOServerCnxnFactory.java:203) [junit4] 2> =09at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 1593668 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.c.ZkStateReader Updated li= ve nodes from ZooKeeper... (0) -> (3) [junit4] 2> 1593668 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.Overseer Overseer (id=3Dnu= ll) closing [junit4] 2> 1593669 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkController Register node= as live in ZooKeeper:/live_nodes/127.0.0.1:37743_se%2Fv [junit4] 2> 1593669 INFO (zkCallback-2425-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1593669 INFO (zkCallback-2418-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1593669 INFO (zkCallback-2442-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1593669 INFO (zkCallback-2430-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1593669 INFO (zkCallback-2436-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1593735 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jm= x.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1593739 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.= mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1593739 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.m.r.SolrJmxReporter JMX moni= toring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.= jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1593740 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.CorePropertiesLocator Foun= d 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-= Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/= workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.c= loud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/shard-3= -001/cores [junit4] 2> 1593764 INFO (qtp20591503-15348) [ ] o.a.s.h.a.Collect= ionsHandler Invoked Collection Action :addreplica with params node=3D127.0.= 0.1:37743_se%252Fv&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd1&type=3DPULL&wt=3Djavabin&version=3D2 and sendToOCPQueue=3Dtrue [junit4] 2> 1593766 INFO (OverseerThreadFactory-7483-thread-5) [ ]= o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:37743_se%2Fv for creating = new replica [junit4] 2> 1593766 INFO (OverseerCollectionConfigSetProcessor-983131= 23628187653-127.0.0.1:42709_se%2Fv-n_0000000000) [ ] o.a.s.c.OverseerTas= kQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000006 doe= sn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 1593795 INFO (qtp29458321-15377) [ ] o.a.s.h.a.CoreAdm= inOperation core create command qt=3D/admin/cores&collection.configName=3Dc= onf1&name=3Dcollection1_shard1_replica_p2&action=3DCREATE&collection=3Dcoll= ection1&shard=3Dshard1&wt=3Djavabin&version=3D2&replicaType=3DPULL [junit4] 2> 1593795 INFO (qtp29458321-15377) [ ] o.a.s.c.Transient= SolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 1594801 INFO (qtp29458321-15377) [ ] o.a.s.c.SolrConfi= g Using Lucene MatchVersion: 8.0.0 [junit4] 2> 1594809 INFO (qtp29458321-15377) [ ] o.a.s.s.IndexSche= ma [collection1_shard1_replica_p2] Schema name=3Dtest [junit4] 2> 1594855 INFO (qtp29458321-15377) [ ] o.a.s.s.IndexSche= ma Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1594861 INFO (qtp29458321-15377) [ ] o.a.s.c.CoreConta= iner Creating SolrCore 'collection1_shard1_replica_p2' using configuration = from collection collection1, trusted=3Dtrue [junit4] 2> 1594862 INFO (qtp29458321-15377) [ ] o.a.s.m.r.SolrJmx= Reporter JMX monitoring for 'solr.core.collection1.shard1.replica_p2' (regi= stry 'solr.core.collection1.shard1.replica_p2') enabled at server: com.sun.= jmx.mbeanserver.JmxMBeanServer@1418a7 [junit4] 2> 1594862 INFO (qtp29458321-15377) [ ] o.a.s.c.SolrCore = solr.RecoveryStrategy.Builder [junit4] 2> 1594862 INFO (qtp29458321-15377) [ ] o.a.s.c.SolrCore = [[collection1_shard1_replica_p2] ] Opening new SolrCore at [/home/jenkins/w= orkspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cl= oud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001/shard-3-= 001/cores/collection1_shard1_replica_p2], dataDir=3D[/home/jenkins/workspac= e/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/../../../../../../.= ./../../home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-cor= e/test/J2/temp/solr.cloud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B= 43CA6B012-001/shard-3-001/cores/collection1_shard1_replica_p2/data/] [junit4] 2> 1594865 INFO (qtp29458321-15377) [ ] o.a.s.u.RandomMer= gePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMer= gePolicy: [TieredMergePolicy: maxMergeAtOnce=3D10, maxMergeAtOnceExplicit= =3D10, maxMergedSegmentMB=3D2.728515625, floorSegmentMB=3D1.0537109375, for= ceMergeDeletesPctAllowed=3D9.49150832494291, segmentsPerTier=3D29.0, maxCFS= SegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0 [junit4] 2> 1594882 WARN (qtp29458321-15377) [ ] o.a.s.c.RequestHa= ndlers 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> 1594911 INFO (qtp29458321-15377) [ ] o.a.s.u.CommitTra= cker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1594911 INFO (qtp29458321-15377) [ ] o.a.s.u.CommitTra= cker Soft AutoCommit: disabled [junit4] 2> 1594912 INFO (qtp29458321-15377) [ ] o.a.s.u.RandomMer= gePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMer= gePolicy: [TieredMergePolicy: maxMergeAtOnce=3D37, maxMergeAtOnceExplicit= =3D49, maxMergedSegmentMB=3D39.982421875, floorSegmentMB=3D0.7265625, force= MergeDeletesPctAllowed=3D3.977644137257724, segmentsPerTier=3D33.0, maxCFSS= egmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.5811959463862607 [junit4] 2> 1594913 INFO (qtp29458321-15377) [ ] o.a.s.s.SolrIndex= Searcher Opening [Searcher@1a5c246[collection1_shard1_replica_p2] main] [junit4] 2> 1594913 INFO (qtp29458321-15377) [ ] o.a.s.r.ManagedRe= sourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1594914 INFO (qtp29458321-15377) [ ] o.a.s.r.ManagedRe= sourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorage= IO:path=3D/configs/conf1 [junit4] 2> 1594914 INFO (qtp29458321-15377) [ ] o.a.s.h.Replicati= onHandler Commits will be reserved for 10000 [junit4] 2> 1594915 INFO (qtp29458321-15377) [ ] o.a.s.c.ZkControl= ler collection1_shard1_replica_p2 starting background replication from lead= er [junit4] 2> 1594915 INFO (qtp29458321-15377) [ ] o.a.s.c.Replicate= FromLeader Will start replication from leader with poll interval: 0:0:7 [junit4] 2> 1594915 INFO (searcherExecutor-7522-thread-1) [ ] o.a.= s.c.SolrCore [collection1_shard1_replica_p2] Registered new searcher Search= er@1a5c246[collection1_shard1_replica_p2] main{ExitableDirectoryReader(Unin= vertingDirectoryReader())} [junit4] 2> 1594915 INFO (qtp29458321-15377) [ ] o.a.s.h.Replicati= onHandler Poll scheduled at an interval of 7000ms [junit4] 2> 1594915 INFO (indexFetcher-7527-thread-1) [ ] o.a.s.h.= IndexFetcher Updated masterUrl to https://127.0.0.1:36441/se/v/collection1_= shard1_replica_t0/ [junit4] 2> 1594915 INFO (qtp29458321-15377) [ ] o.a.s.c.ZkControl= ler Core needs to recover:collection1_shard1_replica_p2 [junit4] 2> 1594915 INFO (updateExecutor-2439-thread-1) [ ] o.a.s.= u.DefaultSolrCoreState Running recovery [junit4] 2> 1594916 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=3Dtr= ue [junit4] 2> 1594916 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Publishing state of core [collection1_shard1_replica_p= 2] as recovering, leader is [https://127.0.0.1:36441/se/v/collection1_shard= 1_replica_t0/] and I am [https://127.0.0.1:37743/se/v/collection1_shard1_re= plica_p2/] [junit4] 2> 1594916 INFO (qtp29458321-15377) [ ] o.a.s.s.HttpSolrC= all [admin] webapp=3Dnull path=3D/admin/cores params=3D{qt=3D/admin/cores&c= ollection.configName=3Dconf1&name=3Dcollection1_shard1_replica_p2&action=3D= CREATE&collection=3Dcollection1&shard=3Dshard1&wt=3Djavabin&version=3D2&rep= licaType=3DPULL} status=3D0 QTime=3D1121 [junit4] 2> 1594916 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting Replication Recovery. [junit4] 2> 1594916 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Stopping background replicate from leader process [junit4] 2> 1594916 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.ZkController collection1_shard1_replica_p2 stopping background replicat= ion from leader [junit4] 2> 1594916 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Attempting to replicate from [https://127.0.0.1:36441/= se/v/collection1_shard1_replica_t0/]. [junit4] 2> 1594918 INFO (qtp20591503-15348) [ ] o.a.s.s.HttpSolrC= all [admin] webapp=3Dnull path=3D/admin/collections params=3D{node=3D127.0.= 0.1:37743_se%252Fv&action=3DADDREPLICA&collection=3Dcollection1&shard=3Dsha= rd1&type=3DPULL&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1153 [junit4] 2> 1594918 INFO (qtp19653279-15373) [ ] o.a.s.c.S.Request= [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/replication params= =3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} stat= us=3D0 QTime=3D0 [junit4] 2> 1594918 INFO (indexFetcher-7527-thread-1) [ ] o.a.s.h.= IndexFetcher Master's generation: 1 [junit4] 2> 1594919 INFO (indexFetcher-7527-thread-1) [ ] o.a.s.h.= IndexFetcher Master's version: 0 [junit4] 2> 1594919 INFO (indexFetcher-7527-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's generation: 1 [junit4] 2> 1594919 INFO (indexFetcher-7527-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's version: 0 [junit4] 2> 1594919 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.SolrTestCaseJ4 ###Starting t= est [junit4] 2> 1594919 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 start commit{_version_=3D1573009985712947200,optimize=3Dfalse,o= penSearcher=3Dfalse,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit= =3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 1594920 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1594920 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.AbstractFullDistribZkTestB= ase Not turning on auto soft commit [junit4] 2> 1594920 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 end_commit_flush [junit4] 2> 1594920 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{waitSearcher=3Dtrue&openSearcher=3Dfalse&commit=3Dtrue&sof= tCommit=3Dfalse&commit_end_point=3Dtrue&wt=3Djavabin&version=3D2}{commit=3D= } 0 0 [junit4] 2> 1594921 INFO (qtp19653279-15372) [ ] o.a.s.c.S.Request= [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/replication params= =3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} stat= us=3D0 QTime=3D0 [junit4] 2> 1594921 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.h.IndexFetcher Master's generation: 1 [junit4] 2> 1594921 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.h.IndexFetcher Master's version: 0 [junit4] 2> 1594921 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 1594921 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.h.IndexFetcher Slave's version: 0 [junit4] 2> 1594922 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Replication Recovery was successful. [junit4] 2> 1594922 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Restaring background replicate from leader process [junit4] 2> 1594922 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.ZkController collection1_shard1_replica_p2 starting background replicat= ion from leader [junit4] 2> 1594922 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.ReplicateFromLeader Will start replication from leader with poll interv= al: 0:0:7 [junit4] 2> 1594923 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.h.ReplicationHandler Poll scheduled at an interval of 7000ms [junit4] 2> 1594923 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 1594923 INFO (indexFetcher-7529-thread-1) [ ] o.a.s.h.= IndexFetcher Updated masterUrl to https://127.0.0.1:36441/se/v/collection1_= shard1_replica_t0/ [junit4] 2> 1594923 INFO (qtp1153753-15277) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2}{deleteByQuery=3D*:* (-1573= 009985716092928)} 0 1 [junit4] 2> 1594924 INFO (qtp19653279-15317) [ ] o.a.s.c.S.Request= [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/replication params= =3D{qt=3D/replication&wt=3Djavabin&version=3D2&command=3Dindexversion} stat= us=3D0 QTime=3D0 [junit4] 2> 1594924 INFO (indexFetcher-7529-thread-1) [ ] o.a.s.h.= IndexFetcher Master's generation: 1 [junit4] 2> 1594924 INFO (indexFetcher-7529-thread-1) [ ] o.a.s.h.= IndexFetcher Master's version: 0 [junit4] 2> 1594924 INFO (indexFetcher-7529-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's generation: 1 [junit4] 2> 1594924 INFO (indexFetcher-7529-thread-1) [ ] o.a.s.h.= IndexFetcher Slave's version: 0 [junit4] 2> 1594924 INFO (recoveryExecutor-2440-thread-1) [ ] o.a.= s.c.RecoveryStrategy Finished recovery process, successful=3D[true] [junit4] 2> 1594928 INFO (qtp19653279-15317) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{deleteByQuery=3D*:* (-1573009985= 718190080)} 0 4 [junit4] 2> 1594929 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ChaosMonkey monkey: starti= ng [junit4] 2> 1594929 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ChaosMonkey monkey: Jetty = will not commit on close [junit4] 2> 1594930 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 start commit{_version_=3D1573009985724481536,optimize=3Dfalse,o= penSearcher=3Dtrue,waitSearcher=3Dfalse,expungeDeletes=3Dfalse,softCommit= =3Dfalse,prepareCommit=3Dfalse} [junit4] 2> 1594930 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1594930 INFO (qtp19653279-15373) [ ] o.a.s.u.DirectUpd= ateHandler2 end_commit_flush [junit4] 2> 1594930 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{waitSearcher=3Dfalse&commit=3Dtrue&softCommit=3Dfalse&wt= =3Djavabin&version=3D2}{commit=3D} 0 0 [junit4] 2> 1594931 INFO (qtp1153753-15273) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-0 = (1573009985723432960)]} 0 2 [junit4] 2> 1594932 INFO (qtp1153753-15273) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[1-0 = (1573009985726578688)]} 0 0 [junit4] 2> 1594933 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-0 (1573009985726578688)= ]} 0 1 [junit4] 2> 1594934 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[1-0 (1573009985728675840)= ]} 0 0 [junit4] 2> 1594936 INFO (qtp1153753-15270) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[1-1 = (1573009985729724416)]} 0 0 [junit4] 2> 1594936 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[1-1 (1573009985730772992)= ]} 0 0 [junit4] 2> 1594937 INFO (qtp1153753-15275) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-1 = (1573009985730772992)]} 0 0 [junit4] 2> 1594937 INFO (qtp1153753-15277) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[1-2 = (1573009985731821568)]} 0 0 [junit4] 2> 1594937 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-1 (1573009985731821568)= ]} 0 0 [junit4] 2> 1594938 INFO (qtp19653279-15311) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[1-2 (1573009985731821569)= ]} 0 0 [junit4] 2> 1594938 INFO (qtp1153753-15275) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[1= -0 (-1573009985732870144)]} 0 0 [junit4] 2> 1594939 INFO (qtp1153753-15276) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-2 = (1573009985732870145)]} 0 0 [junit4] 2> 1594940 INFO (qtp19653279-15311) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[1-0 (-1573009985734967= 296)]} 0 0 [junit4] 2> 1594940 INFO (qtp1153753-15270) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[1-3 = (1573009985734967296)]} 0 0 [junit4] 2> 1594940 INFO (qtp19653279-15372) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-2 (1573009985734967297)= ]} 0 0 [junit4] 2> 1594941 INFO (qtp1153753-15277) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[0= -0 (-1573009985736015872)]} 0 0 [junit4] 2> 1594941 INFO (qtp19653279-15312) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[0-0 (-1573009985736015= 873)]} 0 0 [junit4] 2> 1594942 INFO (qtp19653279-15314) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[1-3 (1573009985736015872)= ]} 0 0 [junit4] 2> 1594942 INFO (qtp1153753-15277) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-3 = (1573009985737064448)]} 0 0 [junit4] 2> 1594942 INFO (qtp1153753-15276) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[1= -2 (-1573009985737064449)]} 0 0 [junit4] 2> 1594942 INFO (qtp19653279-15314) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-3 (1573009985737064448)= ]} 0 0 [junit4] 2> 1594942 INFO (qtp19653279-15312) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[1-2 (-1573009985737064= 449)]} 0 0 [junit4] 2> 1594943 INFO (qtp1153753-15270) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[0= -2 (-1573009985738113024)]} 0 0 [junit4] 2> 1594943 INFO (qtp19653279-15372) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[0-2 (-1573009985738113= 024)]} 0 0 [junit4] 2> 1594943 INFO (qtp1153753-15275) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-4 = (1573009985738113025)]} 0 0 [junit4] 2> 1594944 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-4 (1573009985739161600)= ]} 0 0 [junit4] 2> 1594945 INFO (qtp1153753-15275) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-5 = (1573009985739161600)]} 0 0 [junit4] 2> 1594946 INFO (qtp19653279-15317) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-5 (1573009985740210176)= ]} 0 0 [junit4] 2> 1594946 INFO (qtp1153753-15276) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[0= -3 (-1573009985741258752)]} 0 0 [junit4] 2> 1594947 INFO (qtp19653279-15314) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[0-3 (-1573009985742307= 328)]} 0 0 [junit4] 2> 1594947 INFO (qtp1153753-15270) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-6 = (1573009985742307328)]} 0 0 [junit4] 2> 1594948 INFO (qtp1153753-15273) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[1-4 = (1573009985742307329)]} 0 0 [junit4] 2> 1594950 INFO (qtp19653279-15311) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-6 (1573009985743355904)= ]} 0 1 [junit4] 2> 1594950 INFO (qtp19653279-15312) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[1-4 (1573009985743355905)= ]} 0 1 [junit4] 2> 1594950 INFO (qtp1153753-15277) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-7 = (1573009985745453056)]} 0 0 [junit4] 2> 1594953 INFO (qtp1153753-15275) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[1-5 = (1573009985747550208)]} 0 0 [junit4] 2> 1594953 INFO (qtp19653279-15372) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-7 (1573009985747550208)= ]} 0 0 [junit4] 2> 1594953 INFO (qtp1153753-15276) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[0= -6 (-1573009985748598784)]} 0 0 [junit4] 2> 1594954 INFO (qtp19653279-15317) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[0-6 (-1573009985749647= 360)]} 0 0 [junit4] 2> 1594955 INFO (qtp1153753-15276) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-8 = (1573009985749647360)]} 0 0 [junit4] 2> 1594955 INFO (qtp19653279-15314) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-8 (1573009985750695936)= ]} 0 0 [junit4] 2> 1594956 INFO (qtp1153753-15276) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[0= -7 (-1573009985751744512)]} 0 0 [junit4] 2> 1594956 INFO (qtp19653279-15314) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[0-7 (-1573009985751744= 512)]} 0 0 [junit4] 2> 1594958 INFO (qtp19653279-15312) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[1-5 (1573009985752793088)= ]} 0 0 [junit4] 2> 1594958 INFO (qtp1153753-15270) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[1= -3 (-1573009985753841664)]} 0 0 [junit4] 2> 1594958 INFO (qtp1153753-15276) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-9 = (1573009985753841665)]} 0 0 [junit4] 2> 1594959 INFO (qtp19653279-15372) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[1-3 (-1573009985754890= 240)]} 0 0 [junit4] 2> 1594959 INFO (qtp19653279-15373) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[0-9 (1573009985754890241)= ]} 0 0 [junit4] 2> 1594959 INFO (qtp1153753-15277) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[0= -8 (-1573009985754890241)]} 0 0 [junit4] 2> 1594959 INFO (qtp1153753-15275) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[1-6 = (1573009985754890240)]} 0 0 [junit4] 2> 1594960 INFO (qtp19653279-15317) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{delete=3D[0-8 (-1573009985755938= 816)]} 0 0 [junit4] 2> 1594961 INFO (qtp1153753-15275) [ ] o.a.s.u.p.LogUpdat= eProcessorFactory [control_collection_shard1_replica_n1] webapp=3D/se/v pa= th=3D/update params=3D{wt=3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-10= (1573009985756987392)]} 0 0 [junit4] 2> 1594962 INFO (qtp19653279-15372) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1_shard1_replica_t0] webapp=3D/se/v path=3D/= update params=3D{wt=3Djavabin&version=3D2}{add=3D[1-6 (1573009985758035968)= ]} 0 0 [junit4] 2> 1594963 INFO (qtp19653279-15314) [ ] o.a.s.u.p.LogUpda= teProces [...truncated too long message...] TEST-ChaosMonkeySafeLeaderWithPullReplicasTest.test-seed#[DD6974B43CA6B012]= ) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@a737da{SSL,[ssl,= http/1.1]}{127.0.0.1:0} [junit4] 2> 1776027 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.e.j.s.h.ContextHandler Stopped o= .e.j.s.ServletContextHandler@8495ed{/se/v,null,UNAVAILABLE} [junit4] 2> 1776028 ERROR (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.z.s.ZooKeeperServer ZKShutdown= Handler is not registered, so ZooKeeper server won't take any action on ERR= OR or SHUTDOWN server state changes [junit4] 2> 1776032 INFO (TEST-ChaosMonkeySafeLeaderWithPullReplicasT= est.test-seed#[DD6974B43CA6B012]) [ ] o.a.s.c.ZkTestServer connecting to= 127.0.0.1:40583 40583 [junit4] 2> 1776067 INFO (Thread-3469) [ ] o.a.s.c.ZkTestServer co= nnecting to 127.0.0.1:40583 40583 [junit4] 2> 1776067 WARN (Thread-3469) [ ] 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> =093=09/solr/collections/collection1/state.json [junit4] 2>=20 [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2>=20 [junit4] 2> =096=09/solr/clusterstate.json [junit4] 2> =096=09/solr/clusterprops.json [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> =094=09/solr/overseer/queue-work [junit4] 2>=20 [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DChaosMonkeySa= feLeaderWithPullReplicasTest -Dtests.method=3Dtest -Dtests.seed=3DDD6974B43= CA6B012 -Dtests.multiplier=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Dnl-SR -= Dtests.timezone=3DEurope/Kirov -Dtests.asserts=3Dtrue -Dtests.file.encoding= =3DUTF-8 [junit4] FAILURE 188s J2 | ChaosMonkeySafeLeaderWithPullReplicasTest.te= st <<< [junit4] > Throwable #1: java.lang.AssertionError: Timed out waiting = for replica core_node2 (1500139227759) to replicate from leader core_node1 = (1500139243738) [junit4] > =09at __randomizedtesting.SeedInfo.seed([DD6974B43CA6B012:= 553D4B6E925ADDEA]:0) [junit4] > =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.= waitForReplicationFromReplicas(AbstractFullDistribZkTestBase.java:2133) [junit4] > =09at org.apache.solr.cloud.ChaosMonkeySafeLeaderWithPullR= eplicasTest.test(ChaosMonkeySafeLeaderWithPullReplicasTest.java:209) [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:985) [junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase$Shards= RepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960) [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/J2/temp/solr.clo= ud.ChaosMonkeySafeLeaderWithPullReplicasTest_DD6974B43CA6B012-001 [junit4] 2> Jul 15, 2017 5:23:23 PM com.carrotsearch.randomizedtesting= .ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 3 leaked thre= ad(s). [junit4] 2> NOTE: test params are: codec=3DAsserting(Lucene70): {rnd_b= =3DLucene50(blocksize=3D128), a_t=3DFST50, a_i=3DLucene50(blocksize=3D128),= id=3DLucene50(blocksize=3D128)}, docValues:{_version_=3DDocValuesFormat(na= me=3DMemory)}, maxPointsInLeafNode=3D409, maxMBSortInHeap=3D5.6831741112413= 29, sim=3DRandomSimilarity(queryNorm=3Dtrue): {}, locale=3Dnl-SR, timezone= =3DEurope/Kirov [junit4] 2> NOTE: Linux 4.10.0-26-generic i386/Oracle Corporation 9 (3= 2-bit)/cpus=3D8,threads=3D1,free=3D134114984,total=3D536870912 [junit4] 2> NOTE: All tests run in this JVM: [XsltUpdateRequestHandler= Test, HdfsTlogReplayBufferedWhileIndexingTest, NotRequiredUniqueKeyTest, Tr= iLevelCompositeIdRoutingTest, TestGroupingSearch, BadIndexSchemaTest, TermV= ectorComponentDistributedTest, MetricsHandlerTest, BasicDistributedZk2Test,= TestCollectionAPI, PrimitiveFieldTypeTest, HdfsNNFailoverTest, TestMiniSol= rCloudCluster, TestScoreJoinQPScore, TestUniqueKeyFieldResource, TestDistri= butedStatsComponentCardinality, PreAnalyzedFieldManagedSchemaCloudTest, Tes= tStressInPlaceUpdates, SolrIndexMetricsTest, JSONWriterTest, TestPivotHelpe= rCode, HttpSolrCallGetCoreTest, DirectoryFactoryTest, DateMathParserTest, T= estSuggestSpellingConverter, SolrSlf4jReporterTest, UpdateLogTest, TestUnin= vertingReader, SpellCheckCollatorWithCollapseTest, TestFoldingMultitermQuer= y, BaseCdcrDistributedZkTest, BasicAuthStandaloneTest, SuggesterFSTTest, Co= llectionsAPISolrJTest, SearchHandlerTest, RecoveryZkTest, TestZkChroot, Tes= tCloudInspectUtil, QueryResultKeyTest, TestRestoreCore, TestStressReorder, = TestSolrDeletionPolicy2, SimplePostToolTest, MultiTermTest, MergeStrategyTe= st, SimpleMLTQParserTest, TestJmxIntegration, CopyFieldTest, ShardSplitTest= , RegexBoostProcessorTest, TestRawResponseWriter, TestIndexSearcher, TestCo= nfigSetsAPIZkFailure, DeleteInactiveReplicaTest, PathHierarchyTokenizerFact= oryTest, TestQueryWrapperFilter, TestDistribDocBasedVersion, TestNamedUpdat= eProcessors, TestSolr4Spatial2, SolrCoreCheckLockOnStartupTest, TestFiltere= dDocIdSet, TestLegacyTerms, TestFastWriter, TestStandardQParsers, Substring= BytesRefFilterTest, SparseHLLTest, DocExpirationUpdateProcessorFactoryTest,= TimeZoneUtilsTest, RollingRestartTest, ResponseLogComponentTest, PingReque= stHandlerTest, TestCloudSchemaless, TestRequestStatusCollectionAPI, TestClo= udNestedDocsSort, FullHLLTest, TestSolrCoreProperties, HighlighterMaxOffset= Test, TestDefaultStatsCache, TestRTimerTree, TestHdfsCloudBackupRestore, De= leteReplicaTest, TestManagedSchema, TestDelegationWithHadoopAuth, OverseerT= est, DateFieldTest, TestRecovery, MinimalSchemaTest, TestNRTOpen, ChangedSc= hemaMergeTest, UnloadDistributedZkTest, TestOverriddenPrefixQueryForCustomF= ieldType, TestFieldCacheSortRandom, TestSimpleTextCodec, CdcrReplicationHan= dlerTest, DocumentBuilderTest, FullSolrCloudDistribCmdsTest, ReplaceNodeTes= t, TestTrie, LeaderFailoverAfterPartitionTest, TestLMJelinekMercerSimilarit= yFactory, TestFieldTypeResource, HdfsRestartWhileUpdatingTest, TestDFRSimil= arityFactory, TestExactStatsCache, PeerSyncReplicationTest, TestReRankQPars= erPlugin, TestReload, TestSortByMinMaxFunction, TestFieldCollectionResource= , SpellPossibilityIteratorTest, TestSearcherReuse, ChaosMonkeyNothingIsSafe= WithPullReplicasTest, CachingDirectoryFactoryTest, TestLeaderInitiatedRecov= eryThread, TestPullReplicaErrorHandling, SolrInfoBeanTest, SolrGangliaRepor= terTest, BasicZkTest, TestRandomFaceting, ZkSolrClientTest, AutoCommitTest,= TestDistributedGrouping, TestFaceting, TestHashPartitioner, TestStressVers= ions, HardAutoCommitTest, TestCoreContainer, SimpleFacetsTest, StatsCompone= ntTest, QueryElevationComponentTest, TestSort, TestFunctionQuery, BasicFunc= tionalityTest, TestLazyCores, DirectUpdateHandlerTest, TestBadConfig, ShowF= ileRequestHandlerTest, DistributedQueryElevationComponentTest, SuggesterTes= t, SpatialFilterTest, SuggesterWFSTTest, TestCSVLoader, PolyFieldTest, NoCa= cheHeaderTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, T= estUpdate, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest,= StatelessScriptUpdateProcessorFactoryTest, TestSurroundQueryParser, TestQu= eryUtils, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, Xm= lUpdateRequestHandlerTest, TermVectorComponentTest, MoreLikeThisHandlerTest= , FieldAnalysisRequestHandlerTest, LoggingHandlerTest, IndexSchemaTest, Upd= ateRequestProcessorFactoryTest, TestCSVResponseWriter, TestAnalyzedSuggesti= ons, TestPHPSerializedResponseWriter, SearchHandlerTest, SOLR749Test, TestQ= uerySenderListener, TestSolrIndexConfig, TestQuerySenderNoQuery, SolrIndexC= onfigTest, TestStressRecovery, TestUtils, FileUtilsTest, TestRTGBase, SolrT= estCaseJ4Test, TestDistributedMissingSort, TestTolerantSearch, TestJettySol= rRunner, ConnectionReuseTest, CdcrReplicationDistributedZkTest, ChaosMonkey= SafeLeaderWithPullReplicasTest] [junit4] Completed [502/728 (1!)] on J2 in 188.74s, 1 test, 1 failure <<= < FAILURES! [...truncated 789 lines...] [junit4] JVM J2: stdout was not empty, see: /home/jenkins/workspace/Luce= ne-Solr-master-Linux/solr/build/solr-core/test/temp/junit4-J2-20170715_1653= 46_9065370384945365913649.sysout [junit4] >>> JVM J2 emitted unexpected output (verbatim) ---- [junit4] java.lang.OutOfMemoryError: Java heap space [junit4] Dumping heap to /home/jenkins/workspace/Lucene-Solr-master-Linu= x/heapdumps/java_pid12058.hprof ... [junit4] Heap dump file created [334936433 bytes in 0.597 secs] [junit4] <<< JVM J2: EOF ---- [...truncated 7532 lines...] BUILD FAILED /home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:810: The followi= ng error occurred while executing this line: /home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:762: Some of the= tests produced a heap dump, but did not fail. Maybe a suppressed OutOfMemo= ryError? Dumps created: * java_pid12058.hprof Total time: 70 minutes 34 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts [WARNINGS] Skipping publisher since build result is FAILURE Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any ------=_Part_118_1017302733.1500140518302 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_118_1017302733.1500140518302--