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 AF536200CE1 for ; Thu, 31 Aug 2017 11:02:39 +0200 (CEST) Received: by cust-asf.ponee.io (Postfix) id AD94D16ADB8; Thu, 31 Aug 2017 09:02:39 +0000 (UTC) Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by cust-asf.ponee.io (Postfix) with SMTP id 0824016ADB7 for ; Thu, 31 Aug 2017 11:02:36 +0200 (CEST) Received: (qmail 9786 invoked by uid 500); 31 Aug 2017 09:02:35 -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 9776 invoked by uid 99); 31 Aug 2017 09:02:35 -0000 Received: from pnap-us-west-generic-nat.apache.org (HELO spamd3-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 31 Aug 2017 09:02:35 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd3-us-west.apache.org (ASF Mail Server at spamd3-us-west.apache.org) with ESMTP id CB205182CA1 for ; Thu, 31 Aug 2017 09:02:34 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd3-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 (spamd3-us-west.apache.org [10.40.0.10]) (amavisd-new, port 10024) with ESMTP id T8LD1yQI8GNH for ; Thu, 31 Aug 2017 09:02:15 +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 ESMTP id 3BA7E5FBEA for ; Thu, 31 Aug 2017 09:02:15 +0000 (UTC) Received: from serv1 (ip6-localhost [IPv6:::1]) by serv1.sd-datasolutions.de (Postfix) with ESMTP id 8801A1080149 for ; Thu, 31 Aug 2017 09:02:15 +0000 (UTC) Date: Thu, 31 Aug 2017 09:01:03 +0000 (UTC) From: Policeman Jenkins Server To: dev@lucene.apache.org Message-ID: <479735589.61.1504170135558.JavaMail.jenkins@serv1.sd-datasolutions.de> In-Reply-To: <1871018506.49.1504153107292.JavaMail.jenkins@serv1.sd-datasolutions.de> References: <1871018506.49.1504153107292.JavaMail.jenkins@serv1.sd-datasolutions.de> Subject: [JENKINS-EA] Lucene-Solr-6.6-Linux (64bit/jdk-9-ea+181) - Build # 119 - Still Unstable! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_60_1915134791.1504170135533" X-Jenkins-Job: Lucene-Solr-6.6-Linux X-Jenkins-Result: UNSTABLE X-Priority: 5 (Low) archived-at: Thu, 31 Aug 2017 09:02:39 -0000 ------=_Part_60_1915134791.1504170135533 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Linux/119/ Java: 64bit/jdk-9-ea+181 -XX:-UseCompressedOops -XX:+UseG1GC --illegal-acce= ss=3Ddeny 1 tests failed. FAILED: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test Error Message: document count mismatch. control=3D691 sum(shards)=3D685 cloudClient=3D685 Stack Trace: java.lang.AssertionError: document count mismatch. control=3D691 sum(shard= s)=3D685 cloudClient=3D685 =09at __randomizedtesting.SeedInfo.seed([8CAE2226992DF5FD:4FA1DFC37D19805]:= 0) =09at org.junit.Assert.fail(Assert.java:93) =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsist= ency(AbstractFullDistribZkTestBase.java:1323) =09at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test(ChaosMonkeyNo= thingIsSafeTest.java:226) =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:992) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= Statement.evaluate(BaseDistributedSearchTestCase.java:967) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:49) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:45) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:64) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:47) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java: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 12544 lines...] [junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.6-= Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafe= Test_8CAE2226992DF5FD-001/init-core-data-001 [junit4] 2> 1284002 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8C= AE2226992DF5FD]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields [junit4] 2> 1284002 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8C= AE2226992DF5FD]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) = and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bug= Url=3D"https://issues.apache.org/jira/browse/SOLR-5776") [junit4] 2> 1284002 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8C= AE2226992DF5FD]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting = hostContext system property: / [junit4] 2> 1284004 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1284006 INFO (Thread-3543) [ ] o.a.s.c.ZkTestServer cl= ient port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1284006 INFO (Thread-3543) [ ] o.a.s.c.ZkTestServer St= arting server [junit4] 2> 1284011 ERROR (Thread-3543) [ ] 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> 1284106 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkTestServer start zk server on port:46= 749 [junit4] 2> 1284110 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml [junit4] 2> 1284111 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/schema15.xml to /configs/conf1/schema.xml [junit4] 2> 1284111 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.sni= ppet.randomindexconfig.xml [junit4] 2> 1284112 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 1284112 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 1284112 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/currency.xml to /configs/conf1/currency.xml [junit4] 2> 1284113 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 1284113 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json [junit4] 2> 1284114 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 1284115 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 1284115 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/con= f/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 1284191 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties fi= le to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/te= st/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/con= trol-001/cores/collection1 [junit4] 2> 1284192 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1284193 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.Servle= tContextHandler@2f6d6b29{/,null,AVAILABLE} [junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnect= or@54b4044{HTTP/1.1,[http/1.1]}{127.0.0.1:=E1=81=83=E1=81=85=E1=81=86=E1=81= =87=E1=81=81} [junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @=E1=81=81=E1=81=82=E1= =81=88=E1=81=86=E1=81=85=E1=81=87=E1=81=81ms [junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {= hostContext=3D/, solr.data.dir=3D/home/jenkins/workspace/Lucene-Solr-6.6-Li= nux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTe= st_8CAE2226992DF5FD-001/tempDir-001/control/data, hostPort=3D35671, coreRoo= tDirectory=3D/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-= core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-= 6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIs= SafeTest_8CAE2226992DF5FD-001/control-001/cores} [junit4] 2> 1284194 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option= solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ We= lcome to Apache Solr=E2=84=A2 version 6.6.1 [junit4] 2> 1284195 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ St= arting in cloud mode on port null [junit4] 2> 1284195 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| In= stall dir: null [junit4] 2> 1284195 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| St= art time: 2017-08-31T08:38:29.550044Z [junit4] 2> 1284198 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml fro= m SolrHome (not found in ZooKeeper) [junit4] 2> 1284198 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configu= ration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-c= ore/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-0= 01/control-001/solr.xml [junit4] 2> 1284202 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShard= Handler HTTP client with params: socketTimeout=3D340000&connTimeout=3D45000= &retry=3Dtrue [junit4] 2> 1284202 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.= 1:46749/solr [junit4] 2> 1284208 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1284209 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.OverseerElectionContext I am going to b= e the leader 127.0.0.1:35671_ [junit4] 2> 1284209 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=3D985772005367480= 36-127.0.0.1:35671_-n_0000000000) starting [junit4] 2> 1284211 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in Z= ooKeeper:/live_nodes/127.0.0.1:35671_ [junit4] 2> 1284214 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 1284232 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core defi= nitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene= -Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNot= hingIsSafeTest_8CAE2226992DF5FD-001/control-001/cores [junit4] 2> 1284232 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [colle= ction1] [junit4] 2> 1284233 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transien= t cores [junit4] 2> 1284234 INFO (OverseerStateUpdate-98577200536748036-127.0= .0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new nod= e to shard shard=3Dshard1 [junit4] 2> 1285241 WARN (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.Config Beginning with Solr 5.5, is deprecated, use instead. [junit4] 2> 1285241 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 1285254 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 1285364 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1285413 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.CoreContainer Creating SolrCore 'collection1' using configuration from = collection control_collection, trusted=3Dtrue [junit4] 2> 1285413 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 1285414 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/worksp= ace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.Chao= sMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/control-001/cores/collection1= ], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr= -core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr= -6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingI= sSafeTest_8CAE2226992DF5FD-001/control-001/cores/collection1/data/] [junit4] 2> 1285414 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Se= rver: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420 [junit4] 2> 1285416 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D48, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0] [junit4] 2> 1285521 WARN (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.c.RequestHandlers INVALID paramSet a in requestHandler {type =3D requestH= andler,name =3D /dump,class =3D DumpRequestHandler,attributes =3D {initPara= ms=3Da, name=3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a= =3DA,b=3DB}}} [junit4] 2> 1285547 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.Up= dateLog [junit4] 2> 1285547 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.u.UpdateLog Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH n= umRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1285548 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1285548 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1285548 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D11, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.0] [junit4] 2> 1285549 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.s.SolrIndexSearcher Opening [Searcher@34e0f71c[collection1] main] [junit4] 2> 1285549 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /c= onfigs/conf1 [junit4] 2> 1285549 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using Zoo= KeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 1285550 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 1285550 INFO (searcherExecutor-5046-thread-1) [ ] o.a.= s.c.SolrCore [collection1] Registered new searcher Searcher@34e0f71c[collec= tion1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1285550 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.= s.u.UpdateLog Could not find max version in index or recent updates, using = new clock 1577235210205921280 [junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.SyncStrategy Sync replicas to http://127.0.0.1:35671/collection1/ [junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.SyncStrategy http://127.0.0.1:35671/collection1/ has no replicas [junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext Found all replicas participating in election, = clear LIR [junit4] 2> 1285554 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:35671/co= llection1/ shard1 [junit4] 2> 1285705 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.= c.ZkController I am the leader, no recovery necessary [junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from= ZooKeeper... (0) -> (1) [junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluste= r at 127.0.0.1:46749/solr ready [junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessi= ons:false cause connection loss:false [junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating = collection1 with stateFormat=3D2 [junit4] 2> 1285810 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties fi= le to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/te= st/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/sha= rd-1-001/cores/collection1 [junit4] 2> 1285810 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create je= tty 1 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992= DF5FD-001/shard-1-001 [junit4] 2> 1285810 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1285811 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.Servle= tContextHandler@61856d9c{/,null,AVAILABLE} [junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnect= or@511abcbe{HTTP/1.1,[http/1.1]}{127.0.0.1:=E1=81=83=E1=81=86=E1=81=88=E1= =81=87=E1=81=85} [junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @=E1=81=81=E1=81=82=E1= =81=88=E1=81=88=E1=81=81=E1=81=88=E1=81=89ms [junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {= hostContext=3D/, solrconfig=3Dsolrconfig.xml, solr.data.dir=3D/home/jenkins= /workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.clo= ud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty1, ho= stPort=3D36875, coreRootDirectory=3D/home/jenkins/workspace/Lucene-Solr-6.6= -Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins= /workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.clo= ud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores} [junit4] 2> 1285812 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option= solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ We= lcome to Apache Solr=E2=84=A2 version 6.6.1 [junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ St= arting in cloud mode on port null [junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| In= stall dir: null [junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| St= art time: 2017-08-31T08:38:31.167769Z [junit4] 2> 1285814 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml fro= m SolrHome (not found in ZooKeeper) [junit4] 2> 1285814 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configu= ration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-c= ore/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-0= 01/shard-1-001/solr.xml [junit4] 2> 1285817 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShard= Handler HTTP client with params: socketTimeout=3D340000&connTimeout=3D45000= &retry=3Dtrue [junit4] 2> 1285817 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.= 1:46749/solr [junit4] 2> 1285821 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from= ZooKeeper... (0) -> (1) [junit4] 2> 1285821 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1285822 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in Z= ooKeeper:/live_nodes/127.0.0.1:36875_ [junit4] 2> 1285823 INFO (zkCallback-2074-thread-2) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1285825 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1285826 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 1285851 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core defi= nitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene= -Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNot= hingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores [junit4] 2> 1285851 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [colle= ction1] [junit4] 2> 1285851 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transien= t cores [junit4] 2> 1285854 INFO (OverseerStateUpdate-98577200536748036-127.0= .0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new nod= e to shard shard=3Dshard2 [junit4] 2> 1285955 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeCreated path:/collections/collection1/state.json] for collection [col= lection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 1286864 WARN (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.Config Beginning with Solr 5.5, is deprecated, use instead. [junit4] 2> 1286865 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 1286875 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 1286954 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1286968 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.CoreContainer Creating SolrCore 'collection1' using configuration from = collection collection1, trusted=3Dtrue [junit4] 2> 1286969 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 1286969 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/worksp= ace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.Chao= sMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores/collection1= ], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr= -core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr= -6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingI= sSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores/collection1/data/] [junit4] 2> 1286969 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Se= rver: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420 [junit4] 2> 1286970 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D48, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0] [junit4] 2> 1287069 WARN (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.c.RequestHandlers INVALID paramSet a in requestHandler {type =3D requestH= andler,name =3D /dump,class =3D DumpRequestHandler,attributes =3D {initPara= ms=3Da, name=3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a= =3DA,b=3DB}}} [junit4] 2> 1287087 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.Up= dateLog [junit4] 2> 1287088 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.u.UpdateLog Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH n= umRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1287088 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1287088 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1287089 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D11, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.0] [junit4] 2> 1287089 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.s.SolrIndexSearcher Opening [Searcher@38707c64[collection1] main] [junit4] 2> 1287090 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /c= onfigs/conf1 [junit4] 2> 1287090 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using Zoo= KeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 1287090 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 1287090 INFO (searcherExecutor-5057-thread-1) [ ] o.a.= s.c.SolrCore [collection1] Registered new searcher Searcher@38707c64[collec= tion1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1287091 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.= s.u.UpdateLog Could not find max version in index or recent updates, using = new clock 1577235211821776896 [junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.SyncStrategy Sync replicas to http://127.0.0.1:36875/collection1/ [junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.SyncStrategy http://127.0.0.1:36875/collection1/ has no replicas [junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext Found all replicas participating in election, = clear LIR [junit4] 2> 1287095 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36875/co= llection1/ shard2 [junit4] 2> 1287196 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 1287245 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.= c.ZkController I am the leader, no recovery necessary [junit4] 2> 1287350 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [2]) [junit4] 2> 1287432 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties fi= le to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/te= st/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/sha= rd-2-001/cores/collection1 [junit4] 2> 1287432 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create je= tty 2 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992= DF5FD-001/shard-2-001 [junit4] 2> 1287433 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.Servle= tContextHandler@18c5422e{/,null,AVAILABLE} [junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnect= or@419e10e3{HTTP/1.1,[http/1.1]}{127.0.0.1:=E1=81=84=E1=81=81=E1=81=89=E1= =81=89=E1=81=85} [junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @=E1=81=81=E1=81=82=E1= =81=88=E1=81=89=E1=81=88=E1=81=81=E1=81=81ms [junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {= hostContext=3D/, solrconfig=3Dsolrconfig.xml, solr.data.dir=3D/home/jenkins= /workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.clo= ud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty2, ho= stPort=3D41995, coreRootDirectory=3D/home/jenkins/workspace/Lucene-Solr-6.6= -Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSaf= eTest_8CAE2226992DF5FD-001/shard-2-001/cores} [junit4] 2> 1287434 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option= solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ We= lcome to Apache Solr=E2=84=A2 version 6.6.1 [junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ St= arting in cloud mode on port null [junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| In= stall dir: null [junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| St= art time: 2017-08-31T08:38:32.790209Z [junit4] 2> 1287441 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml fro= m SolrHome (not found in ZooKeeper) [junit4] 2> 1287441 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configu= ration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-c= ore/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-0= 01/shard-2-001/solr.xml [junit4] 2> 1287445 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShard= Handler HTTP client with params: socketTimeout=3D340000&connTimeout=3D45000= &retry=3Dtrue [junit4] 2> 1287445 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.= 1:46749/solr [junit4] 2> 1287449 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from= ZooKeeper... (0) -> (2) [junit4] 2> 1287450 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1287450 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in Z= ooKeeper:/live_nodes/127.0.0.1:41995_ [junit4] 2> 1287453 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1287453 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1287453 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1287453 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 1287470 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core defi= nitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992= DF5FD-001/shard-2-001/cores [junit4] 2> 1287470 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [colle= ction1] [junit4] 2> 1287471 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transien= t cores [junit4] 2> 1287471 INFO (OverseerStateUpdate-98577200536748036-127.0= .0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new nod= e to shard shard=3Dshard1 [junit4] 2> 1287572 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1287573 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1288476 WARN (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.Config Beginning with Solr 5.5, is deprecated, use instead. [junit4] 2> 1288476 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 1288492 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 1288536 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.CoreContainer Creating SolrCore 'collection1' using configuration from = collection collection1, trusted=3Dtrue [junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/worksp= ace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.Chao= sMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001/cores/collection1= ], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr= -core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD= -001/shard-2-001/cores/collection1/data/] [junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Se= rver: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420 [junit4] 2> 1288551 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D48, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0] [junit4] 2> 1288575 WARN (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.c.RequestHandlers INVALID paramSet a in requestHandler {type =3D requestH= andler,name =3D /dump,class =3D DumpRequestHandler,attributes =3D {initPara= ms=3Da, name=3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a= =3DA,b=3DB}}} [junit4] 2> 1288595 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.Up= dateLog [junit4] 2> 1288595 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.u.UpdateLog Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH n= umRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1288603 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1288603 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1288604 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D11, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.0] [junit4] 2> 1288604 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.s.SolrIndexSearcher Opening [Searcher@3b9aba89[collection1] main] [junit4] 2> 1288604 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /c= onfigs/conf1 [junit4] 2> 1288605 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using Zoo= KeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 1288605 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 1288605 INFO (searcherExecutor-5068-thread-1) [ ] o.a.= s.c.SolrCore [collection1] Registered new searcher Searcher@3b9aba89[collec= tion1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1288606 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.= s.u.UpdateLog Could not find max version in index or recent updates, using = new clock 1577235213410369536 [junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.SyncStrategy Sync replicas to http://127.0.0.1:41995/collection1/ [junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.SyncStrategy http://127.0.0.1:41995/collection1/ has no replicas [junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext Found all replicas participating in election, = clear LIR [junit4] 2> 1288609 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41995/co= llection1/ shard1 [junit4] 2> 1288710 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1288710 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1288714 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.= c.ZkController I am the leader, no recovery necessary [junit4] 2> 1288815 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1288815 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [3]) [junit4] 2> 1289025 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties fi= le to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/te= st/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/sha= rd-3-001/cores/collection1 [junit4] 2> 1289026 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create je= tty 3 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992= DF5FD-001/shard-3-001 [junit4] 2> 1289026 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1289027 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.Servle= tContextHandler@e005ad4{/,null,AVAILABLE} [junit4] 2> 1289027 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnect= or@36ade7e7{HTTP/1.1,[http/1.1]}{127.0.0.1:=E1=81=84=E1=81=85=E1=81=80=E1= =81=82=E1=81=83} [junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @=E1=81=81=E1=81=82=E1= =81=89=E1=81=81=E1=81=84=E1=81=80=E1=81=85ms [junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {= hostContext=3D/, solrconfig=3Dsolrconfig.xml, solr.data.dir=3D/home/jenkins= /workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.clo= ud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty3, ho= stPort=3D45023, coreRootDirectory=3D/home/jenkins/workspace/Lucene-Solr-6.6= -Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins= /workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.clo= ud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores} [junit4] 2> 1289028 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option= solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ We= lcome to Apache Solr=E2=84=A2 version 6.6.1 [junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ St= arting in cloud mode on port null [junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| In= stall dir: null [junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| St= art time: 2017-08-31T08:38:34.383605Z [junit4] 2> 1289029 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml fro= m SolrHome (not found in ZooKeeper) [junit4] 2> 1289029 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configu= ration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-c= ore/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-0= 01/shard-3-001/solr.xml [junit4] 2> 1289033 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShard= Handler HTTP client with params: socketTimeout=3D340000&connTimeout=3D45000= &retry=3Dtrue [junit4] 2> 1289034 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.= 1:46749/solr [junit4] 2> 1289037 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from= ZooKeeper... (0) -> (3) [junit4] 2> 1289038 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1289039 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in Z= ooKeeper:/live_nodes/127.0.0.1:45023_ [junit4] 2> 1289039 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1289039 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1289039 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1289039 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1289039 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 1289061 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core defi= nitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene= -Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNot= hingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores [junit4] 2> 1289061 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [colle= ction1] [junit4] 2> 1289062 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transien= t cores [junit4] 2> 1289063 INFO (OverseerStateUpdate-98577200536748036-127.0= .0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new nod= e to shard shard=3Dshard2 [junit4] 2> 1289164 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1289164 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1289164 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1290069 WARN (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.Config Beginning with Solr 5.5, is deprecated, use instead. [junit4] 2> 1290069 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 1290085 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 1290152 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1290158 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.CoreContainer Creating SolrCore 'collection1' using configuration from = collection collection1, trusted=3Dtrue [junit4] 2> 1290158 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 1290158 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/worksp= ace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.Chao= sMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores/collection1= ], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr= -core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr= -6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingI= sSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores/collection1/data/] [junit4] 2> 1290159 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Se= rver: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420 [junit4] 2> 1290160 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D48, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0] [junit4] 2> 1290179 WARN (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.c.RequestHandlers INVALID paramSet a in requestHandler {type =3D requestH= andler,name =3D /dump,class =3D DumpRequestHandler,attributes =3D {initPara= ms=3Da, name=3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a= =3DA,b=3DB}}} [junit4] 2> 1290199 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.Up= dateLog [junit4] 2> 1290199 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.u.UpdateLog Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH n= umRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D11, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.0] [junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.s.SolrIndexSearcher Opening [Searcher@175e64d5[collection1] main] [junit4] 2> 1290201 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /c= onfigs/conf1 [junit4] 2> 1290201 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using Zoo= KeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 1290201 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 1290202 INFO (searcherExecutor-5079-thread-1) [ ] o.a.= s.c.SolrCore [collection1] Registered new searcher Searcher@175e64d5[collec= tion1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1290202 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.= s.u.UpdateLog Could not find max version in index or recent updates, using = new clock 1577235215083896832 [junit4] 2> 1290204 INFO (coreZkRegister-5073-thread-1) [ ] o.a.s.= c.ZkController Core needs to recover:collection1 [junit4] 2> 1290204 INFO (updateExecutor-2093-thread-1) [ ] o.a.s.= u.DefaultSolrCoreState Running recovery [junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=3Dtr= ue [junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy ###### startupVersions=3D[[]] [junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy Begin buffering updates. core=3D[collection1] [junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, = leader is [http://127.0.0.1:36875/collection1/] and I am [http://127.0.0.1:= 45023/collection1/] [junit4] 2> 1290205 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:368= 75]; [WaitForState: action=3DPREPRECOVERY&core=3Dcollection1&nodeName=3D127= .0.0.1:45023_&coreNodeName=3Dcore_node3&state=3Drecovering&checkLive=3Dtrue= &onlyIfLeader=3Dtrue&onlyIfLeaderActive=3Dtrue] [junit4] 2> 1290206 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepR= ecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, ch= eckLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 1290207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepR= ecoveryOp Will wait a max of 183 seconds to see collection1 (shard2 of coll= ection1) have state: recovering [junit4] 2> 1290207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepR= ecoveryOp In WaitForState(recovering): collection=3Dcollection1, shard=3Dsh= ard2, thisCore=3Dcollection1, leaderDoesNotNeedRecovery=3Dfalse, isLeader? = true, live=3Dtrue, checkLive=3Dtrue, currentState=3Ddown, localState=3Dacti= ve, nodeName=3D127.0.0.1:45023_, coreNodeName=3Dcore_node3, onlyIfActiveChe= ckResult=3Dfalse, nodeProps: core_node3:{"core":"collection1","base_url":"h= ttp://127.0.0.1:45023","node_name":"127.0.0.1:45023_","state":"down"} [junit4] 2> 1290306 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1290306 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1290306 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [4]) [junit4] 2> 1290625 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties fi= le to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/te= st/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/sha= rd-4-001/cores/collection1 [junit4] 2> 1290626 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create je= tty 4 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992= DF5FD-001/shard-4-001 [junit4] 2> 1290626 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.Servle= tContextHandler@562cc620{/,null,AVAILABLE} [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnect= or@2e363e3f{HTTP/1.1,[http/1.1]}{127.0.0.1:=E1=81=83=E1=81=88=E1=81=86=E1= =81=82=E1=81=87} [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @=E1=81=81=E1=81=82=E1= =81=89=E1=81=83=E1=81=80=E1=81=80=E1=81=84ms [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {= hostContext=3D/, solrconfig=3Dsolrconfig.xml, solr.data.dir=3D/home/jenkins= /workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.clo= ud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty4, ho= stPort=3D38627, coreRootDirectory=3D/home/jenkins/workspace/Lucene-Solr-6.6= -Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSaf= eTest_8CAE2226992DF5FD-001/shard-4-001/cores} [junit4] 2> 1290627 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option= solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ We= lcome to Apache Solr=E2=84=A2 version 6.6.1 [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ St= arting in cloud mode on port null [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| In= stall dir: null [junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| St= art time: 2017-08-31T08:38:35.982982Z [junit4] 2> 1290629 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml fro= m SolrHome (not found in ZooKeeper) [junit4] 2> 1290629 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configu= ration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-c= ore/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-0= 01/shard-4-001/solr.xml [junit4] 2> 1290632 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShard= Handler HTTP client with params: socketTimeout=3D340000&connTimeout=3D45000= &retry=3Dtrue [junit4] 2> 1290632 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D127.0.0.= 1:46749/solr [junit4] 2> 1290644 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from= ZooKeeper... (0) -> (4) [junit4] 2> 1290645 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=3Dnull) closing [junit4] 2> 1290645 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in Z= ooKeeper:/live_nodes/127.0.0.1:38627_ [junit4] 2> 1290646 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 1290646 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 1290646 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 1290646 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 1290646 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 1290646 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.= ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 1290665 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core defi= nitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992= DF5FD-001/shard-4-001/cores [junit4] 2> 1290665 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [colle= ction1] [junit4] 2> 1290667 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transien= t cores [junit4] 2> 1290668 INFO (OverseerStateUpdate-98577200536748036-127.0= .0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new nod= e to shard shard=3Dshard1 [junit4] 2> 1290771 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1290771 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1290771 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1290771 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1291207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepR= ecoveryOp In WaitForState(recovering): collection=3Dcollection1, shard=3Dsh= ard2, thisCore=3Dcollection1, leaderDoesNotNeedRecovery=3Dfalse, isLeader? = true, live=3Dtrue, checkLive=3Dtrue, currentState=3Drecovering, localState= =3Dactive, nodeName=3D127.0.0.1:45023_, coreNodeName=3Dcore_node3, onlyIfAc= tiveCheckResult=3Dfalse, nodeProps: core_node3:{"core":"collection1","base_= url":"http://127.0.0.1:45023","node_name":"127.0.0.1:45023_","state":"recov= ering"} [junit4] 2> 1291207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepR= ecoveryOp Waited coreNodeName: core_node3, state: recovering, checkLive: tr= ue, onlyIfLeader: true for: 1 seconds. [junit4] 2> 1291207 INFO (qtp1986792501-12293) [ ] o.a.s.s.HttpSol= rCall [admin] webapp=3Dnull path=3D/admin/cores params=3D{nodeName=3D127.0.= 0.1:45023_&onlyIfLeaderActive=3Dtrue&core=3Dcollection1&coreNodeName=3Dcore= _node3&action=3DPREPRECOVERY&checkLive=3Dtrue&state=3Drecovering&onlyIfLead= er=3Dtrue&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1000 [junit4] 2> 1291686 WARN (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.Config Beginning with Solr 5.5, is deprecated, use instead. [junit4] 2> 1291686 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.SolrConfig Using Lucene MatchVersion: 6.6.1 [junit4] 2> 1291693 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 1291707 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:36875/co= llection1/] - recoveringAfterStartup=3D[true] [junit4] 2> 1291707 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.u.PeerSync PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:45023 STAR= T replicas=3D[http://127.0.0.1:36875/collection1/] nUpdates=3D100 [junit4] 2> 1291710 INFO (qtp1986792501-12293) [ ] o.a.s.u.IndexFi= ngerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=3D9223372= 036854775807, maxVersionEncountered=3D0, maxInHash=3D0, versionsHash=3D0, n= umVersions=3D0, numDocs=3D0, maxDoc=3D0} [junit4] 2> 1291710 INFO (qtp1986792501-12293) [ ] o.a.s.c.S.Reque= st [collection1] webapp=3D path=3D/get params=3D{distrib=3Dfalse&qt=3D/get= &getFingerprint=3D9223372036854775807&wt=3Djavabin&version=3D2} status=3D0 = QTime=3D0 [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecifie= d=3D9223372036854775807, maxVersionEncountered=3D0, maxInHash=3D0, versions= Hash=3D0, numVersions=3D0, numDocs=3D0, maxDoc=3D0} [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.u.PeerSync We are already in sync. No need to do a PeerSync=20 [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.u.DirectUpdateHandler2 start commit{,optimize=3Dfalse,openSearcher=3Dtrue= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy PeerSync stage of recovery was successful. [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy Replaying updates buffered during PeerSync. [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy No replay needed. [junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.= s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 1291746 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id [junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.CoreContainer Creating SolrCore 'collection1' using configuration from = collection collection1, trusted=3Dtrue [junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/worksp= ace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.Chao= sMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001/cores/collection1= ], dataDir=3D[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr= -core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD= -001/shard-4-001/cores/collection1/data/] [junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Se= rver: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420 [junit4] 2> 1291753 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D48, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D1.0] [junit4] 2> 1291772 WARN (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.c.RequestHandlers INVALID paramSet a in requestHandler {type =3D requestH= andler,name =3D /dump,class =3D DumpRequestHandler,attributes =3D {initPara= ms=3Da, name=3D/dump, class=3DDumpRequestHandler},args =3D {defaults=3D{a= =3DA,b=3DB}}} [junit4] 2> 1291790 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.Up= dateLog [junit4] 2> 1291790 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.u.UpdateLog Initializing UpdateLog: dataDir=3D defaultSyncLevel=3DFLUSH n= umRecordsToKeep=3D100 maxNumLogsToKeep=3D10 numVersionBuckets=3D65536 [junit4] 2> 1291796 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;=20 [junit4] 2> 1291796 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1291796 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.in= dex.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=3D1000, mergeFactor= =3D11, maxMergeSize=3D9223372036854775807, maxMergeSizeForForcedMerge=3D922= 3372036854775807, calibrateSizeByDeletes=3Dtrue, maxMergeDocs=3D2147483647,= maxCFSSegmentSizeMB=3D8.796093022207999E12, noCFSRatio=3D0.0] [junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.s.SolrIndexSearcher Opening [Searcher@630699e2[collection1] main] [junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /c= onfigs/conf1 [junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using Zoo= KeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 1291798 INFO (searcherExecutor-5090-thread-1) [ ] o.a.= s.c.SolrCore [collection1] Registered new searcher Searcher@630699e2[collec= tion1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1291798 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.= s.u.UpdateLog Could not find max version in index or recent updates, using = new clock 1577235216757424128 [junit4] 2> 1291800 INFO (coreZkRegister-5084-thread-1) [ ] o.a.s.= c.ZkController Core needs to recover:collection1 [junit4] 2> 1291800 INFO (updateExecutor-2100-thread-1) [ ] o.a.s.= u.DefaultSolrCoreState Running recovery [junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=3Dtr= ue [junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy ###### startupVersions=3D[[]] [junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy Begin buffering updates. core=3D[collection1] [junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=3DACTIVE, tlog= =3Dnull} [junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, = leader is [http://127.0.0.1:41995/collection1/] and I am [http://127.0.0.1:= 38627/collection1/] [junit4] 2> 1291801 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:419= 95]; [WaitForState: action=3DPREPRECOVERY&core=3Dcollection1&nodeName=3D127= .0.0.1:38627_&coreNodeName=3Dcore_node4&state=3Drecovering&checkLive=3Dtrue= &onlyIfLeader=3Dtrue&onlyIfLeaderActive=3Dtrue] [junit4] 2> 1291802 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRec= overyOp Going to wait for coreNodeName: core_node4, state: recovering, chec= kLive: true, onlyIfLeader: true, onlyIfLeaderActive: true [junit4] 2> 1291806 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRec= overyOp Will wait a max of 183 seconds to see collection1 (shard1 of collec= tion1) have state: recovering [junit4] 2> 1291806 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRec= overyOp In WaitForState(recovering): collection=3Dcollection1, shard=3Dshar= d1, thisCore=3Dcollection1, leaderDoesNotNeedRecovery=3Dfalse, isLeader? tr= ue, live=3Dtrue, checkLive=3Dtrue, currentState=3Ddown, localState=3Dactive= , nodeName=3D127.0.0.1:38627_, coreNodeName=3Dcore_node4, onlyIfActiveCheck= Result=3Dfalse, nodeProps: core_node4:{"core":"collection1","base_url":"htt= p://127.0.0.1:38627","node_name":"127.0.0.1:38627_","state":"down"} [junit4] 2> 1291902 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1291902 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1291902 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1291902 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1292169 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test [junit4] 2> 1292169 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for reco= veries to finish - collection: collection1 failOnTimeout:true timeout (sec)= :330 [junit4] 2> 1292807 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRec= overyOp In WaitForState(recovering): collection=3Dcollection1, shard=3Dshar= d1, thisCore=3Dcollection1, leaderDoesNotNeedRecovery=3Dfalse, isLeader? tr= ue, live=3Dtrue, checkLive=3Dtrue, currentState=3Drecovering, localState=3D= active, nodeName=3D127.0.0.1:38627_, coreNodeName=3Dcore_node4, onlyIfActiv= eCheckResult=3Dfalse, nodeProps: core_node4:{"core":"collection1","base_url= ":"http://127.0.0.1:38627","node_name":"127.0.0.1:38627_","state":"recoveri= ng"} [junit4] 2> 1292807 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRec= overyOp Waited coreNodeName: core_node4, state: recovering, checkLive: true= , onlyIfLeader: true for: 1 seconds. [junit4] 2> 1292807 INFO (qtp15989041-12321) [ ] o.a.s.s.HttpSolrC= all [admin] webapp=3Dnull path=3D/admin/cores params=3D{nodeName=3D127.0.0.= 1:38627_&onlyIfLeaderActive=3Dtrue&core=3Dcollection1&coreNodeName=3Dcore_n= ode4&action=3DPREPRECOVERY&checkLive=3Dtrue&state=3Drecovering&onlyIfLeader= =3Dtrue&wt=3Djavabin&version=3D2} status=3D0 QTime=3D1004 [junit4] 2> 1293307 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:41995/co= llection1/] - recoveringAfterStartup=3D[true] [junit4] 2> 1293307 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.u.PeerSync PeerSync: core=3Dcollection1 url=3Dhttp://127.0.0.1:38627 STAR= T replicas=3D[http://127.0.0.1:41995/collection1/] nUpdates=3D100 [junit4] 2> 1293308 INFO (qtp15989041-12317) [ ] o.a.s.u.IndexFing= erprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=3D922337203= 6854775807, maxVersionEncountered=3D0, maxInHash=3D0, versionsHash=3D0, num= Versions=3D0, numDocs=3D0, maxDoc=3D0} [junit4] 2> 1293308 INFO (qtp15989041-12317) [ ] o.a.s.c.S.Request= [collection1] webapp=3D path=3D/get params=3D{distrib=3Dfalse&qt=3D/get&g= etFingerprint=3D9223372036854775807&wt=3Djavabin&version=3D2} status=3D0 QT= ime=3D0 [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecifie= d=3D9223372036854775807, maxVersionEncountered=3D0, maxInHash=3D0, versions= Hash=3D0, numVersions=3D0, numDocs=3D0, maxDoc=3D0} [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.u.PeerSync We are already in sync. No need to do a PeerSync=20 [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.u.DirectUpdateHandler2 start commit{,optimize=3Dfalse,openSearcher=3Dtrue= ,waitSearcher=3Dtrue,expungeDeletes=3Dfalse,softCommit=3Dfalse,prepareCommi= t=3Dfalse} [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy PeerSync stage of recovery was successful. [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy Replaying updates buffered during PeerSync. [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy No replay needed. [junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.= s.c.RecoveryStrategy Registering as Active after recovery. [junit4] 2> 1293411 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1293411 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1293411 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1293411 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [5]) [junit4] 2> 1294170 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries fi= nished - collection: collection1 [junit4] 2> 1294177 INFO (qtp1935364758-12255) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt= =3Djavabin&version=3D2}{deleteByQuery=3D*:* (-1577235219245694976)} 0 6 [junit4] 2> 1294221 INFO (qtp678145122-12349) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&_version_=3D-1577235219265617920&distrib.from=3Dhttp= ://127.0.0.1:36875/collection1/&wt=3Djavabin&version=3D2}{deleteByQuery=3D*= :* (-1577235219265617920)} 0 25 [junit4] 2> 1294222 INFO (qtp1986792501-12291) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{upda= te.distrib=3DTOLEADER&distrib.from=3Dhttp://127.0.0.1:41995/collection1/&wt= =3Djavabin&version=3D2}{deleteByQuery=3D*:* (-1577235219265617920)} 0 31 [junit4] 2> 1294231 INFO (qtp166102078-12383) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&_version_=3D-1577235219253035008&distrib.from=3Dhttp= ://127.0.0.1:41995/collection1/&wt=3Djavabin&version=3D2}{deleteByQuery=3D*= :* (-1577235219253035008)} 0 9 [junit4] 2> 1294232 INFO (qtp15989041-12316) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt=3Dj= avabin&version=3D2}{deleteByQuery=3D*:* (-1577235219253035008)} 0 53 [junit4] 2> 1294240 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: starting [junit4] 2> 1294241 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: Jetty will not comm= it on close [junit4] 2> 1294252 INFO (qtp1935364758-12256) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt= =3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-0 (1577235219328532480)]} 0= 1 [junit4] 2> 1294266 INFO (qtp1986792501-12290) [ ] o.a.s.c.S.Reque= st [collection1] webapp=3D path=3D/select params=3D{df=3Dtext&distrib=3Dfa= lse&_stateVer_=3Dcollection1:10&fl=3Did&fl=3Dscore&shards.purpose=3D4&start= =3D0&fsv=3Dtrue&shard.url=3Dhttp://127.0.0.1:36875/collection1/|http://127.= 0.0.1:45023/collection1/&rows=3D10&version=3D2&q=3Daid&NOW=3D1504168719610&= isShard=3Dtrue&wt=3Djavabin} hits=3D0 status=3D0 QTime=3D0 [junit4] 2> 1294268 INFO (qtp166102078-12384) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&distrib.from=3Dhttp://127.0.0.1:41995/collection1/&w= t=3Djavabin&version=3D2}{add=3D[0-0 (1577235219332726784)]} 0 0 [junit4] 2> 1294268 INFO (qtp15989041-12321) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt=3Dj= avabin&version=3D2}{add=3D[0-0 (1577235219332726784)]} 0 14 [junit4] 2> 1294270 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt= =3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-1 (1577235219349504000)]} 0= 0 [junit4] 2> 1294279 INFO (qtp166102078-12384) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&distrib.from=3Dhttp://127.0.0.1:41995/collection1/&w= t=3Djavabin&version=3D2}{add=3D[0-1 (1577235219351601152)]} 0 0 [junit4] 2> 1294279 INFO (qtp15989041-12318) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt=3Dj= avabin&version=3D2}{add=3D[0-1 (1577235219351601152)]} 0 7 [junit4] 2> 1294286 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt= =3Djavabin&version=3D2&CONTROL=3DTRUE}{delete=3D[0-1 (-1577235219366281216)= ]} 0 0 [junit4] 2> 1294289 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&distrib.from=3Dhttp://127.0.0.1:41995/collection1/&w= t=3Djavabin&version=3D2}{delete=3D[0-1 (-1577235219368378368)]} 0 0 [junit4] 2> 1294290 INFO (qtp15989041-12319) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt=3Dj= avabin&version=3D2}{delete=3D[0-1 (-1577235219368378368)]} 0 2 [junit4] 2> 1294292 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt= =3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-2 (1577235219372572672)]} 0= 0 [junit4] 2> 1294293 INFO (qtp15989041-12322) [ ] o.a.s.c.S.Request= [collection1] webapp=3D path=3D/select params=3D{df=3Dtext&distrib=3Dfals= e&_stateVer_=3Dcollection1:10&fl=3Did&fl=3Dscore&shards.purpose=3D4&start= =3D0&fsv=3Dtrue&shard.url=3Dhttp://127.0.0.1:41995/collection1/|http://127.= 0.0.1:38627/collection1/&rows=3D10&version=3D2&q=3Daid&NOW=3D1504168719610&= isShard=3Dtrue&wt=3Djavabin} hits=3D0 status=3D0 QTime=3D0 [junit4] 2> 1294294 INFO (qtp15989041-12323) [ ] o.a.s.c.S.Request= [collection1] webapp=3D path=3D/select params=3D{q=3Daid&_stateVer_=3Dcol= lection1:10&wt=3Djavabin&version=3D2} hits=3D0 status=3D0 QTime=3D38 [junit4] 2> 1294296 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&distrib.from=3Dhttp://127.0.0.1:41995/collection1/&w= t=3Djavabin&version=3D2}{add=3D[0-2 (1577235219374669824)]} 0 0 [junit4] 2> 1294296 INFO (qtp15989041-12321) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt=3Dj= avabin&version=3D2}{add=3D[0-2 (1577235219374669824)]} 0 2 [junit4] 2> 1294298 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt= =3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-3 (1577235219378864128)]} 0= 0 [junit4] 2> 1294303 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&distrib.from=3Dhttp://127.0.0.1:41995/collection1/&w= t=3Djavabin&version=3D2}{add=3D[0-3 (1577235219380961280)]} 0 0 [junit4] 2> 1294303 INFO (qtp15989041-12322) [ ] o.a.s.u.p.LogUpda= teProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt=3Dj= avabin&version=3D2}{add=3D[0-3 (1577235219380961280)]} 0 2 [junit4] 2> 1294305 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUp= dateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{wt= =3Djavabin&version=3D2&CONTROL=3DTRUE}{add=3D[0-4 (1577235219385155584)]} 0= 0 [junit4] 2> 1294310 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpd= ateProcessorFactory [collection1] webapp=3D path=3D/update params=3D{updat= e.distrib=3DFROMLEADER&distrib.from=3Dhttp://127.0.0.1:41995/collection1/&w= t=3Djavabin&version=3D2}{add=3D[0-4 (1577235219388301312)]} 0 0 [junit4] 2> 1294317 [...truncated too long message...] O (zkCallback-2096-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster stat= e change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/coll= ections/collection1/state.json] for collection [collection1] has occurred -= updating... (live nodes size: [1]) [junit4] 2> 1335304 INFO (zkCallback-2096-thread-2) [ ] o.a.s.c.c.= ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected typ= e:NodeDataChanged path:/collections/collection1/state.json] for collection = [collection1] has occurred - updating... (live nodes size: [1]) [junit4] 2> 1336685 WARN (zkCallback-2110-thread-2) [ ] o.a.s.c.c.= ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [Keepe= rErrorCode =3D Session expired for /live_nodes] [junit4] 2> 1336685 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnect= or@d57c427{HTTP/1.1,[http/1.1]}{127.0.0.1:=E1=81=84=E1=81=81=E1=81=89=E1=81= =89=E1=81=85} [junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.Servle= tContextHandler@68ad453{/,null,UNAVAILABLE} [junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 45023 [junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.CoreContainer Shutting down CoreContain= er instance=3D688558845 [junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.m.SolrMetricManager Closing metric report= ers for: solr.node [junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.m.SolrMetricManager Closing metric report= ers for: solr.jvm [junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.m.SolrMetricManager Closing metric report= ers for: solr.jetty [junit4] 2> 1336697 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=3D985772005367480= 47-127.0.0.1:45023_-n_0000000003) closing [junit4] 2> 1336697 INFO (OverseerStateUpdate-98577200536748047-127.0= .0.1:45023_-n_0000000003) [ ] o.a.s.c.Overseer Overseer Loop exiting : 1= 27.0.0.1:45023_ [junit4] 2> 1337657 WARN (zkCallback-2096-thread-6) [ ] o.a.s.c.Sy= ncStrategy Closed, skipping sync up. [junit4] 2> 1337658 INFO (zkCallback-2096-thread-6) [ ] o.a.s.c.So= lrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@350944= 41 [junit4] 2> 1337671 INFO (zkCallback-2096-thread-6) [ ] o.a.s.m.So= lrMetricManager Closing metric reporters for: solr.core.collection1 [junit4] 2> 1337672 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnect= or@36ade7e7{HTTP/1.1,[http/1.1]}{127.0.0.1:=E1=81=80} [junit4] 2> 1337672 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.Servle= tContextHandler@e005ad4{/,null,UNAVAILABLE} [junit4] 2> 1337672 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 38627 [junit4] 2> 1337672 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is no= t registered, so ZooKeeper server won't take any action on ERROR or SHUTDOW= N server state changes [junit4] 2> 1337673 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed= #[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46= 749 46749 [junit4] 2> 1342685 INFO (Thread-3614) [ ] o.a.s.c.ZkTestServer co= nnecting to 127.0.0.1:46749 46749 [junit4] 2> 1342685 WARN (Thread-3614) [ ] o.a.s.c.ZkTestServer Wa= tch limit violations:=20 [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2>=20 [junit4] 2> =092=09/solr/overseer/queue [junit4] 2> =092=09/solr/overseer/collection-queue-work [junit4] 2>=20 [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DChaosMonkeyNo= thingIsSafeTest -Dtests.method=3Dtest -Dtests.seed=3D8CAE2226992DF5FD -Dtes= ts.multiplier=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Dmy -Dtests.timezone= =3DEtc/Greenwich -Dtests.asserts=3Dtrue -Dtests.file.encoding=3DUTF-8 [junit4] FAILURE 58.7s J2 | ChaosMonkeyNothingIsSafeTest.test <<< [junit4] > Throwable #1: java.lang.AssertionError: document count mis= match. control=3D691 sum(shards)=3D685 cloudClient=3D685 [junit4] > =09at __randomizedtesting.SeedInfo.seed([8CAE2226992DF5FD:= 4FA1DFC37D19805]:0) [junit4] > =09at org.apache.solr.cloud.AbstractFullDistribZkTestBase.= checkShardConsistency(AbstractFullDistribZkTestBase.java:1323) [junit4] > =09at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.t= est(ChaosMonkeyNothingIsSafeTest.java:226) [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:992) [junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase$Shards= RepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967) [junit4] > =09at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 1342688 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8C= AE2226992DF5FD]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/wo= rkspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.= ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001 [junit4] 2> NOTE: test params are: codec=3DLucene62, sim=3DRandomSimil= arity(queryNorm=3Dfalse,coord=3Dno): {}, locale=3Dmy, timezone=3DEtc/Greenw= ich [junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 9 (= 64-bit)/cpus=3D8,threads=3D1,free=3D168463480,total=3D520093696 [junit4] 2> NOTE: All tests run in this JVM: [AsyncCallRequestStatusRe= sponseTest, SubstringBytesRefFilterTest, LukeRequestHandlerTest, V2ApiInteg= rationTest, TestSchemaNameResource, MultiThreadedOCPTest, TestSolrJ, SolrJm= xReporterTest, DeleteLastCustomShardedReplicaTest, CloudExitableDirectoryRe= aderTest, AutoCommitTest, SortSpecParsingTest, TestConfigSetImmutable, Coll= ectionTooManyReplicasTest, OverseerTest, TestFieldCacheSortRandom, TestRest= oreCore, EnumFieldTest, SpellPossibilityIteratorTest, FieldMutatingUpdatePr= ocessorTest, TestNamedUpdateProcessors, TestCorePropertiesReload, ReplicaLi= stTransformerTest, HttpPartitionTest, SolrCoreCheckLockOnStartupTest, TestW= riterPerf, TestStressReorder, SolrGangliaReporterTest, SolrTestCaseJ4Test, = TestSolrConfigHandlerCloud, TestHashQParserPlugin, QueryResultKeyTest, Test= CoreDiscovery, TestSearcherReuse, TestShortCircuitedRequests, DocExpiration= UpdateProcessorFactoryTest, LargeFieldTest, UpdateLogTest, TestJsonFacets, = TestExportWriter, OpenExchangeRatesOrgProviderTest, TestRawTransformer, Tim= eZoneUtilsTest, MinimalSchemaTest, TestIndexSearcher, TestPostingsSolrHighl= ighter, TestLegacyFieldCache, TestHalfAndHalfDocValues, TestUtils, HdfsTlog= ReplayBufferedWhileIndexingTest, StatsComponentTest, TestReload, PreAnalyze= dFieldTest, SuggesterTSTTest, TestNRTOpen, DistribDocExpirationUpdateProces= sorTest, DocValuesMultiTest, TestHdfsBackupRestoreCore, LeaderFailureAfterF= reshStartTest, BinaryUpdateRequestHandlerTest, TestRTimerTree, ZkStateWrite= rTest, TestSimpleTextCodec, TestSolr4Spatial2, DistributedFacetPivotLongTai= lTest, CoreMergeIndexesAdminHandlerTest, CoreAdminHandlerTest, SimpleCollec= tionCreateDeleteTest, AtomicUpdateProcessorFactoryTest, TestSchemalessBuffe= redUpdates, PrimUtilsTest, TestCollationField, CdcrVersionReplicationTest, = DirectUpdateHandlerOptimizeTest, BlockDirectoryTest, PluginInfoTest, TestMa= nagedSchemaThreadSafety, TestCollectionAPI, TestSolrCloudWithKerberosAlt, A= nalyticsMergeStrategyTest, TestTolerantUpdateProcessorRandomCloud, Suggeste= rTest, TestMergePolicyConfig, QueryParsingTest, TestStandardQParsers, TestI= ndexingPerformance, TestDFRSimilarityFactory, TestFreeTextSuggestions, Repl= aceNodeTest, DeleteShardTest, TestBulkSchemaAPI, HardAutoCommitTest, HdfsNN= FailoverTest, RecoveryZkTest, TestQueryWrapperFilter, ActionThrottleTest, O= verriddenZkACLAndCredentialsProvidersTest, RequestLoggingTest, TestBinaryFi= eld, DistributedVersionInfoTest, ClassificationUpdateProcessorIntegrationTe= st, SolrIndexMetricsTest, TestOnReconnectListenerSupport, TestHdfsUpdateLog= , CachingDirectoryFactoryTest, DistributedSuggestComponentTest, FieldAnalys= isRequestHandlerTest, TestJavabinTupleStreamParser, PreAnalyzedUpdateProces= sorTest, BasicDistributedZk2Test, TermVectorComponentDistributedTest, DOMUt= ilTest, XmlUpdateRequestHandlerTest, BadComponentTest, PeerSyncReplicationT= est, TestFieldSortValues, ShardRoutingTest, ClusterStateUpdateTest, TestZkC= hroot, TestDistributedSearch, DisMaxRequestHandlerTest, TestReversedWildcar= dFilterFactory, PrimitiveFieldTypeTest, DocumentBuilderTest, TermVectorComp= onentTest, TestSolrQueryParser, LoggingHandlerTest, SolrPluginUtilsTest, Up= dateRequestProcessorFactoryTest, MBeansHandlerTest, JsonLoaderTest, TestPar= tialUpdateDeduplication, CSVRequestHandlerTest, TestComponentsName, SearchH= andlerTest, TestQuerySenderListener, AlternateDirectoryTest, ResponseLogCom= ponentTest, SampleTest, TestDocSet, OutputWriterTest, ExternalFileFieldSort= Test, TestPhraseSuggestions, TestLMJelinekMercerSimilarityFactory, Resource= LoaderTest, ChaosMonkeyNothingIsSafeTest] [junit4] Completed [490/713 (1!)] on J2 in 58.70s, 1 test, 1 failure <<<= FAILURES! [...truncated 37126 lines...] ------=_Part_60_1915134791.1504170135533 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_60_1915134791.1504170135533--