Return-Path: X-Original-To: apmail-lucene-dev-archive@www.apache.org Delivered-To: apmail-lucene-dev-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id D2FBB180A0 for ; Tue, 28 Jul 2015 22:53:41 +0000 (UTC) Received: (qmail 78623 invoked by uid 500); 28 Jul 2015 22:53:40 -0000 Delivered-To: apmail-lucene-dev-archive@lucene.apache.org Received: (qmail 78563 invoked by uid 500); 28 Jul 2015 22:53:40 -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 78545 invoked by uid 99); 28 Jul 2015 22:53:40 -0000 Received: from Unknown (HELO spamd2-us-west.apache.org) (209.188.14.142) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 28 Jul 2015 22:53:40 +0000 Received: from localhost (localhost [127.0.0.1]) by spamd2-us-west.apache.org (ASF Mail Server at spamd2-us-west.apache.org) with ESMTP id E62D71A8B0A; Tue, 28 Jul 2015 22:53:39 +0000 (UTC) X-Virus-Scanned: Debian amavisd-new at spamd2-us-west.apache.org X-Spam-Flag: NO X-Spam-Score: 2.002 X-Spam-Level: ** X-Spam-Status: No, score=2.002 tagged_above=-999 required=6.31 tests=[FSL_HELO_NON_FQDN_1=0.001, KAM_BADIPHTTP=2, SPF_PASS=-0.001, URIBL_BLOCKED=0.001, WEIRD_PORT=0.001] autolearn=disabled Received: from mx1-us-west.apache.org ([10.40.0.8]) by localhost (spamd2-us-west.apache.org [10.40.0.9]) (amavisd-new, port 10024) with ESMTP id fBOmq9UeL5xE; Tue, 28 Jul 2015 22:53:22 +0000 (UTC) Received: from serv1 (serv1.sd-datasolutions.de [188.138.57.78]) by mx1-us-west.apache.org (ASF Mail Server at mx1-us-west.apache.org) with ESMTPS id 05BE32642F; Tue, 28 Jul 2015 22:53:21 +0000 (UTC) Received: from localhost.localdomain ([127.0.0.1] helo=serv1) by serv1 with esmtp (Exim 4.82) (envelope-from ) id 1ZKDkN-00082V-AL; Tue, 28 Jul 2015 22:53:19 +0000 Date: Tue, 28 Jul 2015 22:53:03 +0000 (UTC) From: Policeman Jenkins Server To: hossman@apache.org, mikemccand@apache.org, dev@lucene.apache.org Message-ID: <464769262.63.1438123999318.JavaMail.jenkins@serv1> Subject: [JENKINS-EA] Lucene-Solr-trunk-Linux (64bit/jdk1.9.0-ea-b60) - Build # 13641 - Failure! MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="----=_Part_62_265652163.1438123999271" X-Jenkins-Job: Lucene-Solr-trunk-Linux X-Jenkins-Result: FAILURE X-Priority: 5 (Low) ------=_Part_62_265652163.1438123999271 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: quoted-printable Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/13641/ Java: 64bit/jdk1.9.0-ea-b60 -XX:-UseCompressedOops -XX:+UseSerialGC -Djava.= locale.providers=3DJRE,SPI 1 tests failed. FAILED: org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTests Error Message: Timeout while trying to assert update logs @ collection=3Dsource_collection Stack Trace: java.lang.AssertionError: Timeout while trying to assert update logs @ coll= ection=3Dsource_collection =09at __randomizedtesting.SeedInfo.seed([18EBDB3D08C1B2C7:108BAE1107CF9ACC]= :0) =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.assertNumberOf= TlogFiles(CdcrReplicationDistributedZkTest.java:644) =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTestUpdateLo= gSynchronisation(CdcrReplicationDistributedZkTest.java:384) =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTests(CdcrRe= plicationDistributedZkTest.java:50) =09at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) =09at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.= java:62) =09at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces= sorImpl.java:43) =09at java.lang.reflect.Method.invoke(Method.java:502) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(Randomized= Runner.java:1627) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(Random= izedRunner.java:836) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(Random= izedRunner.java:872) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(Random= izedRunner.java:886) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= FixedStatement.callStatement(BaseDistributedSearchTestCase.java:963) =09at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$Shards= Statement.evaluate(BaseDistributedSearchTestCase.java:938) =09at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$= 1.evaluate(SystemPropertiesRestoreRule.java:57) =09at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRu= leSetupTeardownChained.java:50) =09at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBef= oreAfterRule.java:46) =09at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleT= hreadAndTestName.java:49) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:65) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:365) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTa= sk(ThreadLeakControl.java:798) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(Threa= dLeakControl.java:458) =09at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(Ran= domizedRunner.java:845) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(Random= izedRunner.java:747) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(Random= izedRunner.java:781) =09at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(Random= izedRunner.java:792) =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:46) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStor= eClassName.java:42) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMeth= odsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRule= AssertionsRequired.java:54) =09at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFai= lure.java:48) =09at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(Test= RuleIgnoreAfterMaxFailures.java:65) =09at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIg= noreTestSuites.java:55) =09at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(St= atementAdapter.java:36) =09at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.= run(ThreadLeakControl.java:365) =09at java.lang.Thread.run(Thread.java:745) Caused by: java.lang.AssertionError: Number of tlogs on replica: 67 is supe= rior to: 50. =09at org.junit.Assert.fail(Assert.java:93) =09at org.junit.Assert.assertTrue(Assert.java:43) =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTest._assertNumberO= fTlogFiles(CdcrReplicationDistributedZkTest.java:674) =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.assertNumberOf= TlogFiles(CdcrReplicationDistributedZkTest.java:634) =09... 43 more Build Log: [...truncated 10994 lines...] [junit4] Suite: org.apache.solr.cloud.CdcrReplicationDistributedZkTest [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-trun= k-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistrib= utedZkTest_18EBDB3D08C1B2C7-001/init-core-data-001 [junit4] 2> 1136166 INFO (SUITE-CdcrReplicationDistributedZkTest-seed= #[18EBDB3D08C1B2C7]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (fal= se) and clientAuth (false) [junit4] 2> 1136166 INFO (SUITE-CdcrReplicationDistributedZkTest-seed= #[18EBDB3D08C1B2C7]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Sett= ing hostContext system property: /ev/az [junit4] 2> 1136168 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SE= RVER [junit4] 2> 1136168 INFO (Thread-4276) [ ] o.a.s.c.ZkTestServer cl= ient port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1136168 INFO (Thread-4276) [ ] o.a.s.c.ZkTestServer St= arting server [junit4] 2> 1136268 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.ZkTestServer start zk server on = port:40733 [junit4] 2> 1136268 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkC= redentialsProvider [junit4] 2> 1136268 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for = client to connect to ZooKeeper [junit4] 2> 1136271 INFO (zkCallback-1495-thread-1) [ ] o.a.s.c.c.= ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@21= a3e7ef name:ZooKeeperConnection Watcher:127.0.0.1:40733 got event WatchedEv= ent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1136271 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Client is co= nnected to ZooKeeper [junit4] 2> 1136271 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkA= CLProvider [junit4] 2> 1136272 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1136273 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkC= redentialsProvider [junit4] 2> 1136273 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for = client to connect to ZooKeeper [junit4] 2> 1136274 INFO (zkCallback-1496-thread-1) [ ] o.a.s.c.c.= ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@16= fbfb23 name:ZooKeeperConnection Watcher:127.0.0.1:40733/solr got event Watc= hedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1136274 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Client is co= nnected to ZooKeeper [junit4] 2> 1136274 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkA= CLProvider [junit4] 2> 1136274 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /collec= tions/collection1 [junit4] 2> 1136275 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /collec= tions/collection1/shards [junit4] 2> 1136275 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /collec= tions/control_collection [junit4] 2> 1136276 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /collec= tions/control_collection/shards [junit4] 2> 1136276 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/solrconfig-cdcr.xml to /configs/conf1/solrconfig.xml [junit4] 2> 1136277 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/solrconfig.xml [junit4] 2> 1136277 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/schema15.xml to /configs/conf1/schema.xml [junit4] 2> 1136278 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/schema.xml [junit4] 2> 1136278 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrc= onfig.snippet.randomindexconfig.xml [junit4] 2> 1136278 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/solrconfig.snippet.randomindexconfig.xml [junit4] 2> 1136279 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/stopwords.txt to /configs/conf1/stopwords.txt [junit4] 2> 1136279 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/stopwords.txt [junit4] 2> 1136280 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/protwords.txt to /configs/conf1/protwords.txt [junit4] 2> 1136280 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/protwords.txt [junit4] 2> 1136280 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/currency.xml to /configs/conf1/currency.xml [junit4] 2> 1136280 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/currency.xml [junit4] 2> 1136281 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml [junit4] 2> 1136281 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/enumsConfig.xml [junit4] 2> 1136282 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.j= son [junit4] 2> 1136282 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/open-exchange-rates.json [junit4] 2> 1136282 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1A= ccent.txt [junit4] 2> 1136282 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/mapping-ISOLatin1Accent.txt [junit4] 2> 1136283 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt [junit4] 2> 1136283 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/old_synonyms.txt [junit4] 2> 1136284 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.AbstractZkTestCase put /home/jen= kins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collec= tion1/conf/synonyms.txt to /configs/conf1/synonyms.txt [junit4] 2> 1136284 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient makePath: /config= s/conf1/synonyms.txt [junit4] 2> 1136285 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTests [junit4] 2> 1136331 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.SolrTestCaseJ4 Writing core.proper= ties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/sol= r-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C= 1B2C7-001/jetty-001/cores/collection1 [junit4] 2> 1136332 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529 [junit4] 2> 1136336 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s= .ServletContextHandler@4a3d7c3c{/ev/az,null,AVAILABLE} [junit4] 2> 1136342 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.ServerConnector Started ServerCo= nnector@1f9ab654{HTTP/1.1}{127.0.0.1:52363} [junit4] 2> 1136342 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.Server Started @1137750ms [junit4] 2> 1136342 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty proper= ties: {shards=3Dshard1, hostContext=3D/ev/az, hostPort=3D52363, coreRootDir= ectory=3D/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-co= re/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C= 7-001/jetty-001/cores} [junit4] 2> 1136342 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchF= ilter.init(): sun.misc.Launcher$AppClassLoader@45fe3ee3 [junit4] 2> 1136342 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.SolrResourceLoader new SolrResou= rceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/s= olr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTes= t_18EBDB3D08C1B2C7-001/jetty-001/' [junit4] 2> 1136351 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkC= redentialsProvider [junit4] 2> 1136351 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for = client to connect to ZooKeeper [junit4] 2> 1136352 INFO (zkCallback-1497-thread-1) [ ] o.a.s.c.c.= ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@59= 412403 name:ZooKeeperConnection Watcher:127.0.0.1:40733/solr got event Watc= hedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1136352 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Client is co= nnected to ZooKeeper [junit4] 2> 1136352 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkA= CLProvider [junit4] 2> 1136353 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.= xml from SolrHome (not found in ZooKeeper) [junit4] 2> 1136353 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.SolrXmlConfig Loading container = configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bui= ld/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBD= B3D08C1B2C7-001/jetty-001/solr.xml [junit4] 2> 1136356 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoresLocator Config-defined core= root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3= D08C1B2C7-001/jetty-001/cores [junit4] 2> 1136356 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoreContainer New CoreContainer = 709087343 [junit4] 2> 1136356 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoreContainer Loading cores into= CoreContainer [instanceDir=3D/home/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZ= kTest_18EBDB3D08C1B2C7-001/jetty-001/] [junit4] 2> 1136357 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoreContainer loading shared lib= rary: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/= test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C7-0= 01/jetty-001/lib [junit4] 2> 1136357 WARN (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.SolrResourceLoader Can't find (o= r read) directory to add to classloader: lib (resolved as: /home/jenkins/wo= rkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.clou= d.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C7-001/jetty-001/lib). [junit4] 2> 1136360 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.h.c.HttpShardHandlerFactory create= d with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnection= sPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 214= 7483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRe= tries : false, [junit4] 2> 1136361 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.u.UpdateShardHandler Creating Upda= teShardHandler HTTP client with params: socketTimeout=3D340000&connTimeout= =3D45000&retry=3Dtrue [junit4] 2> 1136361 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf= 4j.impl.Log4jLoggerFactory [junit4] 2> 1136362 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.l.LogWatcher Registering Log Liste= ner [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 1136362 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D1= 27.0.0.1:40733/solr [junit4] 2> 1136362 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.ZkController zkHost includes chr= oot [junit4] 2> 1136362 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkC= redentialsProvider [junit4] 2> 1136362 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for = client to connect to ZooKeeper [junit4] 2> 1136363 INFO (zkCallback-1499-thread-1) [ ] o.a.s.c.c.= ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6c= b2041d name:ZooKeeperConnection Watcher:127.0.0.1:40733 got event WatchedEv= ent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1136363 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Client is co= nnected to ZooKeeper [junit4] 2> 1136363 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkA= CLProvider [junit4] 2> 1136364 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.Conne= ctionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1136364 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ConnectionMan= ager Watcher org.apache.solr.common.cloud.ConnectionManager@45a97e75 name:Z= ooKeeperConnection Watcher:127.0.0.1:40733/solr got event WatchedEvent stat= e:SyncConnected type:None path:null path:null type:None [junit4] 2> 1136364 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.Conne= ctionManager Client is connected to ZooKeeper [junit4] 2> 1136365 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer/queue [junit4] 2> 1136366 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer/collection-queue-work [junit4] 2> 1136367 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer/collection-map-running [junit4] 2> 1136367 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer/collection-map-completed [junit4] 2> 1136368 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer/collection-map-failure [junit4] 2> 1136368 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /live_nodes [junit4] 2> 1136369 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /aliases.json [junit4] 2> 1136369 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /clusterstate.json [junit4] 2> 1136370 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.ZkContr= oller Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52363_ev%2Fa= z [junit4] 2> 1136370 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /live_nodes/127.0.0.1:52363_ev%2Faz [junit4] 2> 1136370 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer_elect [junit4] 2> 1136371 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer_elect/election [junit4] 2> 1136371 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Oversee= r Overseer (id=3Dnull) closing [junit4] 2> 1136371 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.LeaderE= lector Joined leadership election with path: /overseer_elect/election/94248= 856982257668-127.0.0.1:52363_ev%2Faz-n_0000000000 [junit4] 2> 1136372 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Oversee= rElectionContext I am going to be the leader 127.0.0.1:52363_ev%2Faz [junit4] 2> 1136372 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer_elect/leader [junit4] 2> 1136372 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Oversee= r Overseer (id=3D94248856982257668-127.0.0.1:52363_ev%2Faz-n_0000000000) st= arting [junit4] 2> 1136373 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /overseer/queue-work [junit4] 2> 1136375 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Oversee= rAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoR= eplicaFailoverWorkLoopDelay=3D10000 autoReplicaFailoverWaitAfterExpiration= =3D30000 autoReplicaFailoverBadNodeExpiration=3D60000 [junit4] 2> 1136375 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkSta= teReader Updating cluster state from ZooKeeper...=20 [junit4] 2> 1136375 INFO (OverseerCollectionProcessor-942488569822576= 68-127.0.0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.= a.s.c.OverseerCollectionProcessor Process current queue of collection creat= ions [junit4] 2> 1136375 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Ov= erseer Starting to work on the main queue [junit4] 2> 1136376 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.CoreCon= tainer No authentication plugin used. [junit4] 2> 1136376 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.CoreCon= tainer Security conf doesn't exist. Skipping setup for authorization module= . [junit4] 2> 1136376 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.CoresLo= cator Looking for core definitions underneath /home/jenkins/workspace/Lucen= e-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplica= tionDistributedZkTest_18EBDB3D08C1B2C7-001/jetty-001/cores [junit4] 2> 1136377 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.SolrCor= e Created CoreDescriptor: {name=3Dcollection1, config=3Dsolrconfig.xml, tra= nsient=3Dfalse, schema=3Dschema.xml, loadOnStartup=3Dtrue, configSetPropert= ies=3Dconfigsetprops.json, instanceDir=3D/home/jenkins/workspace/Lucene-Sol= r-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationD= istributedZkTest_18EBDB3D08C1B2C7-001/jetty-001/cores/collection1, collecti= on=3Dtmp_collection, absoluteInstDir=3D/home/jenkins/workspace/Lucene-Solr-= trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDis= tributedZkTest_18EBDB3D08C1B2C7-001/jetty-001/cores/collection1/, coreNodeN= ame=3D, dataDir=3Ddata/, shard=3D} [junit4] 2> 1136377 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.CoresLo= cator Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-L= inux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistribute= dZkTest_18EBDB3D08C1B2C7-001/jetty-001/cores/collection1/ [junit4] 2> 1136377 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.CoresLo= cator Found 1 core definitions [junit4] 2> 1136378 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController publishing state=3Ddown [junit4] 2> 1136378 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController numShards not found on descriptor - readin= g it from system property [junit4] 2> 1136378 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.s.SolrDis= patchFilter user.dir=3D/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr= /build/solr-core/test/J2 [junit4] 2> 1136378 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.s.SolrDis= patchFilter SolrDispatchFilter.init() done [junit4] 2> 1136378 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.DistributedQueu= e NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 1136378 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController look for our core node name [junit4] 2> 1136378 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Ov= erseer processMessage: queueSize: 1, message =3D { [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:52363/ev/az", [junit4] 2> "node_name":"127.0.0.1:52363_ev%2Faz", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"tmp_collection", [junit4] 2> "operation":"state"} current state version: 0 [junit4] 2> 1136379 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.o.= ReplicaMutator Update state numShards=3D2 message=3D{ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:52363/ev/az", [junit4] 2> "node_name":"127.0.0.1:52363_ev%2Faz", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"tmp_collection", [junit4] 2> "operation":"state"} [junit4] 2> 1136379 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.o.= ClusterStateMutator building a new cName: tmp_collection [junit4] 2> 1136379 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.o.= ReplicaMutator Assigning new node to shard shard=3Dshard2 [junit4] 2> 1136380 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChan= ged path:/clusterstate.json, has occurred - updating... (live nodes size: 1= ) [junit4] 2> 1136380 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= Updated cluster state version to 1 [junit4] 2> 1137378 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController waiting to find shard id in clusterstate f= or collection1 [junit4] 2> 1137378 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController Check for collection zkNode:tmp_collection [junit4] 2> 1137379 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController Creating collection in ZooKeeper:tmp_colle= ction [junit4] 2> 1137379 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController Looking for collection configName [junit4] 2> 1137379 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController Only one config set found in zk - using it= :conf1 [junit4] 2> 1137379 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.c.SolrZkClient makePath: /collections/tmp_collection [junit4] 2> 1137380 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.c.ZkStateReader Load collection config from:/collection= s/tmp_collection [junit4] 2> 1137380 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.c.ZkStateReader path=3D/collections/tmp_collection conf= igName=3Dconf1 specified config exists in ZooKeeper [junit4] 2> 1137380 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory= : '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/tes= t/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C7-001/= jetty-001/cores/collection1/' [junit4] 2> 1137404 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.Config loaded config solrconfig.xml with version 0=20 [junit4] 2> 1137407 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.SolrConfig current version of requestparams : -1 [junit4] 2> 1137409 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0 [junit4] 2> 1137414 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml [junit4] 2> 1137415 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/sch= ema.xml [junit4] 2> 1137417 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 1137483 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema default search field in schema is text [junit4] 2> 1137484 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema unique key field: id [junit4] 2> 1137485 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from = file currency.xml [junit4] 2> 1137486 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from = file currency.xml [junit4] 2> 1137492 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, = assuming default properties: Can't find resource 'configsetprops.json' in c= lasspath or '/configs/conf1', cwd=3D/home/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J2 [junit4] 2> 1137492 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using con= figuration from collection tmp_collection [junit4] 2> 1137492 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockD= irectoryFactory [junit4] 2> 1137492 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening n= ew SolrCore at [/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/= solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D= 08C1B2C7-001/jetty-001/cores/collection1/], dataDir=3D[null] [junit4] 2> 1137493 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is e= nabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanS= erver@70634a1d [junit4] 2> 1137493 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new = directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/so= lr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08= C1B2C7-001/jetty-001/cores/collection1/data [junit4] 2> 1137493 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore New index directory detect= ed: old=3Dnull new=3D/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/b= uild/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18E= BDB3D08C1B2C7-001/jetty-001/cores/collection1/data/index/ [junit4] 2> 1137493 WARN (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Solr index d= irectory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-c= ore/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2= C7-001/jetty-001/cores/collection1/data/index' doesn't exist. Creating new = index... [junit4] 2> 1137493 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.CachingDirectoryFactory return new = directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/so= lr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08= C1B2C7-001/jetty-001/cores/collection1/data/index [junit4] 2> 1137494 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy= wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePoli= cy: maxMergeAtOnce=3D39, maxMergeAtOnceExplicit=3D26, maxMergedSegmentMB=3D= 16.0986328125, floorSegmentMB=3D0.35546875, forceMergeDeletesPctAllowed=3D2= 5.865488090774736, segmentsPerTier=3D41.0, maxCFSSegmentSizeMB=3D8.79609302= 2207999E12, noCFSRatio=3D0.66880291210395 [junit4] 2> 1137494 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommi= t: commits: num=3D1 [junit4] 2> =09commit{dir=3DMockDirectoryWrapper(RAMDirectory@6be4f113= lockFactory=3Dorg.apache.lucene.store.SingleInstanceLockFactory@715d4fe0),= segFN=3Dsegments_1,generation=3D1} [junit4] 2> 1137494 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = =3D 1 [junit4] 2> 1137494 INFO (OldIndexDirectoryCleanupThreadForCore-colle= ction1) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x= :collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup= for core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/so= lr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest= _18EBDB3D08C1B2C7-001/jetty-001/cores/collection1/data/ [junit4] 2> 1137495 WARN (OldIndexDirectoryCleanupThreadForCore-colle= ction1) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x= :collection1] o.a.s.c.DirectoryFactory /home/jenkins/workspace/Lucene-Solr-= trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDis= tributedZkTest_18EBDB3D08C1B2C7-001/jetty-001/cores/collection1/data/ does = not point to a valid data directory; skipping clean-up of old index directo= ries. [junit4] 2> 1137496 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creat= ing updateRequestProcessorChain "cdcr-processor-chain" [junit4] 2> 1137496 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorC= hain defined as default, creating implicit default [junit4] 2> 1137497 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1137498 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1137498 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1137499 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1137501 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /= admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segm= ents,/get,/admin/system,/replication,/admin/properties,/config,/schema,/adm= in/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/cdcr,/up= date,/admin/file [junit4] 2> 1137501 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore Using default statsCache c= ache: org.apache.solr.search.stats.LocalStatsCache [junit4] 2> 1137501 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog imple= mentation: org.apache.solr.update.CdcrUpdateLog [junit4] 2> 1137501 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: d= ataDir=3D defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep= =3D10 numVersionBuckets=3D65536 [junit4] 2> 1137502 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled [junit4] 2> 1137502 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled [junit4] 2> 1137502 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy= wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMer= gePolicy: minMergeSize=3D0, mergeFactor=3D10, maxMergeSize=3D2131215468, ma= xMergeSizeForForcedMerge=3D9223372036854775807, calibrateSizeByDeletes=3Dtr= ue, maxMergeDocs=3D2147483647, maxCFSSegmentSizeMB=3D8.796093022207999E12, = noCFSRatio=3D0.1] [junit4] 2> 1137503 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit:= commits: num=3D1 [junit4] 2> =09commit{dir=3DMockDirectoryWrapper(RAMDirectory@6be4f113= lockFactory=3Dorg.apache.lucene.store.SingleInstanceLockFactory@715d4fe0),= segFN=3Dsegments_1,generation=3D1} [junit4] 2> 1137503 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = =3D 1 [junit4] 2> 1137503 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@= 59746799[collection1] main [junit4] 2> 1137503 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader Load collection con= fig from:/collections/tmp_collection [junit4] 2> 1137503 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.c.ZkStateReader path=3D/collections= /tmp_collection configName=3Dconf1 specified config exists in ZooKeeper [junit4] 2> 1137503 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Setting up Z= ooKeeper-based storage for the RestManager with znodeBase: /configs/conf1 [junit4] 2> 1137504 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured Z= ooKeeperStorageIO with znodeBase: /configs/conf1 [junit4] 2> 1137504 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManage= r with initArgs: {} [junit4] 2> 1137504 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Reading _res= t_managed.json using ZooKeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 1137504 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage No data foun= d for znode /configs/conf1/_rest_managed.json [junit4] 2> 1137504 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Loaded null = at path _rest_managed.json using ZooKeeperStorageIO:path=3D/configs/conf1 [junit4] 2> 1137504 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 register= ed ManagedResources [junit4] 2> 1137504 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be = reserved for 10000 [junit4] 2> 1137505 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collectio= ns/tmp_collection/cdcr/state [junit4] 2> 1137506 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.h.CdcrBufferStateManager Created znod= e /collections/tmp_collection/cdcr/state/buffer [junit4] 2> 1137506 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.h.CdcrProcessStateManager Created zno= de /collections/tmp_collection/cdcr/state/process [junit4] 2> 1137507 INFO (searcherExecutor-4749-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_nod= e1) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:col= lection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5= 9746799[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReade= r())} [junit4] 2> 1137507 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.UpdateLog Looking up max value of v= ersion field to seed version buckets [junit4] 2> 1137507 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.VersionInfo Refreshing highest valu= e of _version_ for 65536 version buckets from index [junit4] 2> 1137507 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.VersionInfo No terms found for _ver= sion_, cannot seed version bucket highest value from index [junit4] 2> 1137507 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.UpdateLog Could not find max versio= n in index or recent updates, using new clock 1507981713119117312 [junit4] 2> 1137509 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2 ms to seed version= buckets with highest version 1507981713119117312 [junit4] 2> 1137509 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/c= onf1 [junit4] 2> 1137509 INFO (coreLoadExecutor-4748-thread-1-processing-n= :127.0.0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:sha= rd2 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: col= lection1 [junit4] 2> 1137509 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ZkController Register replica - core:collection1 address:ht= tp://127.0.0.1:52363/ev/az collection:tmp_collection shard:shard2 [junit4] 2> 1137510 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.c.SolrZkClient makePath: /collections/tmp_collection/leader= _elect/shard2/election [junit4] 2> 1137511 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.LeaderElector Joined leadership election with path: /collec= tions/tmp_collection/leader_elect/shard2/election/94248856982257668-core_no= de1-n_0000000000 [junit4] 2> 1137511 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ShardLeaderElectionContext Running the leader process for s= hard shard2 [junit4] 2> 1137512 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.DistributedQueu= e NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 1137512 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continu= e. [junit4] 2> 1137512 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try an= d sync [junit4] 2> 1137512 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:52363/ev/az/= collection1/ [junit4] 2> 1137512 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Ov= erseer processMessage: queueSize: 1, message =3D { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"tmp_collection"} current state version: 1 [junit4] 2> 1137512 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 1137512 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.SyncStrategy http://127.0.0.1:52363/ev/az/collection1/ has = no replicas [junit4] 2> 1137512 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.= 0.0.1:52363/ev/az/collection1/ shard2 [junit4] 2> 1137512 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.c.SolrZkClient makePath: /collections/tmp_collection/leader= s/shard2 [junit4] 2> 1137513 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.h.CdcrProcessStat= eManager Received new leader state @ tmp_collection:shard2 [junit4] 2> 1137514 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.DistributedQueu= e NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 1137515 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Ov= erseer processMessage: queueSize: 1, message =3D { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"tmp_collection", [junit4] 2> "base_url":"http://127.0.0.1:52363/ev/az", [junit4] 2> "core":"collection1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1137616 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChan= ged path:/clusterstate.json, has occurred - updating... (live nodes size: 1= ) [junit4] 2> 1137617 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= Updated cluster state version to 2 [junit4] 2> 1137665 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ZkController We are http://127.0.0.1:52363/ev/az/collection= 1/ and leader is http://127.0.0.1:52363/ev/az/collection1/ [junit4] 2> 1137665 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ZkController No LogReplay needed for core=3Dcollection1 bas= eURL=3Dhttp://127.0.0.1:52363/ev/az [junit4] 2> 1137665 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 1137665 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ZkController publishing state=3Dactive [junit4] 2> 1137665 INFO (coreZkRegister-4742-thread-1-processing-n:1= 27.0.0.1:52363_ev%2Faz x:collection1 s:shard2 c:tmp_collection r:core_node1= ) [n:127.0.0.1:52363_ev%2Faz c:tmp_collection s:shard2 r:core_node1 x:colle= ction1] o.a.s.c.ZkController numShards not found on descriptor - reading it= from system property [junit4] 2> 1137666 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.DistributedQueu= e NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 1137666 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Ov= erseer processMessage: queueSize: 1, message =3D { [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:52363/ev/az", [junit4] 2> "node_name":"127.0.0.1:52363_ev%2Faz", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"tmp_collection", [junit4] 2> "operation":"state"} current state version: 2 [junit4] 2> 1137667 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.o.= ReplicaMutator Update state numShards=3D2 message=3D{ [junit4] 2> "core":"collection1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:52363/ev/az", [junit4] 2> "node_name":"127.0.0.1:52363_ev%2Faz", [junit4] 2> "numShards":"2", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"tmp_collection", [junit4] 2> "operation":"state"} [junit4] 2> 1137768 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChan= ged path:/clusterstate.json, has occurred - updating... (live nodes size: 1= ) [junit4] 2> 1137769 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= Updated cluster state version to 3 [junit4] 2> 1137957 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.SolrTestCaseJ4 Writing core.proper= ties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/sol= r-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C= 1B2C7-001/jetty-002/cores/collection1 [junit4] 2> 1137958 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.Server jetty-9.2.11.v20150529 [junit4] 2> 1137959 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s= .ServletContextHandler@16564ab{/ev/az,null,AVAILABLE} [junit4] 2> 1137960 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.ServerConnector Started ServerCo= nnector@46890fb3{HTTP/1.1}{127.0.0.1:42058} [junit4] 2> 1137960 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.e.j.s.Server Started @1139368ms [junit4] 2> 1137960 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty proper= ties: {shards=3Dshard2, hostContext=3D/ev/az, hostPort=3D42058, coreRootDir= ectory=3D/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-co= re/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C= 7-001/jetty-002/cores} [junit4] 2> 1137960 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchF= ilter.init(): sun.misc.Launcher$AppClassLoader@45fe3ee3 [junit4] 2> 1137961 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.SolrResourceLoader new SolrResou= rceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/s= olr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTes= t_18EBDB3D08C1B2C7-001/jetty-002/' [junit4] 2> 1137974 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkC= redentialsProvider [junit4] 2> 1137975 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for = client to connect to ZooKeeper [junit4] 2> 1137975 INFO (zkCallback-1501-thread-1) [ ] o.a.s.c.c.= ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@23= c6d54b name:ZooKeeperConnection Watcher:127.0.0.1:40733/solr got event Watc= hedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1137975 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Client is co= nnected to ZooKeeper [junit4] 2> 1137976 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkA= CLProvider [junit4] 2> 1137976 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.= xml from SolrHome (not found in ZooKeeper) [junit4] 2> 1137976 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.SolrXmlConfig Loading container = configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/bui= ld/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBD= B3D08C1B2C7-001/jetty-002/solr.xml [junit4] 2> 1137981 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoresLocator Config-defined core= root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build= /solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3= D08C1B2C7-001/jetty-002/cores [junit4] 2> 1137981 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoreContainer New CoreContainer = 849328074 [junit4] 2> 1137981 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoreContainer Loading cores into= CoreContainer [instanceDir=3D/home/jenkins/workspace/Lucene-Solr-trunk-Lin= ux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZ= kTest_18EBDB3D08C1B2C7-001/jetty-002/] [junit4] 2> 1137982 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.CoreContainer loading shared lib= rary: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/= test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C7-0= 01/jetty-002/lib [junit4] 2> 1137982 WARN (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.SolrResourceLoader Can't find (o= r read) directory to add to classloader: lib (resolved as: /home/jenkins/wo= rkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.clou= d.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C7-001/jetty-002/lib). [junit4] 2> 1137988 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.h.c.HttpShardHandlerFactory create= d with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnection= sPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 214= 7483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRe= tries : false, [junit4] 2> 1137989 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.u.UpdateShardHandler Creating Upda= teShardHandler HTTP client with params: socketTimeout=3D340000&connTimeout= =3D45000&retry=3Dtrue [junit4] 2> 1137990 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf= 4j.impl.Log4jLoggerFactory [junit4] 2> 1137990 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.l.LogWatcher Registering Log Liste= ner [Log4j (org.slf4j.impl.Log4jLoggerFactory)] [junit4] 2> 1137990 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.ZkContainer Zookeeper client=3D1= 27.0.0.1:40733/solr [junit4] 2> 1137990 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.ZkController zkHost includes chr= oot [junit4] 2> 1137991 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkC= redentialsProvider [junit4] 2> 1137991 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Waiting for = client to connect to ZooKeeper [junit4] 2> 1137992 INFO (zkCallback-1503-thread-1) [ ] o.a.s.c.c.= ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2b= 6228a6 name:ZooKeeperConnection Watcher:127.0.0.1:40733 got event WatchedEv= ent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1137992 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.ConnectionManager Client is co= nnected to ZooKeeper [junit4] 2> 1137992 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [ ] o.a.s.c.c.SolrZkClient Using default ZkA= CLProvider [junit4] 2> 1137993 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.c.Conne= ctionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1137993 INFO (zkCallback-1504-thread-1-processing-n:127.0= .0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.c.ConnectionMan= ager Watcher org.apache.solr.common.cloud.ConnectionManager@5bbffebd name:Z= ooKeeperConnection Watcher:127.0.0.1:40733/solr got event WatchedEvent stat= e:SyncConnected type:None path:null path:null type:None [junit4] 2> 1137994 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.c.Conne= ctionManager Client is connected to ZooKeeper [junit4] 2> 1137995 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.c.ZkSta= teReader Updating cluster state from ZooKeeper...=20 [junit4] 2> 1138997 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.ZkContr= oller Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42058_ev%2Fa= z [junit4] 2> 1138997 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.c.SolrZ= kClient makePath: /live_nodes/127.0.0.1:42058_ev%2Faz [junit4] 2> 1138998 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.Oversee= r Overseer (id=3Dnull) closing [junit4] 2> 1138998 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.LeaderE= lector Joined leadership election with path: /overseer_elect/election/94248= 856982257671-127.0.0.1:42058_ev%2Faz-n_0000000001 [junit4] 2> 1138999 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.LeaderE= lector Watching path /overseer_elect/election/94248856982257668-127.0.0.1:5= 2363_ev%2Faz-n_0000000000 to know if I could be the leader [junit4] 2> 1138999 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.CoreCon= tainer No authentication plugin used. [junit4] 2> 1138999 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.CoreCon= tainer Security conf doesn't exist. Skipping setup for authorization module= . [junit4] 2> 1138999 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.CoresLo= cator Looking for core definitions underneath /home/jenkins/workspace/Lucen= e-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplica= tionDistributedZkTest_18EBDB3D08C1B2C7-001/jetty-002/cores [junit4] 2> 1139000 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.SolrCor= e Created CoreDescriptor: {name=3Dcollection1, config=3Dsolrconfig.xml, tra= nsient=3Dfalse, schema=3Dschema.xml, loadOnStartup=3Dtrue, configSetPropert= ies=3Dconfigsetprops.json, instanceDir=3D/home/jenkins/workspace/Lucene-Sol= r-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationD= istributedZkTest_18EBDB3D08C1B2C7-001/jetty-002/cores/collection1, collecti= on=3Dtmp_collection, absoluteInstDir=3D/home/jenkins/workspace/Lucene-Solr-= trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDis= tributedZkTest_18EBDB3D08C1B2C7-001/jetty-002/cores/collection1/, coreNodeN= ame=3D, dataDir=3Ddata/, shard=3D} [junit4] 2> 1139000 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.CoresLo= cator Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-L= inux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistribute= dZkTest_18EBDB3D08C1B2C7-001/jetty-002/cores/collection1/ [junit4] 2> 1139000 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.CoresLo= cator Found 1 core definitions [junit4] 2> 1139000 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController publishing state=3Ddown [junit4] 2> 1139000 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController numShards not found on descriptor - readin= g it from system property [junit4] 2> 1139000 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.s.SolrDis= patchFilter user.dir=3D/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr= /build/solr-core/test/J2 [junit4] 2> 1139001 INFO (TEST-CdcrReplicationDistributedZkTest.doTes= ts-seed#[18EBDB3D08C1B2C7]) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.s.SolrDis= patchFilter SolrDispatchFilter.init() done [junit4] 2> 1139001 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController look for our core node name [junit4] 2> 1139001 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.DistributedQueu= e NodeChildrenChanged fired on path /overseer/queue state SyncConnected [junit4] 2> 1139001 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.Ov= erseer processMessage: queueSize: 1, message =3D { [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:42058/ev/az", [junit4] 2> "node_name":"127.0.0.1:42058_ev%2Faz", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"tmp_collection", [junit4] 2> "operation":"state"} current state version: 3 [junit4] 2> 1139001 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.o.= ReplicaMutator Update state numShards=3D2 message=3D{ [junit4] 2> "core":"collection1", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:42058/ev/az", [junit4] 2> "node_name":"127.0.0.1:42058_ev%2Faz", [junit4] 2> "numShards":"2", [junit4] 2> "state":"down", [junit4] 2> "shard":null, [junit4] 2> "collection":"tmp_collection", [junit4] 2> "operation":"state"} [junit4] 2> 1139002 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.o.= ReplicaMutator Collection already exists with numShards=3D2 [junit4] 2> 1139002 INFO (OverseerStateUpdate-94248856982257668-127.0= .0.1:52363_ev%2Faz-n_0000000000) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.o.= ReplicaMutator Assigning new node to shard shard=3Dshard1 [junit4] 2> 1139103 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChan= ged path:/clusterstate.json, has occurred - updating... (live nodes size: 2= ) [junit4] 2> 1139103 INFO (zkCallback-1504-thread-1-processing-n:127.0= .0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.c.ZkStateReader= A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChan= ged path:/clusterstate.json, has occurred - updating... (live nodes size: 2= ) [junit4] 2> 1139104 INFO (zkCallback-1500-thread-1-processing-n:127.0= .0.1:52363_ev%2Faz) [n:127.0.0.1:52363_ev%2Faz ] o.a.s.c.c.ZkStateReader= Updated cluster state version to 4 [junit4] 2> 1139104 INFO (zkCallback-1504-thread-1-processing-n:127.0= .0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz ] o.a.s.c.c.ZkStateReader= Updated cluster state version to 4 [junit4] 2> 1140001 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController waiting to find shard id in clusterstate f= or collection1 [junit4] 2> 1140001 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController Check for collection zkNode:tmp_collection [junit4] 2> 1140001 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ZkController Collection zkNode exists [junit4] 2> 1140002 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.c.ZkStateReader Load collection config from:/collection= s/tmp_collection [junit4] 2> 1140002 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.c.ZkStateReader path=3D/collections/tmp_collection conf= igName=3Dconf1 specified config exists in ZooKeeper [junit4] 2> 1140002 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory= : '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/tes= t/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C7-001/= jetty-002/cores/collection1/' [junit4] 2> 1140008 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.Config loaded config solrconfig.xml with version 0=20 [junit4] 2> 1140010 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.SolrConfig current version of requestparams : -1 [junit4] 2> 1140025 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0 [junit4] 2> 1140031 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml [junit4] 2> 1140031 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/sch= ema.xml [junit4] 2> 1140034 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema [collection1] Schema name=3Dtest [junit4] 2> 1140103 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema default search field in schema is text [junit4] 2> 1140104 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.IndexSchema unique key field: id [junit4] 2> 1140104 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from = file currency.xml [junit4] 2> 1140106 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from = file currency.xml [junit4] 2> 1140111 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, = assuming default properties: Can't find resource 'configsetprops.json' in c= lasspath or '/configs/conf1', cwd=3D/home/jenkins/workspace/Lucene-Solr-tru= nk-Linux/solr/build/solr-core/test/J2 [junit4] 2> 1140111 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection x:c= ollection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using con= figuration from collection tmp_collection [junit4] 2> 1140111 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockD= irectoryFactory [junit4] 2> 1140111 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening n= ew SolrCore at [/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/= solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D= 08C1B2C7-001/jetty-002/cores/collection1/], dataDir=3D[null] [junit4] 2> 1140112 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is e= nabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanS= erver@70634a1d [junit4] 2> 1140112 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.CachingDirectoryFactory return new = directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/so= lr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08= C1B2C7-001/jetty-002/cores/collection1/data [junit4] 2> 1140112 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore New index directory detect= ed: old=3Dnull new=3D/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/b= uild/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18E= BDB3D08C1B2C7-001/jetty-002/cores/collection1/data/index/ [junit4] 2> 1140112 WARN (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore [collection1] Solr index d= irectory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-c= ore/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2= C7-001/jetty-002/cores/collection1/data/index' doesn't exist. Creating new = index... [junit4] 2> 1140112 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.CachingDirectoryFactory return new = directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/so= lr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest_18EBDB3D08= C1B2C7-001/jetty-002/cores/collection1/data/index [junit4] 2> 1140112 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy= wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePoli= cy: maxMergeAtOnce=3D39, maxMergeAtOnceExplicit=3D26, maxMergedSegmentMB=3D= 16.0986328125, floorSegmentMB=3D0.35546875, forceMergeDeletesPctAllowed=3D2= 5.865488090774736, segmentsPerTier=3D41.0, maxCFSSegmentSizeMB=3D8.79609302= 2207999E12, noCFSRatio=3D0.66880291210395 [junit4] 2> 1140113 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommi= t: commits: num=3D1 [junit4] 2> =09commit{dir=3DMockDirectoryWrapper(RAMDirectory@5a8b26ed= lockFactory=3Dorg.apache.lucene.store.SingleInstanceLockFactory@2a130bcb),= segFN=3Dsegments_1,generation=3D1} [junit4] 2> 1140113 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore newest commit generation = =3D 1 [junit4] 2> 1140113 INFO (OldIndexDirectoryCleanupThreadForCore-colle= ction1) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:shard1 r:core_node2 x= :collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup= for core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/so= lr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDistributedZkTest= _18EBDB3D08C1B2C7-001/jetty-002/cores/collection1/data/ [junit4] 2> 1140113 WARN (OldIndexDirectoryCleanupThreadForCore-colle= ction1) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:shard1 r:core_node2 x= :collection1] o.a.s.c.DirectoryFactory /home/jenkins/workspace/Lucene-Solr-= trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.CdcrReplicationDis= tributedZkTest_18EBDB3D08C1B2C7-001/jetty-002/cores/collection1/data/ does = not point to a valid data directory; skipping clean-up of old index directo= ries. [junit4] 2> 1140115 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creat= ing updateRequestProcessorChain "cdcr-processor-chain" [junit4] 2> 1140116 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore no updateRequestProcessorC= hain defined as default, creating implicit default [junit4] 2> 1140117 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1140117 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1140118 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1140118 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSecond= s=3D60 [junit4] 2> 1140120 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.RequestHandlers Registered paths: /= admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segm= ents,/get,/admin/system,/replication,/admin/properties,/config,/schema,/adm= in/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/cdcr,/up= date,/admin/file [junit4] 2> 1140121 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.c.SolrCore Using default statsCache c= ache: org.apache.solr.search.stats.LocalStatsCache [junit4] 2> 1140121 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.u.UpdateHandler Using UpdateLog imple= mentation: org.apache.solr.update.CdcrUpdateLog [junit4] 2> 1140121 INFO (coreLoadExecutor-4760-thread-1-processing-n= :127.0.0.1:42058_ev%2Faz) [n:127.0.0.1:42058_ev%2Faz c:tmp_collection s:sha= rd1 r:core_node2 x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: d= ataDir=3D defaultSyncLevel=3DFLUSH numRecordsToKeep=3D100 maxNumLogsToKeep= =3D10 numVersionBuckets=3D65536 [junit4] 2> 1140122 INFO (coreLoadExecutor-4760-thre [...truncated too long message...] hread-4276) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40733 40733 [junit4] 2> 1481111 WARN (Thread-4276) [ ] o.a.s.c.ZkTestServer Wa= tch limit violations:=20 [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2>=20 [junit4] 2> =09293=09/solr/aliases.json [junit4] 2> =09293=09/solr/clusterstate.json [junit4] 2> =0980=09/solr/configs/conf1 [junit4] 2> =0935=09/solr/collections/source_collection/state.json [junit4] 2> =0934=09/solr/collections/target_collection/state.json [junit4] 2> =093=09/solr/collections/source_collection/leaders/shard1 [junit4] 2> =092=09/solr/collections/source_collection/leaders/shard2 [junit4] 2> =092=09/solr/collections/tmp_collection/leaders/shard1 [junit4] 2> =092=09/solr/collections/tmp_collection/leaders/shard2 [junit4] 2> =092=09/solr/collections/target_collection/leaders/shard1 [junit4] 2> =092=09/solr/collections/target_collection/leaders/shard2 [junit4] 2>=20 [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2>=20 [junit4] 2> =0945=09/solr/collections/source_collection/cdcr/state/pro= cess [junit4] 2> =0938=09/solr/collections/source_collection/cdcr/state/buf= fer [junit4] 2> =0935=09/solr/collections/target_collection/cdcr/state/buf= fer [junit4] 2> =0935=09/solr/collections/target_collection/cdcr/state/pro= cess [junit4] 2> =098=09/solr/collections/tmp_collection/cdcr/state/buffer [junit4] 2> =098=09/solr/collections/tmp_collection/cdcr/state/process [junit4] 2> =094=09/solr/overseer_elect/election/94248856982257668-127= .0.0.1:52363_ev%2Faz-n_0000000000 [junit4] 2> =094=09/solr/overseer_elect/election/94248856982257718-127= .0.0.1:41908_ev%2Faz-n_0000000008 [junit4] 2> =093=09/solr/overseer_elect/election/94248856982257695-127= .0.0.1:48179_ev%2Faz-n_0000000007 [junit4] 2> =092=09/solr/overseer_elect/election/94248856982257674-127= .0.0.1:40882_ev%2Faz-n_0000000002 [junit4] 2> =092=09/solr/overseer_elect/election/94248856982257689-127= .0.0.1:47372_ev%2Faz-n_0000000005 [junit4] 2> =092=09/solr/collections/target_collection/leader_elect/sh= ard2/election/94248856982257695-core_node1-n_0000000000 [junit4] 2> =092=09/solr/collections/source_collection/leader_elect/sh= ard1/election/94248856982257674-core_node1-n_0000000000 [junit4] 2> =092=09/solr/overseer_elect/election/94248856982257844-127= .0.0.1:39792_ev%2Faz-n_0000000013 [junit4] 2>=20 [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2>=20 [junit4] 2> =09285=09/solr/live_nodes [junit4] 2> =093=09/solr/overseer/queue [junit4] 2> =093=09/solr/overseer/collection-queue-work [junit4] 2>=20 [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=3DCdcrReplicati= onDistributedZkTest -Dtests.method=3DdoTests -Dtests.seed=3D18EBDB3D08C1B2C= 7 -Dtests.multiplier=3D3 -Dtests.slow=3Dtrue -Dtests.locale=3Dzh_CN -Dtests= .timezone=3DAsia/Ashgabat -Dtests.asserts=3Dtrue -Dtests.file.encoding=3DIS= O-8859-1 [junit4] FAILURE 345s J2 | CdcrReplicationDistributedZkTest.doTests <<< [junit4] > Throwable #1: java.lang.AssertionError: Timeout while tryi= ng to assert update logs @ collection=3Dsource_collection [junit4] > =09at __randomizedtesting.SeedInfo.seed([18EBDB3D08C1B2C7:= 108BAE1107CF9ACC]:0) [junit4] > =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTe= st.assertNumberOfTlogFiles(CdcrReplicationDistributedZkTest.java:644) [junit4] > =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTe= st.doTestUpdateLogSynchronisation(CdcrReplicationDistributedZkTest.java:384= ) [junit4] > =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTe= st.doTests(CdcrReplicationDistributedZkTest.java:50) [junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase$Shards= RepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase= .java:963) [junit4] > =09at org.apache.solr.BaseDistributedSearchTestCase$Shards= RepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:938) [junit4] > =09at java.lang.Thread.run(Thread.java:745) [junit4] > Caused by: java.lang.AssertionError: Number of tlogs on re= plica: 67 is superior to: 50. [junit4] > =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTe= st._assertNumberOfTlogFiles(CdcrReplicationDistributedZkTest.java:674) [junit4] > =09at org.apache.solr.cloud.CdcrReplicationDistributedZkTe= st.assertNumberOfTlogFiles(CdcrReplicationDistributedZkTest.java:634) [junit4] > =09... 43 more [junit4] 2> 1481134 INFO (SUITE-CdcrReplicationDistributedZkTest-seed= #[18EBDB3D08C1B2C7]-worker) [n:127.0.0.1:48179_ev%2Faz c:target_collection = s:shard2 r:core_node1 x:target_collection_shard2_replica2] o.a.s.SolrTestCa= seJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/wo= rkspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.clou= d.CdcrReplicationDistributedZkTest_18EBDB3D08C1B2C7-001 [junit4] 2> Jul 28, 2015 10:49:33 PM com.carrotsearch.randomizedtestin= g.ThreadLeakControl checkThreadLeaks [junit4] 2> WARNING: Will linger awaiting termination of 4 leaked thre= ad(s). [junit4] 2> NOTE: test params are: codec=3DCheapBastard, sim=3DDefault= Similarity, locale=3Dzh_CN, timezone=3DAsia/Ashgabat [junit4] 2> NOTE: Linux 3.16.0-44-generic amd64/Oracle Corporation 1.9= .0-ea (64-bit)/cpus=3D12,threads=3D1,free=3D241198304,total=3D518979584 [junit4] 2> NOTE: All tests run in this JVM: [TestBinaryResponseWriter= , HdfsDirectoryFactoryTest, CdcrVersionReplicationTest, TestDownShardTolera= ntSearch, TestTrieFacet, TestCloudManagedSchema, DistributedFacetPivotSmall= Test, TestTolerantSearch, ResponseLogComponentTest, OverriddenZkACLAndCrede= ntialsProvidersTest, RollingRestartTest, TestXIncludeConfig, BigEndianAscen= dingWordDeserializerTest, XsltUpdateRequestHandlerTest, DocValuesTest, Test= ConfigOverlay, DistribCursorPagingTest, TestQueryUtils, CleanupOldIndexTest= , QueryEqualityTest, DistributedQueryComponentOptimizationTest, TestLuceneM= atchVersion, TestManagedSchemaDynamicFieldResource, ParsingFieldUpdateProce= ssorsTest, TestSolrConfigHandlerCloud, TestCrossCoreJoin, SoftAutoCommitTes= t, TestScoreJoinQPNoScore, TestDocSet, TestRandomMergePolicy, PrimUtilsTest= , LeaderInitiatedRecoveryOnCommitTest, SynonymTokenizerTest, TestStressReco= very, CollectionsAPIAsyncDistributedZkTest, TestHdfsUpdateLog, TestSolrQuer= yParser, TestFieldCollectionResource, SimpleFacetsTest, TestExtendedDismaxP= arser, TestComplexPhraseQParserPlugin, RulesTest, FileBasedSpellCheckerTest= , DocExpirationUpdateProcessorFactoryTest, ConcurrentDeleteAndCreateCollect= ionTest, HdfsBasicDistributedZk2Test, NumericFieldsTest, TestOverriddenPref= ixQueryForCustomFieldType, TestCollationFieldDocValues, PreAnalyzedUpdatePr= ocessorTest, DeleteReplicaTest, SampleTest, TestDocBasedVersionConstraints,= HardAutoCommitTest, TestSystemIdResolver, TestSort, DistributedQueryCompon= entCustomSortTest, SuggesterTest, UnloadDistributedZkTest, LeaderElectionTe= st, DistributedDebugComponentTest, HLLSerializationTest, TestSQLHandler, Ov= erseerTest, TestSurroundQueryParser, DistributedSuggestComponentTest, TestS= earcherReuse, SpatialHeatmapFacetsTest, TestDynamicFieldCollectionResource,= BinaryUpdateRequestHandlerTest, JavabinLoaderTest, HdfsSyncSliceTest, Basi= cDistributedZk2Test, TestSerializedLuceneMatchVersion, AsyncCallRequestStat= usResponseTest, TestDynamicLoading, TestQuerySenderNoQuery, TestSolrDynamic= MBean, TestJettySolrRunner, SortByFunctionTest, RecoveryZkTest, XmlUpdateRe= questHandlerTest, BaseCdcrDistributedZkTest, TestCustomDocTransformer, Solr= CoreCheckLockOnStartupTest, OpenCloseCoreStressTest, LeaderElectionIntegrat= ionTest, TestReplicationHandler, TestStressReorder, TestRangeQuery, StatsCo= mponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, BadIndexS= chemaTest, TestFiltering, CoreAdminHandlerTest, SuggesterTSTTest, TestTrie,= PolyFieldTest, TestPseudoReturnFields, TestUpdate, TestWordDelimiterFilter= Factory, DefaultValueUpdateProcessorTest, IndexBasedSpellCheckerTest, Stand= ardRequestHandlerTest, DirectSolrSpellCheckerTest, TestQueryTypes, TermsCom= ponentTest, DocumentBuilderTest, TermVectorComponentTest, FastVectorHighlig= hterTest, LoggingHandlerTest, IndexSchemaTest, TestCollationField, ReturnFi= eldsTest, TestCSVResponseWriter, QueryParsingTest, TestComponentsName, Upda= teParamsTest, CopyFieldTest, TestSearchPerf, TestFuzzyAnalyzedSuggestions, = NotRequiredUniqueKeyTest, TestPerFieldSimilarity, TestLMJelinekMercerSimila= rityFactory, TestDefaultSimilarityFactory, TestFastOutputStream, PluginInfo= Test, TestSuggestSpellingConverter, SpellingQueryConverterTest, DOMUtilTest= , RAMDirectoryFactoryTest, ClusterStateTest, TestDocumentBuilder, SystemInf= oHandlerTest, FileUtilsTest, DistributedMLTComponentTest, TestSimpleTrackin= gShardHandler, CdcrReplicationDistributedZkTest] [junit4] Completed [430/528] on J2 in 345.99s, 1 test, 1 failure <<< FAI= LURES! [...truncated 309 lines...] BUILD FAILED /home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:717: The followin= g error occurred while executing this line: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:661: The followin= g error occurred while executing this line: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:59: The following= error occurred while executing this line: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:230: The fol= lowing error occurred while executing this line: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:518: = The following error occurred while executing this line: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:142= 9: The following error occurred while executing this line: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:984= : There were test failures: 528 suites, 2080 tests, 1 failure, 61 ignored (= 26 assumptions) Total time: 42 minutes 45 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any ------=_Part_62_265652163.1438123999271 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_62_265652163.1438123999271--